niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #363
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.09s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestScriptTokenEmptyCommand101--- PASS: TestScriptTokenEmptyCommand (0.00s)102=== CONT TestDoWithRetry_BodyReplayedViaGetBody103=== CONT TestScriptTokenScriptFails104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107--- PASS: TestScriptTokenScriptFails (0.00s)108=== CONT TestStreamPushReportsEveryPath109=== CONT TestScriptTokenNoExpiryRerunsEveryCall110=== CONT TestFileTokenEmpty111=== CONT TestFileTokenMissing112=== CONT TestFileTokenReadsAndCaches113=== CONT TestStaticToken114=== CONT TestShellSplit115=== CONT TestSetClientTLSErrors116=== CONT TestSetClientTLSDoesNotMutateDefaultTransport117=== CONT TestSetClientTLS118=== CONT TestEncodeNixBase32119=== CONT TestClientSignaturesByStorePath120=== CONT TestStreamPushReportsSignatures121=== CONT TestResolveStorePath122=== CONT TestStreamPushRequestLine123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestStreamPushGivesUpOnDeadServer125=== CONT TestRateLimiterFeedback126=== CONT TestStreamPushIsolatesFailures127=== CONT TestStreamPushBatchesUnderLoad128--- PASS: TestScriptTokenBadJSON (0.00s)129=== CONT TestPathInfoCACompatibility130=== RUN TestPathInfoCACompatibility/null_ca_field131=== PAUSE TestPathInfoCACompatibility/null_ca_field132=== RUN TestPathInfoCACompatibility/old_string_format_-_text133=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text134=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive135=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive136=== CONT TestConvertHashToNix32137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== CONT TestParsePathInfoJSONMultiplePaths139=== CONT TestShellSplitErrors140=== RUN TestEncodeNixBase32/test_string_hash141=== CONT TestGetStorePathHash142--- PASS: TestStaticToken (0.00s)1432026/10/06 09:19:20 ERROR Upload failed error=boom count=1144=== CONT TestEncodeNixBase32WithRealHash1452026/10/06 09:19:20 ERROR Upload failed error="connection refused" count=201462026/10/06 09:19:20 ERROR Server seems unavailable, giving up on batch untried=17147=== CONT TestPathInfoHashCompatibility148--- PASS: TestShellSplit (0.00s)149--- PASS: TestStreamPushReportsEveryPath (0.00s)150--- PASS: TestFileTokenMissing (0.00s)151--- PASS: TestClientSignaturesByStorePath (0.00s)1522026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5153--- PASS: TestResolveStorePath (0.00s)154--- PASS: TestShellSplitErrors (0.00s)155--- PASS: TestFileTokenEmpty (0.00s)156--- PASS: TestScriptTokenEmptyToken (0.01s)157=== RUN TestConvertHashToNix32/SRI_format_to_Nix32158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== RUN TestConvertHashToNix32/invalid_format162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1632026/10/06 09:19:20 ERROR Upload failed error="bad path" count=3164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon166=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon167=== CONT TestFilterOversizedClosures168=== RUN TestFilterOversizedClosures/no_limit_keeps_everything169=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1712026/10/06 09:19:20 ERROR Upload failed error=boom count=1172=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1732026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1752026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39243176=== CONT TestDumpPathWriterError177--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)178--- PASS: TestFileTokenReadsAndCaches (0.00s)179=== CONT TestUploadMultipart_PartsInParallel180=== PAUSE TestConvertHashToNix32/invalid_format181=== CONT TestParsePathInfoJSON182=== PAUSE TestEncodeNixBase32/test_string_hash183=== PAUSE TestRateLimiterFeedback/429_enables_limiter184=== RUN TestPathInfoCACompatibility/new_structured_format_-_text185=== RUN TestGetStorePathHash/valid_store_path186=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun187=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything188=== CONT TestDumpPathSingleFile189=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths190=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512191--- PASS: TestStreamPushIsolatesFailures (0.00s)192--- PASS: TestEncodeNixBase32WithRealHash (0.00s)193=== RUN TestRateLimiterFeedback/503_enables_limiter194--- PASS: TestStreamPushReportsSignatures (0.00s)195=== PAUSE TestRateLimiterFeedback/503_enables_limiter196=== CONT TestDumpPathMatchesNix1972026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=5198=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter199=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter200=== RUN TestParsePathInfoJSON/Nix_format201=== RUN TestEncodeNixBase32/empty_input202=== PAUSE TestParsePathInfoJSON/Nix_format203=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2042026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:39243205=== CONT TestCaseHackSuffix206=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter207=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter208=== RUN TestParsePathInfoJSON/Lix_format209--- PASS: TestDoServerRequestAttachesToken (0.01s)210=== CONT TestUploadMultipart_SupersededByPeer211=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method212=== RUN TestSetClientTLSErrors/missing_cert_file213=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== PAUSE TestGetStorePathHash/valid_store_path218=== RUN TestGetStorePathHash/basename_without_hyphen_should_error219=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error220=== PAUSE TestEncodeNixBase32/empty_input221=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica222--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)223=== CONT TestPartSizeForNAR224=== RUN TestUploadMultipart_SupersededByPeer/exists225=== PAUSE TestParsePathInfoJSON/Lix_format226=== CONT TestRegisterUploadedObjectReusesConnections227=== PAUSE TestSetClientTLSErrors/missing_cert_file228=== CONT TestConvertHashToNix32/SRI_format_to_Nix32229=== CONT TestConvertHashToNix32/already_Nix32_format230=== RUN TestSetClientTLS/rejects_connection_without_client_cert231=== CONT TestConvertHashToNix32/invalid_format232=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== RUN TestFilterOversizedClosures/all_closures_skipped234=== PAUSE TestFilterOversizedClosures/all_closures_skipped235=== CONT TestRateLimiterFeedback/429_enables_limiter236=== CONT TestPathInfoCACompatibility/null_ca_field2372026/10/06 09:19:20 INFO Garbage collection started238=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method239=== CONT TestPathInfoCACompatibility/new_structured_format_-_text240=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive241=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)242=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI243=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2442026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=52452026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34069246=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon247=== CONT TestEncodeNixBase32/test_string_hash248=== CONT TestEncodeNixBase32/empty_input249=== CONT TestFilterOversizedClosures/no_limit_keeps_everything250=== CONT TestFilterOversizedClosures/all_closures_skipped2512026/10/06 09:19:20 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=50252=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2532026/10/06 09:19:20 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=2000254=== CONT TestPathInfoCACompatibility/old_string_format_-_text255=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2562026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=5257=== RUN TestPartSizeForNAR/zero_stays_at_minimum258=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum259=== RUN TestPartSizeForNAR/small_stays_at_minimum260=== PAUSE TestPartSizeForNAR/small_stays_at_minimum261=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum262=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum263=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts264=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts265=== RUN TestPartSizeForNAR/1_TiB266=== PAUSE TestPartSizeForNAR/1_TiB267=== RUN TestPartSizeForNAR/5_TiB_S3_max_object268=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object269--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)270=== RUN TestParsePathInfoJSON/empty_input271=== PAUSE TestUploadMultipart_SupersededByPeer/exists272=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert273=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter274=== CONT TestRateLimiterFeedback/503_enables_limiter275=== RUN TestSetClientTLSErrors/missing_key_file276=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths277=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error278=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== RUN TestPartSizeForNAR/capped_at_5_GiB280=== PAUSE TestPartSizeForNAR/capped_at_5_GiB281=== CONT TestPartSizeForNAR/zero_stays_at_minimum282=== PAUSE TestSetClientTLSErrors/missing_key_file283--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)284--- PASS: TestConvertHashToNix32 (0.00s)285 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)286 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)287 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)288=== PAUSE TestParsePathInfoJSON/empty_input289=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2902026/10/06 09:19:20 INFO Garbage collection started291=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts292=== CONT TestPartSizeForNAR/capped_at_5_GiB293=== CONT TestPartSizeForNAR/5_TiB_S3_max_object294=== CONT TestPartSizeForNAR/1_TiB295--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)296=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error297=== RUN TestUploadMultipart_SupersededByPeer/missing298=== PAUSE TestUploadMultipart_SupersededByPeer/missing299=== CONT TestUploadMultipart_SupersededByPeer/exists300=== RUN TestParsePathInfoJSON/whitespace_only301=== PAUSE TestParsePathInfoJSON/whitespace_only302=== RUN TestParsePathInfoJSON/invalid_JSON303=== PAUSE TestParsePathInfoJSON/invalid_JSON304=== CONT TestParsePathInfoJSON/Nix_format305=== CONT TestPartSizeForNAR/small_stays_at_minimum306=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestParsePathInfoJSON/whitespace_only3092026/10/06 09:19:20 WARN Rate limiter enabled after throttle name=server-test rate=5310=== CONT TestParsePathInfoJSON/empty_input3112026/10/06 09:19:20 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43589312=== CONT TestParsePathInfoJSON/Lix_format313--- PASS: TestParsePathInfoJSON (0.04s)314 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)315 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)316 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)317 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)318 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3192026/10/06 09:19:20 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=0320=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA321=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA322=== RUN TestSetClientTLS/preserves_debug_logging_transport323=== PAUSE TestSetClientTLS/preserves_debug_logging_transport324=== CONT TestSetClientTLS/rejects_connection_without_client_cert3252026/10/06 09:19:20 WARN Rate limiter backed off name=server-test rate=5326=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error327=== CONT TestGetStorePathHash/valid_store_path328=== CONT TestUploadMultipart_SupersededByPeer/missing329=== CONT TestSetClientTLS/preserves_debug_logging_transport330--- PASS: TestDumpPathSingleFile (0.03s)3312026/10/06 09:19:20 WARN Garbage collection finished on another replica. Its statistics are not available here332=== RUN TestSetClientTLSErrors/missing_ca_file333=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error334=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error335=== PAUSE TestSetClientTLSErrors/missing_ca_file336=== CONT TestGetStorePathHash/basename_without_hyphen_should_error337=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA338--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)339=== RUN TestSetClientTLSErrors/invalid_ca_file340=== PAUSE TestSetClientTLSErrors/invalid_ca_file341=== CONT TestSetClientTLSErrors/missing_cert_file342=== CONT TestSetClientTLSErrors/missing_ca_file343=== CONT TestSetClientTLSErrors/invalid_ca_file344--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)345--- PASS: TestEncodeNixBase32 (0.05s)346 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)347 --- PASS: TestEncodeNixBase32/empty_input (0.00s)348--- PASS: TestFilterOversizedClosures (0.05s)349 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)350 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)351 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)352--- PASS: TestPathInfoCACompatibility (0.02s)353 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)355 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)356 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)357 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)358--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)359 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)360 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)361=== CONT TestSetClientTLSErrors/missing_key_file362--- PASS: TestPathInfoHashCompatibility (0.02s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)365 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)367--- PASS: TestPartSizeForNAR (0.02s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)370 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375--- PASS: TestRateLimiterFeedback (0.02s)376 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)378 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)379 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)380--- PASS: TestGetStorePathHash (0.06s)381 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)382 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)384 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)385--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)386 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)387 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)388--- PASS: TestSetClientTLSErrors (0.05s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.02s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)392 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.02s)393--- PASS: TestStreamPushRequestLine (0.07s)3942026/10/06 09:19:20 http: TLS handshake error from 127.0.0.1:32864: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.05s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)400--- PASS: TestCaseHackSuffix (0.07s)401--- PASS: TestDumpPathWriterError (0.08s)402--- PASS: TestStreamPushBatchesUnderLoad (0.12s)403--- PASS: TestDumpPathMatchesNix (0.12s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres1513834102/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres1513834102/data -l logfile start434435/build/postgres1513834102:5432 - no response4362026-10-06 09:19:22.805 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 09:19:22.806 UTC [129] LOG: listening on Unix socket "/build/postgres1513834102/.s.PGSQL.5432"4382026-10-06 09:19:22.809 UTC [136] LOG: database system was shut down at 2026-10-06 09:19:22 UTC4392026-10-06 09:19:22.813 UTC [129] LOG: database system is ready to accept connections440/build/postgres1513834102:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/06 09:19:23 INFO lead: acquired remote=192.0.2.1:12344872026/10/06 09:19:23 INFO lead: released remote=192.0.2.1:12344882026/10/06 09:19:23 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 09:19:25 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/06 09:19:25 INFO lead: acquired remote=192.0.2.1:12344972026-10-06 09:19:26.515 UTC [388] FATAL: terminating connection due to administrator command4982026/10/06 09:19:26 INFO lead: acquired remote=192.0.2.1:12344992026/10/06 09:19:27 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/06 09:19:27 INFO lead: released remote=192.0.2.1:12345012026/10/06 09:19:27 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyOutlastsServerWriteTimeout612=== PAUSE TestReadProxyOutlastsServerWriteTimeout613=== RUN TestReadProxyConditionalGet614=== PAUSE TestReadProxyConditionalGet615=== RUN TestReadProxyRootRedirectsToIndexHTML616=== PAUSE TestReadProxyRootRedirectsToIndexHTML617=== RUN TestReadProxyDisabled618=== PAUSE TestReadProxyDisabled619=== RUN TestReadRedirectNar620=== PAUSE TestReadRedirectNar621=== RUN TestReadRedirectKeepsNarinfoProxied622=== PAUSE TestReadRedirectKeepsNarinfoProxied623=== RUN TestReadProxyRangeRequest624=== PAUSE TestReadProxyRangeRequest625=== RUN TestReadRedirectUsesPublicS3URL626=== PAUSE TestReadRedirectUsesPublicS3URL627=== RUN TestPush_OverlappingRootsStoreOneRowPerKey628=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey629=== RUN TestPush_CompleteCommitsEveryRoot630=== PAUSE TestPush_CompleteCommitsEveryRoot631=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit632=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit633=== RUN TestPush_RejectsBadRequests634=== PAUSE TestPush_RejectsBadRequests635=== RUN TestPush_SignsNarinfosOfItsPendingObjects636=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects637=== RUN TestRedundantMultipartUpload638=== PAUSE TestRedundantMultipartUpload639=== RUN TestCompleteMultipartUpload_ErrorButObjectExists640=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists641=== RUN TestCompletedNarNotReofferedAcrossClosures642=== PAUSE TestCompletedNarNotReofferedAcrossClosures643=== RUN TestPresignedUploadRegisteredBeforeCommit644=== PAUSE TestPresignedUploadRegisteredBeforeCommit645=== RUN TestService_Rustfstest646=== PAUSE TestService_Rustfstest647=== RUN TestParseSize648=== PAUSE TestParseSize649=== RUN TestSkippedUploadsHandler650=== PAUSE TestSkippedUploadsHandler651=== RUN TestSystemdListenerNotActivated652--- PASS: TestSystemdListenerNotActivated (0.00s)653=== RUN TestWatchdogBeatsWhenHealthy654--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)655=== RUN TestWatchdogSkipsWhenUnhealthy6562026/10/06 09:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/06 09:19:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 09:19:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"666--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)667=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== RUN TestProxyWriteTimeout670=== PAUSE TestProxyWriteTimeout671=== RUN TestPendingClosureWriteTimeout672=== PAUSE TestPendingClosureWriteTimeout673=== RUN TestIsValidUploadKey674=== PAUSE TestIsValidUploadKey675=== RUN TestUploadHandlersRejectInvalidKeys676=== PAUSE TestUploadHandlersRejectInvalidKeys677=== RUN TestUploadHandlersRejectOversizedBody678=== PAUSE TestUploadHandlersRejectOversizedBody679=== RUN TestService_cleanupPendingClosuresHandler680=== PAUSE TestService_cleanupPendingClosuresHandler681=== RUN TestService_createPendingClosureHandler682=== PAUSE TestService_createPendingClosureHandler683=== RUN TestService_verifyS3Integrity684=== PAUSE TestService_verifyS3Integrity685=== RUN TestCompleteMultipartUnregistered686=== PAUSE TestCompleteMultipartUnregistered687=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT688=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestSkippedUploadsHandler690=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded691=== CONT TestService_AuthMiddleware692=== CONT TestParseSize693--- PASS: TestParseSize (0.00s)694=== CONT TestMultipartCleanup695=== CONT TestReadRedirectUsesPublicS3URL6962026/10/06 09:19:28 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000697=== CONT TestService_Rustfstest698=== CONT TestServerTLSConfig699=== RUN TestServerTLSConfig/no_client_CA700=== PAUSE TestServerTLSConfig/no_client_CA701=== RUN TestServerTLSConfig/missing_CA_file702=== PAUSE TestServerTLSConfig/missing_CA_file703=== RUN TestServerTLSConfig/not_a_PEM_file704=== PAUSE TestServerTLSConfig/not_a_PEM_file705=== CONT TestPresignedUploadRegisteredBeforeCommit706=== CONT TestGCBugBareHashReferences707=== CONT TestService_NativeMTLS708=== CONT TestCompletedNarNotReofferedAcrossClosures709=== CONT TestMetricsInventory710=== CONT TestCompleteMultipartUpload_ErrorButObjectExists711=== CONT TestNARDeduplicationMetadataUploadBug712=== CONT TestRedundantMultipartUpload713=== CONT TestCreatePendingClosureRejectsOversizedNAR714=== CONT TestPush_SignsNarinfosOfItsPendingObjects715=== CONT TestCacheConfigHandlerMaxNarSize716=== CONT TestPush_RejectsBadRequests717=== CONT TestGenerateLandingPage718--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)719=== CONT TestReadProxyRangeRequest720--- PASS: TestSkippedUploadsHandler (0.01s)7212026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures722=== CONT TestGCAdvisoryLockBlocksConcurrentRun723=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit724=== CONT TestService_readinessHandler725=== CONT TestPush_CompleteCommitsEveryRoot726=== CONT TestPush_OverlappingRootsStoreOneRowPerKey727=== CONT TestService_healthCheckHandler728--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)729=== CONT TestReadRedirectKeepsNarinfoProxied730--- PASS: TestGenerateLandingPage (0.01s)731=== CONT TestLeadEndsOnShutdown7322026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures733--- PASS: TestService_Rustfstest (0.30s)734=== CONT TestReadRedirectNar7352026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures736--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.34s)737=== CONT TestLeadIncumbentAnnouncesAtOnce738--- PASS: TestReadRedirectUsesPublicS3URL (0.36s)739=== CONT TestReadProxyDisabled7402026/10/06 09:19:28 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"741--- PASS: TestService_AuthMiddleware (0.38s)742=== CONT TestLeadElectsOneAndHandsOver7432026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7442026/10/06 09:19:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket3/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""7452026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=17462026/10/06 09:19:28 INFO Received cleanup request method=DELETE path=/api/pending_closures7472026/10/06 09:19:28 INFO Aborted multipart uploads count=1 kept=07482026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes749--- PASS: TestMultipartCleanup (0.41s)750=== CONT TestReadProxyRootRedirectsToIndexHTML751--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.42s)752=== CONT TestGCMetrics7532026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes7542026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7552026/10/06 09:19:28 INFO Signed narinfos id=1 count=17562026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7572026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7582026/10/06 09:19:28 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7592026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7602026/10/06 09:19:28 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7612026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7622026/10/06 09:19:28 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17632026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7642026/10/06 09:19:28 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo765--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.45s)766=== CONT TestReadProxyConditionalGet767--- PASS: TestService_healthCheckHandler (0.46s)768=== CONT TestGracefulShutdownDrainsInflight7692026/10/06 09:19:28 INFO Starting HTTP server address=127.0.0.1:358017702026/10/06 09:19:28 INFO Shutdown signal received, draining in-flight requests timeout=10s771--- PASS: TestReadProxyRangeRequest (0.50s)772=== CONT TestReadProxyOutlastsServerWriteTimeout773--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)774=== CONT TestConnectWaitsForAPeerMigration775--- PASS: TestGracefulShutdownDrainsInflight (0.07s)776=== CONT TestReadProxyHead7772026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures7782026/10/06 09:19:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7792026/10/06 09:19:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"780--- PASS: TestService_NativeMTLS (0.56s)781=== CONT TestResolveDBConnectionString782=== RUN TestResolveDBConnectionString/flag_wins783=== PAUSE TestResolveDBConnectionString/flag_wins784=== RUN TestResolveDBConnectionString/file_when_flag_empty785=== PAUSE TestResolveDBConnectionString/file_when_flag_empty786=== RUN TestResolveDBConnectionString/missing_file_is_an_error787=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error788=== RUN TestResolveDBConnectionString/PGHOST_allows_empty789=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty790=== RUN TestResolveDBConnectionString/nothing_configured791=== PAUSE TestResolveDBConnectionString/nothing_configured792=== CONT TestReadProxyInvalidPath7932026/10/06 09:19:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7942026/10/06 09:19: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=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3Ljk1ZTk2MWJmLTg4YjEtNGJiZS04M2FkLWIwMDQ0NjdlOTVjYngxNzkxMjc4MzY4Njg3MTU5ODQ37952026/10/06 09:19:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3Ljk1ZTk2MWJmLTg4YjEtNGJiZS04M2FkLWIwMDQ0NjdlOTVjYngxNzkxMjc4MzY4Njg3MTU5ODQ3 parts=1796--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.58s)797=== CONT TestReadProxy4047982026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures799--- PASS: TestGCBugBareHashReferences (0.59s)800=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8012026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8022026/10/06 09:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete8032026/10/06 09:19:28 WARN readiness check failed error="closed pool"804--- PASS: TestService_readinessHandler (0.63s)805=== CONT TestGCTaskStore_Fail806--- PASS: TestGCTaskStore_Fail (0.00s)807=== CONT TestReadProxyNarStreaming8082026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8092026/10/06 09:19:28 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"810--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.66s)811=== CONT TestGCTaskStore_PhaseUpdates812--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)813=== CONT TestClientFallsBackToClosures8142026/10/06 09:19:28 INFO Aborted multipart uploads count=0 kept=08152026/10/06 09:19:28 WARN Force mode enabled - objects will be deleted immediately without grace period816=== RUN TestPush_RejectsBadRequests/no_roots817=== PAUSE TestPush_RejectsBadRequests/no_roots818=== RUN TestPush_RejectsBadRequests/no_objects819=== PAUSE TestPush_RejectsBadRequests/no_objects820=== RUN TestPush_RejectsBadRequests/bad_root821=== PAUSE TestPush_RejectsBadRequests/bad_root822=== RUN TestPush_RejectsBadRequests/root_not_in_objects823=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects824=== CONT TestReadProxyNarinfoAlreadyDecompressed8252026/10/06 09:19:28 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=08262026/10/06 09:19:28 INFO Vacuumed table table=pending_closures8272026/10/06 09:19:28 INFO Vacuumed table table=pending_objects8282026/10/06 09:19:28 INFO Vacuumed table table=multipart_uploads8292026/10/06 09:19:28 INFO Vacuumed table table=closures8302026/10/06 09:19:28 INFO Vacuumed table table=objects8312026/10/06 09:19:28 INFO Received complete push request method=POST path=/api/pushes/2/complete832=== NAME TestNARDeduplicationMetadataUploadBug833 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3639992007/001/store/al7n95vs0gx2gg1jnb5ymda735x6g3wg-file1.txt834--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.72s)835=== CONT TestGCTaskStore_CompletedAllowsNewTask836--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)837=== CONT TestClientPushesUseOnePush8382026/10/06 09:19:28 INFO lead: acquired remote=192.0.2.1:1234839--- PASS: TestMetricsInventory (0.77s)840=== CONT TestGCTaskStore_GetReturnsLatest841--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)842=== CONT TestPinProtectsFromGC8432026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/06 09:19:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8452026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures846--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.80s)847=== CONT TestGCTaskStore_GetEmpty848--- PASS: TestGCTaskStore_GetEmpty (0.00s)849=== CONT TestClientSharedPathCommittedMidPush8502026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes8512026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8522026/10/06 09:19:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8532026/10/06 09:19:28 INFO Uploading al7n95vs0gx2gg1jnb5ymda735x6g3wg-file1.txt (160B)8542026/10/06 09:19:28 WARN Failed to register uploaded object key=al7n95vs0gx2gg1jnb5ymda735x6g3wg.ls error="server returned 404: 404 page not found\n"8552026/10/06 09:19:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8562026/10/06 09:19:28 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8572026/10/06 09:19:28 INFO Signed narinfos id=1 count=18582026/10/06 09:19:28 INFO Uploading 1 narinfos8592026/10/06 09:19:28 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/06 09:19:28 INFO Received complete push request method=POST path=/api/pushes/1/complete8612026/10/06 09:19:28 WARN Failed to register uploaded object key=al7n95vs0gx2gg1jnb5ymda735x6g3wg.narinfo error="server returned 404: 404 page not found\n"8622026/10/06 09:19:28 INFO Upload complete. (66ms)863=== NAME TestNARDeduplicationMetadataUploadBug864 metadata_upload_test.go:54: Retrieved narinfo from S3:865 StorePath: /build/TestNARDeduplicationMetadataUploadBug3639992007/001/store/al7n95vs0gx2gg1jnb5ymda735x6g3wg-file1.txt866 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst867 Compression: zstd868 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf869 NarSize: 160870 References: 871 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf8722026/10/06 09:19:28 INFO Received push request method=POST path=/api/pushes873 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)874 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):875 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8762026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete877--- PASS: TestPush_CompleteCommitsEveryRoot (0.86s)878=== CONT TestReadProxyNarinfo879--- PASS: TestReadRedirectNar (0.58s)880=== CONT TestSweepSkipsRowsLockedByPush881=== NAME TestNARDeduplicationMetadataUploadBug882 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3639992007/001/store/6dpk2n1d6rpi1v0dp45j15nbl20bh64r-file2.txt8832026/10/06 09:19:29 INFO lead: acquired remote=192.0.2.1:12348842026/10/06 09:19:29 INFO lead: released remote=192.0.2.1:1234885--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.55s)886=== CONT TestClientWithDependencies8872026/10/06 09:19:29 INFO lead: acquired remote=192.0.2.1:12348882026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes8892026/10/06 09:19:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)890--- PASS: TestReadProxyDisabled (0.59s)891=== CONT TestIsValidCachePath892=== RUN TestIsValidCachePath/narinfo893=== PAUSE TestIsValidCachePath/narinfo894=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars895=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars896=== RUN TestIsValidCachePath/nar_zst897=== PAUSE TestIsValidCachePath/nar_zst898=== RUN TestIsValidCachePath/nar_xz899=== PAUSE TestIsValidCachePath/nar_xz900=== RUN TestIsValidCachePath/nar_bz2901=== PAUSE TestIsValidCachePath/nar_bz2902=== RUN TestIsValidCachePath/nar_uncompressed903=== PAUSE TestIsValidCachePath/nar_uncompressed904=== RUN TestIsValidCachePath/ls905=== PAUSE TestIsValidCachePath/ls906=== RUN TestIsValidCachePath/log907=== PAUSE TestIsValidCachePath/log908=== RUN TestIsValidCachePath/realisation909=== PAUSE TestIsValidCachePath/realisation910=== RUN TestIsValidCachePath/nix-cache-info911=== PAUSE TestIsValidCachePath/nix-cache-info912=== RUN TestIsValidCachePath/index.html913=== PAUSE TestIsValidCachePath/index.html914=== RUN TestIsValidCachePath/traversal_parent915=== PAUSE TestIsValidCachePath/traversal_parent916=== RUN TestIsValidCachePath/traversal_in_middle917=== PAUSE TestIsValidCachePath/traversal_in_middle918=== RUN TestIsValidCachePath/invalid_char_e919=== PAUSE TestIsValidCachePath/invalid_char_e920=== RUN TestIsValidCachePath/invalid_char_u921=== PAUSE TestIsValidCachePath/invalid_char_u922=== RUN TestIsValidCachePath/random_path923=== PAUSE TestIsValidCachePath/random_path924=== RUN TestIsValidCachePath/empty925=== PAUSE TestIsValidCachePath/empty926=== RUN TestIsValidCachePath/leading_slash927=== PAUSE TestIsValidCachePath/leading_slash928=== RUN TestIsValidCachePath/wrong_extension929=== PAUSE TestIsValidCachePath/wrong_extension930=== RUN TestIsValidCachePath/short_hash931=== PAUSE TestIsValidCachePath/short_hash932=== CONT TestFailedS3DeleteKeepsTombstone9332026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9342026/10/06 09:19:29 WARN Failed to register uploaded object key=6dpk2n1d6rpi1v0dp45j15nbl20bh64r.ls error="server returned 404: 404 page not found\n"9352026/10/06 09:19:29 INFO Signed narinfos id=2 count=19362026/10/06 09:19:29 INFO Uploading 1 narinfos9372026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/2/complete9382026/10/06 09:19:29 WARN Failed to register uploaded object key=6dpk2n1d6rpi1v0dp45j15nbl20bh64r.narinfo error="server returned 404: 404 page not found\n"9392026/10/06 09:19:29 INFO Upload complete. (51ms)940=== NAME TestNARDeduplicationMetadataUploadBug941 metadata_upload_test.go:76: Retrieved narinfo from S3:942 StorePath: /build/TestNARDeduplicationMetadataUploadBug3639992007/001/store/6dpk2n1d6rpi1v0dp45j15nbl20bh64r-file2.txt943 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst944 Compression: zstd945 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf946 NarSize: 160947 References: 948 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf949 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)950 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):951 {"version":1,"root":{"type":"regular","size":44}}952--- PASS: TestNARDeduplicationMetadataUploadBug (0.96s)953=== CONT TestClientMultipleUploads9542026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete955--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)956=== CONT TestProxyHeadersOnlyTrustedOnSocket9572026/10/06 09:19:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LmZhYjIxMDgzLWMwMTktNDc4MC1hYjc3LTk4YmVmYjI0OGM2Y3gxNzkxMjc4MzY4NzM0NjkyMTIy parts=129582026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures959--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.00s)960=== CONT TestForceGCDuringPushOffersSweptObject961=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows962=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows963=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check964=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check965=== CONT TestClientIntegration9662026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=09672026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period9682026/10/06 09:19: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=09692026/10/06 09:19:29 INFO Vacuumed table table=pending_closures9702026/10/06 09:19:29 INFO Vacuumed table table=pending_objects9712026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads9722026/10/06 09:19:29 INFO Vacuumed table table=closures9732026/10/06 09:19:29 INFO Vacuumed table table=objects974--- PASS: TestGCMetrics (0.59s)975=== CONT TestParseSingleRange976=== RUN TestParseSingleRange/none977=== PAUSE TestParseSingleRange/none978=== RUN TestParseSingleRange/unknown_unit979=== PAUSE TestParseSingleRange/unknown_unit980=== RUN TestParseSingleRange/multi-range_ignored981=== PAUSE TestParseSingleRange/multi-range_ignored982=== RUN TestParseSingleRange/malformed_no_dash983=== PAUSE TestParseSingleRange/malformed_no_dash984=== RUN TestParseSingleRange/malformed_both_empty985=== PAUSE TestParseSingleRange/malformed_both_empty986=== RUN TestParseSingleRange/malformed_end_before_start987=== PAUSE TestParseSingleRange/malformed_end_before_start988=== RUN TestParseSingleRange/closed989=== PAUSE TestParseSingleRange/closed990=== RUN TestParseSingleRange/open-ended991=== PAUSE TestParseSingleRange/open-ended992=== RUN TestParseSingleRange/end_clamped_to_size993=== PAUSE TestParseSingleRange/end_clamped_to_size994=== RUN TestParseSingleRange/suffix995=== PAUSE TestParseSingleRange/suffix996=== RUN TestParseSingleRange/suffix_exceeds_size997=== PAUSE TestParseSingleRange/suffix_exceeds_size998=== RUN TestParseSingleRange/single_byte999=== PAUSE TestParseSingleRange/single_byte1000=== RUN TestParseSingleRange/start_past_EOF1001=== PAUSE TestParseSingleRange/start_past_EOF1002=== RUN TestParseSingleRange/start_far_past_EOF1003=== PAUSE TestParseSingleRange/start_far_past_EOF1004=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1005--- PASS: TestReadProxyConditionalGet (0.60s)1006=== CONT TestPresentNotReportedWhileGCDeletesClosure1007--- PASS: TestReadProxyHead (0.55s)1008=== CONT TestClientErrorHandling1009=== RUN TestClientErrorHandling/InvalidStorePath1010=== PAUSE TestClientErrorHandling/InvalidStorePath1011=== RUN TestClientErrorHandling/InvalidAuthToken1012=== PAUSE TestClientErrorHandling/InvalidAuthToken1013=== RUN TestClientErrorHandling/ServerNotAvailable1014=== PAUSE TestClientErrorHandling/ServerNotAvailable1015=== CONT TestGCSweepDeliversEachKeyOnce1016--- PASS: TestReadProxyInvalidPath (0.55s)1017=== CONT TestRegisterCompletedObjectNeedsPendingRow1018--- PASS: TestReadProxy404 (0.58s)1019=== CONT TestClientCADerivations1020--- PASS: TestReadProxyNarStreaming (0.57s)1021=== CONT TestPresentReportsOnlyClosureRoots10222026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10232026/10/06 09:19:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LjE3NWY5ZjE0LTIyMmEtNDc4OC1hOTdhLWMwMDZkOTRiMGYzZHgxNzkxMjc4MzY4OTYwMzMyOTM0 parts=1210242026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1025--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.54s)1026=== CONT TestTombstonedObjectOfferedWithoutWaiting10272026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1028=== NAME TestPinProtectsFromGC1029 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3123289904/001/store/cr8gpihc1avmbyng17b23hppg0s8a2c8-pinned-file.txt1030 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3123289904/001/store/y2d96m5yjsmbj4h0b5fawsggdbhisazf-unpinned-file.txt10312026/10/06 09:19:29 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10322026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=010342026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period10362026/10/06 09:19:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10372026/10/06 09:19:29 INFO Uploading ycgdz6bjqa95y1qw3igjsj6msnwf6fpi-b (216B)10382026/10/06 09:19:29 INFO Uploading a93my8zndfc2xvs6hiys5i9nw76as8p5-shared-dep (136B)10392026/10/06 09:19: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=010402026/10/06 09:19:29 INFO Vacuumed table table=pending_closures10412026/10/06 09:19:29 WARN Failed to register uploaded object key=1swhpa3w8pz6sjyci54r2sikfbx3ni7f.ls error="server returned 404: 404 page not found\n"10422026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10432026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10442026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0bv7w1iycgsrzvvg0nrli7r9c2lnsm4b5dqrgvrsizfa1fnmpfij.nar.zst error="server returned 404: 404 page not found\n"10452026/10/06 09:19:29 WARN Failed to register uploaded object key=ycgdz6bjqa95y1qw3igjsj6msnwf6fpi.ls error="server returned 404: 404 page not found\n"10462026/10/06 09:19:29 WARN Failed to register uploaded object key=a93my8zndfc2xvs6hiys5i9nw76as8p5.ls error="server returned 404: 404 page not found\n"10472026/10/06 09:19:29 INFO Signed narinfos id=1 count=210482026/10/06 09:19:29 INFO Vacuumed table table=pending_objects10492026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10502026/10/06 09:19:29 INFO Signed narinfos id=2 count=210512026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads10522026/10/06 09:19:29 INFO Uploading 4 narinfos10532026/10/06 09:19:29 INFO Vacuumed table table=closures10542026/10/06 09:19:29 INFO Vacuumed table table=objects10552026/10/06 09:19:29 WARN Failed to register uploaded object key=a93my8zndfc2xvs6hiys5i9nw76as8p5.narinfo error="server returned 404: 404 page not found\n"10562026/10/06 09:19:29 WARN Failed to register uploaded object key=1swhpa3w8pz6sjyci54r2sikfbx3ni7f.narinfo error="server returned 404: 404 page not found\n"10572026/10/06 09:19:29 WARN Failed to register uploaded object key=ycgdz6bjqa95y1qw3igjsj6msnwf6fpi.narinfo error="server returned 404: 404 page not found\n"10582026/10/06 09:19:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10592026/10/06 09:19:29 WARN Failed to register uploaded object key=a93my8zndfc2xvs6hiys5i9nw76as8p5.narinfo error="server returned 404: 404 page not found\n"10602026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=010612026/10/06 09:19:29 INFO Completed upload id=110622026/10/06 09:19:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10632026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period10642026/10/06 09:19:29 INFO Completed upload id=210652026/10/06 09:19:29 INFO Upload complete. (67ms)1066=== NAME TestClientFallsBackToClosures1067 client_pushes_test.go:112: Retrieved narinfo from S3:1068 StorePath: /build/TestClientFallsBackToClosures2268585486/001/store/a93my8zndfc2xvs6hiys5i9nw76as8p5-shared-dep1069 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1070 Compression: zstd1071 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821072 NarSize: 1361073 References: 1074 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1075 client_pushes_test.go:112: Retrieved narinfo from S3:1076 StorePath: /build/TestClientFallsBackToClosures2268585486/001/store/1swhpa3w8pz6sjyci54r2sikfbx3ni7f-a1077 URL: nar/0bv7w1iycgsrzvvg0nrli7r9c2lnsm4b5dqrgvrsizfa1fnmpfij.nar.zst1078 Compression: zstd1079 NarHash: sha256:0bv7w1iycgsrzvvg0nrli7r9c2lnsm4b5dqrgvrsizfa1fnmpfij1080 NarSize: 2161081 References: /build/TestClientFallsBackToClosures2268585486/001/store/a93my8zndfc2xvs6hiys5i9nw76as8p5-shared-dep1082 CA: text:sha256:0ww95zkrfvhfrjv8h89gi02wdl5bd6mfiplkdjn5vgf5v574lx1k10832026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures10842026/10/06 09:19: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=01085 client_pushes_test.go:112: Retrieved narinfo from S3:1086 StorePath: /build/TestClientFallsBackToClosures2268585486/001/store/ycgdz6bjqa95y1qw3igjsj6msnwf6fpi-b1087 URL: nar/0bv7w1iycgsrzvvg0nrli7r9c2lnsm4b5dqrgvrsizfa1fnmpfij.nar.zst1088 Compression: zstd1089 NarHash: sha256:0bv7w1iycgsrzvvg0nrli7r9c2lnsm4b5dqrgvrsizfa1fnmpfij1090 NarSize: 2161091 References: /build/TestClientFallsBackToClosures2268585486/001/store/a93my8zndfc2xvs6hiys5i9nw76as8p5-shared-dep1092 CA: text:sha256:0ww95zkrfvhfrjv8h89gi02wdl5bd6mfiplkdjn5vgf5v574lx1k10932026/10/06 09:19:29 INFO Vacuumed table table=pending_closures10942026/10/06 09:19:29 INFO Vacuumed table table=pending_objects10952026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads10962026/10/06 09:19:29 INFO Vacuumed table table=closures10972026/10/06 09:19:29 INFO Vacuumed table table=objects1098--- PASS: TestClientFallsBackToClosures (0.77s)1099=== CONT TestCacheStatsHandler1100--- PASS: TestSweepSkipsRowsLockedByPush (0.56s)1101=== CONT TestGCSweepSkipsPendingObjects11022026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes11032026/10/06 09:19:29 INFO Starting HTTP server address=127.0.0.1:3398111042026/10/06 09:19:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket4065051052/001/proxy.sock11052026/10/06 09:19:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11062026/10/06 09:19:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1107--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.48s)1108=== CONT TestCacheConfigHandler1109=== RUN TestCacheConfigHandler/full_config,_no_issuer1110=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1111=== RUN TestCacheConfigHandler/no_cache_url_configured1112=== PAUSE TestCacheConfigHandler/no_cache_url_configured1113=== RUN TestCacheConfigHandler/no_signing_keys1114=== PAUSE TestCacheConfigHandler/no_signing_keys1115=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1116=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1117=== CONT TestDeduplicatedObjectsRecordedAsPending11182026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes11192026/10/06 09:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11202026/10/06 09:19:29 INFO Uploading cr8gpihc1avmbyng17b23hppg0s8a2c8-pinned-file.txt (128B)11212026/10/06 09:19:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11222026/10/06 09:19:29 INFO Uploading fa8kdh79hl4cvlkah893h4cb5rh57mvc-shared-dep (136B)11232026/10/06 09:19:29 INFO Uploading 78p58ihcq0x6mr9h6xz8ky0y8mprrbpv-b (216B)11242026/10/06 09:19:29 WARN Failed to register uploaded object key=cr8gpihc1avmbyng17b23hppg0s8a2c8.ls error="server returned 404: 404 page not found\n"11252026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11262026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11272026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes11282026/10/06 09:19:29 INFO Signed narinfos id=1 count=111292026/10/06 09:19:29 INFO Uploading 1 narinfos11302026/10/06 09:19:29 WARN Failed to register uploaded object key=4cyf972cyfkbs3mhh9h4h6pllwqza5dp.ls error="server returned 404: 404 page not found\n"11312026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0xn732cym6n33gmfzn5qsmpq8k5bwpy2l3hwhasb8wqicj1fw589.nar.zst error="server returned 404: 404 page not found\n"11322026/10/06 09:19:29 WARN Failed to register uploaded object key=78p58ihcq0x6mr9h6xz8ky0y8mprrbpv.ls error="server returned 404: 404 page not found\n"11332026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11342026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11352026/10/06 09:19:29 WARN Failed to register uploaded object key=fa8kdh79hl4cvlkah893h4cb5rh57mvc.ls error="server returned 404: 404 page not found\n"11362026/10/06 09:19:29 INFO Signed narinfos id=1 count=311372026/10/06 09:19:29 INFO Uploading 3 narinfos11382026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete11392026/10/06 09:19:29 WARN Failed to register uploaded object key=cr8gpihc1avmbyng17b23hppg0s8a2c8.narinfo error="server returned 404: 404 page not found\n"11402026/10/06 09:19:29 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11412026/10/06 09:19:29 INFO Uploading 83khbmpk675mq251i4n1v6rsim3iys6c-shared-dep (136B)11422026/10/06 09:19:29 INFO Uploading 2mzf16kp8p48cvkzpki1ivpqmc5f04hb-top (224B)11432026/10/06 09:19:29 WARN Failed to register uploaded object key=4cyf972cyfkbs3mhh9h4h6pllwqza5dp.narinfo error="server returned 404: 404 page not found\n"11442026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete11452026/10/06 09:19:29 WARN Failed to register uploaded object key=78p58ihcq0x6mr9h6xz8ky0y8mprrbpv.narinfo error="server returned 404: 404 page not found\n"11462026/10/06 09:19:29 WARN Failed to register uploaded object key=fa8kdh79hl4cvlkah893h4cb5rh57mvc.narinfo error="server returned 404: 404 page not found\n"11472026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11482026/10/06 09:19:29 WARN Failed to register uploaded object key=83khbmpk675mq251i4n1v6rsim3iys6c.ls error="server returned 404: 404 page not found\n"11492026/10/06 09:19:29 WARN Failed to register uploaded object key=2mzf16kp8p48cvkzpki1ivpqmc5f04hb.ls error="server returned 404: 404 page not found\n"11502026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0kw834gl107cvwmwclrlypan6qpgzdpq8sks8vy8igc9p689l86v.nar.zst error="server returned 404: 404 page not found\n"11512026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11522026/10/06 09:19:29 INFO Signed narinfos id=1 count=211532026/10/06 09:19:29 INFO Uploading 2 narinfos11542026/10/06 09:19:29 INFO Upload complete. (66ms)11552026/10/06 09:19:29 INFO Upload complete. (70ms)11562026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete11572026/10/06 09:19:29 WARN Failed to register uploaded object key=2mzf16kp8p48cvkzpki1ivpqmc5f04hb.narinfo error="server returned 404: 404 page not found\n"11582026/10/06 09:19:29 WARN Failed to register uploaded object key=83khbmpk675mq251i4n1v6rsim3iys6c.narinfo error="server returned 404: 404 page not found\n"1159=== NAME TestClientPushesUseOnePush1160 client_pushes_test.go:97: Retrieved narinfo from S3:1161 StorePath: /build/TestClientPushesUseOnePush2510411937/001/store/fa8kdh79hl4cvlkah893h4cb5rh57mvc-shared-dep1162 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1163 Compression: zstd1164 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821165 NarSize: 1361166 References: 1167 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1168 client_pushes_test.go:97: Retrieved narinfo from S3:1169 StorePath: /build/TestClientPushesUseOnePush2510411937/001/store/4cyf972cyfkbs3mhh9h4h6pllwqza5dp-a1170 URL: nar/0xn732cym6n33gmfzn5qsmpq8k5bwpy2l3hwhasb8wqicj1fw589.nar.zst1171 Compression: zstd1172 NarHash: sha256:0xn732cym6n33gmfzn5qsmpq8k5bwpy2l3hwhasb8wqicj1fw5891173 NarSize: 2161174 References: /build/TestClientPushesUseOnePush2510411937/001/store/fa8kdh79hl4cvlkah893h4cb5rh57mvc-shared-dep1175 CA: text:sha256:057bs6g2wvl3bvihqs1j3kv0dn7whl92ann35r628y5c7xyk923h1176=== NAME TestClientWithDependencies1177 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1017990992/001/store/hc1v3608vqhr8n9drdxd1r6ywjg6zmzg-test-script11782026/10/06 09:19:29 INFO Upload complete. (66ms)1179=== NAME TestClientSharedPathCommittedMidPush1180 client_integration_test.go:680: Retrieved narinfo from S3:1181 StorePath: /build/TestClientSharedPathCommittedMidPush3395198183/001/store/83khbmpk675mq251i4n1v6rsim3iys6c-shared-dep1182 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1183 Compression: zstd1184 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821185 NarSize: 1361186 References: 1187 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1188=== NAME TestClientPushesUseOnePush1189 client_pushes_test.go:97: Retrieved narinfo from S3:1190 StorePath: /build/TestClientPushesUseOnePush2510411937/001/store/78p58ihcq0x6mr9h6xz8ky0y8mprrbpv-b1191 URL: nar/0xn732cym6n33gmfzn5qsmpq8k5bwpy2l3hwhasb8wqicj1fw589.nar.zst1192 Compression: zstd1193 NarHash: sha256:0xn732cym6n33gmfzn5qsmpq8k5bwpy2l3hwhasb8wqicj1fw5891194 NarSize: 2161195 References: /build/TestClientPushesUseOnePush2510411937/001/store/fa8kdh79hl4cvlkah893h4cb5rh57mvc-shared-dep1196 CA: text:sha256:057bs6g2wvl3bvihqs1j3kv0dn7whl92ann35r628y5c7xyk923h1197=== NAME TestClientSharedPathCommittedMidPush1198 client_integration_test.go:680: Retrieved narinfo from S3:1199 StorePath: /build/TestClientSharedPathCommittedMidPush3395198183/001/store/2mzf16kp8p48cvkzpki1ivpqmc5f04hb-top1200 URL: nar/0kw834gl107cvwmwclrlypan6qpgzdpq8sks8vy8igc9p689l86v.nar.zst1201 Compression: zstd1202 NarHash: sha256:0kw834gl107cvwmwclrlypan6qpgzdpq8sks8vy8igc9p689l86v1203 NarSize: 2241204 References: /build/TestClientSharedPathCommittedMidPush3395198183/001/store/83khbmpk675mq251i4n1v6rsim3iys6c-shared-dep1205 CA: text:sha256:0gyw1nms5dxl5vlspxxqspl6zj54da7dlwazv47ahibzhr177x891206--- PASS: TestClientPushesUseOnePush (0.76s)1207=== CONT TestService_ReadScope_PublicByDefault1208--- PASS: TestClientSharedPathCommittedMidPush (0.69s)1209=== CONT TestGCTaskStore_ConflictDifferentParams1210--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1211=== CONT TestPushDedupSurvivesConcurrentGC12122026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=01213=== NAME TestClientWithDependencies1214 client_integration_test.go:615: Found 1 dependencies (including self)1215=== NAME TestClientMultipleUploads1216 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4153081511/001/store/rhvpx9c96fz87gjkwvxf8njsc259qfwj-test-file-0.txt12172026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12182026/10/06 09:19:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12192026/10/06 09:19:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12202026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1221--- PASS: TestFailedS3DeleteKeepsTombstone (0.59s)1222=== CONT TestService_RequireScope_OIDC12232026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes12242026/10/06 09:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12252026/10/06 09:19:29 INFO Uploading y2d96m5yjsmbj4h0b5fawsggdbhisazf-unpinned-file.txt (128B)12262026/10/06 09:19:29 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161227=== NAME TestClientIntegration1228 client_integration_test.go:286: Created store path: /build/TestClientIntegration2995301368/002/store/y3nac0l85yx40sgc54pwyswj7yygaw73-test-file.txt1229--- PASS: TestReadProxyNarinfo (0.68s)1230=== CONT TestGCTaskStore_DeduplicateSameParams1231--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1232=== CONT TestGCTaskStore_StartNew1233--- PASS: TestGCTaskStore_StartNew (0.00s)1234=== CONT TestOrphanedObjectsGC12352026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12362026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12372026/10/06 09:19:29 WARN Failed to register uploaded object key=y2d96m5yjsmbj4h0b5fawsggdbhisazf.ls error="server returned 404: 404 page not found\n"12382026/10/06 09:19:29 INFO Signed narinfos id=2 count=112392026/10/06 09:19:29 INFO Uploading 1 narinfos1240=== NAME TestClientMultipleUploads12412026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/2/complete1242 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4153081511/001/store/dmz4q93zplw6xps8miafc6wxq6chc4mi-test-file-1.txt12432026/10/06 09:19:29 WARN Failed to register uploaded object key=y2d96m5yjsmbj4h0b5fawsggdbhisazf.narinfo error="server returned 404: 404 page not found\n"12442026/10/06 09:19:29 INFO Upload complete. (49ms)1245--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.98s)1246=== CONT TestGCEndsOnShutdown1247=== RUN TestGCEndsOnShutdown/before_the_run1248=== PAUSE TestGCEndsOnShutdown/before_the_run1249=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1250=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1251=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1252=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1253=== CONT TestOrphanedObjectsGCStressTest12542026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes1255=== NAME TestClientMultipleUploads1256 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4153081511/001/store/axblf1kk4wyd9vwqqldmsk9zq2rvznpp-test-file-2.txt12572026/10/06 09:19:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures12582026/10/06 09:19:29 INFO Garbage collection started12592026/10/06 09:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12602026/10/06 09:19:29 INFO Uploading hc1v3608vqhr8n9drdxd1r6ywjg6zmzg-test-script (136B)12612026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12622026/10/06 09:19:29 WARN Failed to register uploaded object key=hc1v3608vqhr8n9drdxd1r6ywjg6zmzg.ls error="server returned 404: 404 page not found\n"12632026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12642026/10/06 09:19:29 WARN Failed to register uploaded object key=log/3nx64n9b12892p0kaqpw461rnxk8cbpd-test-script.drv error="server returned 404: 404 page not found\n"12652026/10/06 09:19:29 INFO Signed narinfos id=1 count=112662026/10/06 09:19:29 INFO Uploading 1 narinfos12672026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012682026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12692026/10/06 09:19:29 WARN Failed to register uploaded object key=hc1v3608vqhr8n9drdxd1r6ywjg6zmzg.narinfo error="server returned 404: 404 page not found\n"12702026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12712026/10/06 09:19:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36393/oidc1272--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.52s)1273=== CONT TestCreatePin_ReservedPins12742026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=012752026/10/06 09:19:29 INFO Upload complete. (68ms)12762026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes1277=== NAME TestClientWithDependencies1278 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1017990992/001/store) requires matching store prefix12792026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period12802026/10/06 09:19:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12812026/10/06 09:19:29 INFO Uploading y3nac0l85yx40sgc54pwyswj7yygaw73-test-file.txt (152B)1282--- PASS: TestClientWithDependencies (0.74s)1283=== CONT TestCommitRacingPendingCleanupKeepsObjects12842026/10/06 09:19:29 WARN Failed to register uploaded object key=y3nac0l85yx40sgc54pwyswj7yygaw73.ls error="server returned 404: 404 page not found\n"12852026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12862026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12872026/10/06 09:19:29 INFO Signed narinfos id=1 count=112882026/10/06 09:19:29 INFO Uploading 1 narinfos12892026/10/06 09:19: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=012902026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete12912026/10/06 09:19:29 WARN Failed to register uploaded object key=y3nac0l85yx40sgc54pwyswj7yygaw73.narinfo error="server returned 404: 404 page not found\n"12922026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12932026/10/06 09:19:29 INFO Vacuumed table table=pending_objects12942026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads12952026/10/06 09:19: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=012962026/10/06 09:19:29 INFO Upload complete. (59ms)12972026/10/06 09:19:29 INFO Vacuumed table table=pending_closures12982026/10/06 09:19:29 INFO Vacuumed table table=closures12992026/10/06 09:19:29 INFO Vacuumed table table=pending_objects13002026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads13012026/10/06 09:19:29 INFO Vacuumed table table=closures13022026/10/06 09:19:29 INFO Vacuumed table table=objects13032026/10/06 09:19:29 INFO Vacuumed table table=objects1304--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1305=== CONT TestSweepRechecksPendingAfterLocking13062026/10/06 09:19:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13072026/10/06 09:19:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38881/oidc13082026/10/06 09:19:29 INFO Received push request method=POST path=/api/pushes13092026/10/06 09:19:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LjZjY2EzYjgyLTMxNzUtNDMyYi1iNjczLTVjODU0ZTMyNWY3OXgxNzkxMjc4MzY5Mzk0MzYxMzQ2 error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13102026/10/06 09:19:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LmMzODNmODYzLTI0OWQtNGRkZi1hOTZiLTlmODdiNGQ2NjAyZngxNzkxMjc4MzY5Mzg4NzU4MjU3 parts=1213112026/10/06 09:19:29 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13122026/10/06 09:19:29 INFO Uploading rhvpx9c96fz87gjkwvxf8njsc259qfwj-test-file-0.txt (160B)13132026/10/06 09:19:29 INFO Uploading axblf1kk4wyd9vwqqldmsk9zq2rvznpp-test-file-2.txt (160B)13142026/10/06 09:19:29 INFO Uploading dmz4q93zplw6xps8miafc6wxq6chc4mi-test-file-1.txt (160B)13152026/10/06 09:19:29 INFO Received cleanup request method=DELETE path=/api/pending_closures1316--- PASS: TestPresentReportsOnlyClosureRoots (0.48s)1317=== CONT TestObjectStatsTrigger13182026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13192026/10/06 09:19:29 WARN Failed to register uploaded object key=dmz4q93zplw6xps8miafc6wxq6chc4mi.ls error="server returned 404: 404 page not found\n"13202026/10/06 09:19:29 WARN Failed to register uploaded object key=axblf1kk4wyd9vwqqldmsk9zq2rvznpp.ls error="server returned 404: 404 page not found\n"13212026/10/06 09:19:29 WARN Failed to register uploaded object key=rhvpx9c96fz87gjkwvxf8njsc259qfwj.ls error="server returned 404: 404 page not found\n"13222026/10/06 09:19:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13232026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13242026/10/06 09:19:29 INFO Aborted multipart uploads count=1 kept=013252026/10/06 09:19:29 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13262026/10/06 09:19:29 INFO Signed narinfos id=1 count=313272026/10/06 09:19:29 INFO Uploading 3 narinfos13282026/10/06 09:19:29 INFO All 1 paths already cached1329=== NAME TestClientIntegration1330 client_integration_test.go:312: Retrieved narinfo from S3:1331 StorePath: /build/TestClientIntegration2995301368/002/store/y3nac0l85yx40sgc54pwyswj7yygaw73-test-file.txt1332 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1333 Compression: zstd1334 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11335 NarSize: 1521336 References: 1337 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113382026/10/06 09:19:29 WARN Failed to register uploaded object key=axblf1kk4wyd9vwqqldmsk9zq2rvznpp.narinfo error="server returned 404: 404 page not found\n"13392026/10/06 09:19:29 WARN Failed to register uploaded object key=rhvpx9c96fz87gjkwvxf8njsc259qfwj.narinfo error="server returned 404: 404 page not found\n"13402026/10/06 09:19:29 INFO Received complete push request method=POST path=/api/pushes/1/complete13412026/10/06 09:19:29 WARN Failed to register uploaded object key=dmz4q93zplw6xps8miafc6wxq6chc4mi.narinfo error="server returned 404: 404 page not found\n"1342--- PASS: TestRedundantMultipartUpload (1.68s)1343=== CONT TestGetExistingObjectsLocksRows1344=== NAME TestClientIntegration1345 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1346 client_integration_test.go:313: Decompressed .ls content (64 bytes):1347 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1348 client_integration_test.go:316: Testing garbage collection...13492026/10/06 09:19:29 INFO Upload complete. (64ms)1350=== NAME TestClientMultipleUploads1351 client_integration_test.go:369: Uploaded 3 paths in 99.841032ms1352--- PASS: TestClientMultipleUploads (0.74s)1353=== CONT TestPushWaitsForSweepHoldingRow13542026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures1355--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.47s)1356=== CONT TestPendingCleanupUsesOneCutoff13572026/10/06 09:19:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures13582026/10/06 09:19:29 INFO Garbage collection started1359--- PASS: TestCacheStatsHandler (0.30s)13602026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=01361=== CONT TestUploadHandlersRejectOversizedBody1362=== NAME TestClientCADerivations1363 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1526601672/001/store/3gb6hf59788xm23bbb5lk6a4bg8wqqp5-ca-test13642026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period1365--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.73s)1366=== CONT TestPendingClosureWriteTimeout1367=== RUN TestPendingClosureWriteTimeout/empty1368=== PAUSE TestPendingClosureWriteTimeout/empty1369=== RUN TestPendingClosureWriteTimeout/400_objects1370=== PAUSE TestPendingClosureWriteTimeout/400_objects1371=== RUN TestPendingClosureWriteTimeout/670k_objects1372=== PAUSE TestPendingClosureWriteTimeout/670k_objects1373=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1374=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1375=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13762026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/06 09:19: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=013782026/10/06 09:19:29 INFO Vacuumed table table=pending_closures13792026/10/06 09:19:29 INFO Vacuumed table table=pending_objects13802026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads13812026/10/06 09:19:29 INFO Vacuumed table table=closures1382=== NAME TestClientCADerivations1383 client_ca_test.go:139: Found 1 dependencies (including self)13842026/10/06 09:19:29 INFO Vacuumed table table=objects13852026/10/06 09:19:29 INFO Aborted multipart uploads count=0 kept=013862026/10/06 09:19:29 INFO Received uploads request method=POST path=/api/pending_closures13872026/10/06 09:19:29 WARN Force mode enabled - objects will be deleted immediately without grace period13882026/10/06 09:19: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=01389--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.33s)1390=== CONT TestUploadHandlersRejectInvalidKeys1391=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1392=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1393=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1394=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1395=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1396=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1397=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1398=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1399=== CONT TestIsValidUploadKey1400=== RUN TestIsValidUploadKey/narinfo1401=== PAUSE TestIsValidUploadKey/narinfo1402=== RUN TestIsValidUploadKey/nar_zst1403=== PAUSE TestIsValidUploadKey/nar_zst1404=== RUN TestIsValidUploadKey/nar_xz1405=== PAUSE TestIsValidUploadKey/nar_xz1406=== RUN TestIsValidUploadKey/nar_plain1407=== PAUSE TestIsValidUploadKey/nar_plain1408=== RUN TestIsValidUploadKey/listing1409=== PAUSE TestIsValidUploadKey/listing1410=== RUN TestIsValidUploadKey/build_log1411=== PAUSE TestIsValidUploadKey/build_log1412=== RUN TestIsValidUploadKey/build_log_home-manager_file1413=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1414=== RUN TestIsValidUploadKey/build_log_plus_in_name1415=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1416=== RUN TestIsValidUploadKey/build_log_question_mark1417=== PAUSE TestIsValidUploadKey/build_log_question_mark1418=== RUN TestIsValidUploadKey/build_log_equals1419=== PAUSE TestIsValidUploadKey/build_log_equals1420=== RUN TestIsValidUploadKey/realisation1421=== PAUSE TestIsValidUploadKey/realisation1422=== RUN TestIsValidUploadKey/realisation_plus_in_output1423=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1424=== RUN TestIsValidUploadKey/nix-cache-info1425=== PAUSE TestIsValidUploadKey/nix-cache-info1426=== RUN TestIsValidUploadKey/index.html1427=== PAUSE TestIsValidUploadKey/index.html1428=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1429=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1430=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1431=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1432=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1433=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1434=== RUN TestIsValidUploadKey/traversal1435=== PAUSE TestIsValidUploadKey/traversal1436=== RUN TestIsValidUploadKey/traversal_nar1437=== PAUSE TestIsValidUploadKey/traversal_nar1438=== RUN TestIsValidUploadKey/absolute1439=== PAUSE TestIsValidUploadKey/absolute1440=== RUN TestIsValidUploadKey/empty_key1441=== PAUSE TestIsValidUploadKey/empty_key1442=== RUN TestIsValidUploadKey/unknown_type1443=== PAUSE TestIsValidUploadKey/unknown_type1444=== CONT TestCompleteMultipartUnregistered14452026/10/06 09:19:29 INFO Vacuumed table table=pending_closures14462026/10/06 09:19:29 INFO Vacuumed table table=pending_objects14472026/10/06 09:19:29 INFO Vacuumed table table=multipart_uploads14482026/10/06 09:19:29 INFO Vacuumed table table=closures14492026/10/06 09:19:29 INFO Vacuumed table table=objects1450--- PASS: TestGCSweepSkipsPendingObjects (0.37s)1451=== CONT TestService_ReadAuthMiddleware1452--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1453=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1454=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1455=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1456=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1457=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1458=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1459=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1460=== CONT TestProxyWriteTimeout1461=== RUN TestProxyWriteTimeout/narinfo1462=== PAUSE TestProxyWriteTimeout/narinfo1463=== RUN TestProxyWriteTimeout/1_GiB_nar1464=== PAUSE TestProxyWriteTimeout/1_GiB_nar1465=== RUN TestProxyWriteTimeout/10_GiB_nar14662026/10/06 09:19:30 INFO lead: released remote=192.0.2.1:12341467=== PAUSE TestProxyWriteTimeout/10_GiB_nar1468--- PASS: TestLeadEndsOnShutdown (1.88s)1469=== RUN TestProxyWriteTimeout/unknown_size1470=== PAUSE TestProxyWriteTimeout/unknown_size1471=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1472=== CONT TestService_AuthMiddleware_MTLSProxyHeader14732026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes14752026/10/06 09:19:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14762026/10/06 09:19:30 INFO Uploading 3gb6hf59788xm23bbb5lk6a4bg8wqqp5-ca-test (144B)14772026/10/06 09:19:30 WARN Failed to register uploaded object key=3gb6hf59788xm23bbb5lk6a4bg8wqqp5.ls error="server returned 404: 404 page not found\n"14782026/10/06 09:19:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14792026/10/06 09:19:30 WARN Failed to register uploaded object key=log/4hq3h4q96vrv7h5qdysmgwrfipqimlc6-ca-test.drv error="server returned 404: 404 page not found\n"14802026/10/06 09:19:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14812026/10/06 09:19:30 INFO Signed narinfos id=1 count=114822026/10/06 09:19:30 INFO Uploading 1 narinfos14832026/10/06 09:19:30 INFO Received complete push request method=POST path=/api/pushes/1/complete14842026/10/06 09:19:30 WARN Failed to register uploaded object key=3gb6hf59788xm23bbb5lk6a4bg8wqqp5.narinfo error="server returned 404: 404 page not found\n"14852026/10/06 09:19:30 INFO Upload complete. (168ms)14862026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=01487=== NAME TestClientCADerivations1488 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1526601672/001/store/3gb6hf59788xm23bbb5lk6a4bg8wqqp5-ca-test1489 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1490 Compression: zstd1491 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1492 NarSize: 1441493 References: 1494 Deriver: /build/TestClientCADerivations1526601672/001/store/4hq3h4q96vrv7h5qdysmgwrfipqimlc6-ca-test.drv1495 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1496 client_ca_test.go:185: Checking for realisation files in S3...1497 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1498 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14992026/10/06 09:19:30 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=015002026/10/06 09:19:30 INFO Vacuumed table table=pending_closures15012026/10/06 09:19:30 INFO Vacuumed table table=pending_objects15022026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads15032026/10/06 09:19:30 INFO Vacuumed table table=closures15042026/10/06 09:19:30 INFO Vacuumed table table=objects15052026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=015062026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period15072026/10/06 09:19: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=015082026/10/06 09:19:30 INFO Vacuumed table table=pending_closures15092026/10/06 09:19:30 INFO Vacuumed table table=pending_objects15102026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads15112026/10/06 09:19:30 INFO Vacuumed table table=closures15122026/10/06 09:19:30 INFO Vacuumed table table=objects1513--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)1514=== CONT TestService_createPendingClosureHandler1515=== RUN TestService_RequireScope_OIDC/builder_may_write1516=== PAUSE TestService_RequireScope_OIDC/builder_may_write1517=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1518=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1519=== RUN TestService_RequireScope_OIDC/ops_may_admin1520=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1521=== RUN TestService_RequireScope_OIDC/ops_may_not_write1522=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1523=== RUN TestService_RequireScope_OIDC/reader_may_not_write1524=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1525=== RUN TestService_RequireScope_OIDC/static_token_may_admin1526=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1527=== RUN TestService_RequireScope_OIDC/static_token_may_write1528=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1529=== RUN TestService_RequireScope_OIDC/reader_may_read1530=== PAUSE TestService_RequireScope_OIDC/reader_may_read1531=== RUN TestService_RequireScope_OIDC/writer_implies_read1532=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1533=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1534=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1535=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1536=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1537=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1538=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1539=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1540=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1541=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1542=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1543=== CONT TestService_verifyS3Integrity15442026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=015452026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=015462026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period15472026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period15482026/10/06 09:19: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=015492026/10/06 09:19:30 INFO Vacuumed table table=pending_closures1550--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.02s)1551=== CONT TestService_cleanupPendingClosuresHandler15522026/10/06 09:19:30 INFO Vacuumed table table=pending_objects15532026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads15542026/10/06 09:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15552026/10/06 09:19:30 WARN Refused reserved pin name=worker-x86_64-linux15562026/10/06 09:19:30 INFO Vacuumed table table=closures15572026/10/06 09:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15582026/10/06 09:19:30 INFO Received create pin request method=POST path=/api/pins/my-app15592026/10/06 09:19:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15602026/10/06 09:19:30 INFO Vacuumed table table=objects1561--- PASS: TestCreatePin_ReservedPins (0.45s)1562=== CONT TestService_AuthMiddleware_OIDC15632026/10/06 09:19: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=015642026/10/06 09:19:30 INFO Vacuumed table table=pending_closures15652026/10/06 09:19:30 INFO Vacuumed table table=pending_objects15662026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads15672026/10/06 09:19:30 INFO Vacuumed table table=closures1568--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.45s)1569=== CONT TestServerTLSConfig/no_client_CA1570=== CONT TestServerTLSConfig/not_a_PEM_file1571=== CONT TestServerTLSConfig/missing_CA_file1572--- PASS: TestServerTLSConfig (0.00s)1573 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1574 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1575 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1576=== CONT TestResolveDBConnectionString/flag_wins1577=== CONT TestResolveDBConnectionString/nothing_configured1578=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1579=== CONT TestResolveDBConnectionString/missing_file_is_an_error1580=== CONT TestResolveDBConnectionString/file_when_flag_empty1581=== CONT TestPush_RejectsBadRequests/no_roots15822026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1583=== CONT TestPush_RejectsBadRequests/bad_root1584--- PASS: TestResolveDBConnectionString (0.00s)1585 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1586 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1587 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1588 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1589 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)15902026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1591=== CONT TestPush_RejectsBadRequests/no_objects15922026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes1593=== CONT TestPush_RejectsBadRequests/root_not_in_objects15942026/10/06 09:19:30 INFO Received push request method=POST path=/api/pushes15952026/10/06 09:19:30 INFO Vacuumed table table=objects1596=== CONT TestIsValidCachePath/narinfo1597--- PASS: TestPush_RejectsBadRequests (0.70s)1598 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1599 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1600 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1601 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1602=== CONT TestIsValidCachePath/index.html1603=== CONT TestIsValidCachePath/short_hash1604=== CONT TestIsValidCachePath/wrong_extension1605=== CONT TestIsValidCachePath/leading_slash1606=== CONT TestIsValidCachePath/empty1607=== CONT TestIsValidCachePath/random_path1608=== CONT TestIsValidCachePath/invalid_char_u1609=== CONT TestIsValidCachePath/invalid_char_e1610=== CONT TestIsValidCachePath/traversal_in_middle1611=== CONT TestIsValidCachePath/traversal_parent1612=== CONT TestIsValidCachePath/realisation1613=== CONT TestIsValidCachePath/nix-cache-info1614=== CONT TestIsValidCachePath/log1615=== CONT TestIsValidCachePath/nar_uncompressed1616=== CONT TestIsValidCachePath/nar_xz1617=== CONT TestIsValidCachePath/ls1618=== CONT TestIsValidCachePath/nar_bz21619=== CONT TestIsValidCachePath/nar_zst1620=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1621--- PASS: TestIsValidCachePath (0.00s)1622 --- PASS: TestIsValidCachePath/narinfo (0.00s)1623 --- PASS: TestIsValidCachePath/index.html (0.00s)1624 --- PASS: TestIsValidCachePath/short_hash (0.00s)1625 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1626 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1627 --- PASS: TestIsValidCachePath/empty (0.00s)1628 --- PASS: TestIsValidCachePath/random_path (0.00s)1629 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1630 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1631 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1632 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1633 --- PASS: TestIsValidCachePath/realisation (0.00s)1634 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1635 --- PASS: TestIsValidCachePath/log (0.00s)1636 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1637 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1638 --- PASS: TestIsValidCachePath/ls (0.00s)1639 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1640 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1641 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1642=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1643--- PASS: TestSweepRechecksPendingAfterLocking (0.44s)1644=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1645=== NAME TestClientCADerivations1646 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1647 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1648 error: binary cache 's3://bucket56?endpoint=http://localhost:45187®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1526601672/001/store'1649 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11650--- PASS: TestClientCADerivations (0.93s)1651=== CONT TestParseSingleRange/none1652=== CONT TestParseSingleRange/open-ended1653=== CONT TestParseSingleRange/start_far_past_EOF1654=== CONT TestParseSingleRange/start_past_EOF1655=== CONT TestParseSingleRange/single_byte1656=== CONT TestParseSingleRange/suffix_exceeds_size1657=== CONT TestParseSingleRange/suffix1658=== CONT TestParseSingleRange/end_clamped_to_size1659=== CONT TestParseSingleRange/malformed_both_empty1660=== CONT TestParseSingleRange/closed1661=== CONT TestParseSingleRange/malformed_end_before_start1662=== CONT TestParseSingleRange/multi-range_ignored1663=== CONT TestParseSingleRange/malformed_no_dash1664=== CONT TestParseSingleRange/unknown_unit1665--- PASS: TestParseSingleRange (0.00s)1666 --- PASS: TestParseSingleRange/none (0.00s)1667 --- PASS: TestParseSingleRange/open-ended (0.00s)1668 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1669 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1670 --- PASS: TestParseSingleRange/single_byte (0.00s)1671 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1672 --- PASS: TestParseSingleRange/suffix (0.00s)1673 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1674 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1675 --- PASS: TestParseSingleRange/closed (0.00s)1676 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1677 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1678 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1679 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1680=== CONT TestClientErrorHandling/InvalidStorePath1681--- PASS: TestObjectStatsTrigger (0.42s)1682=== CONT TestClientErrorHandling/ServerNotAvailable16832026/10/06 09:19:30 INFO lead: released remote=192.0.2.1:12341684--- PASS: TestGetExistingObjectsLocksRows (0.45s)1685=== CONT TestClientErrorHandling/InvalidAuthToken16862026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures16872026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures16882026/10/06 09:19:30 INFO lead: acquired remote=192.0.2.1:123416892026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures16902026/10/06 09:19: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/present16912026/10/06 09:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures16922026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures1693--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)1694=== CONT TestCacheConfigHandler/full_config,_no_issuer1695=== CONT TestCacheConfigHandler/no_signing_keys1696=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1697=== CONT TestCacheConfigHandler/no_cache_url_configured1698--- PASS: TestCacheConfigHandler (0.00s)1699 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1700 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1701 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1702 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1703=== CONT TestGCEndsOnShutdown/before_the_run17042026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17052026/10/06 09:19:30 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1706--- PASS: TestCompleteMultipartUnregistered (0.42s)1707=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17082026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures1709--- PASS: TestService_ReadAuthMiddleware (0.46s)1710=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1711=== NAME TestOrphanedObjectsGC1712 orphaned_objects_gc_test.go:290: GC Test Summary:1713 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1714 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1715 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1716 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1717 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1718--- PASS: TestOrphanedObjectsGC (0.72s)1719=== CONT TestPendingClosureWriteTimeout/empty1720=== CONT TestPendingClosureWriteTimeout/670k_objects1721=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17222026/10/06 09:19:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38859/oidc17232026/10/06 09:19:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.062508ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1724--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.39s)1725=== CONT TestPendingClosureWriteTimeout/400_objects1726=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17272026/10/06 09:19:30 INFO Received uploads request method=POST path=/1728=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17292026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/1730=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17312026/10/06 09:19:30 INFO Received uploads request method=POST path=/1732=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17332026/10/06 09:19:30 INFO Received request for more parts method=POST path=/1734--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1735 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1736 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1737 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1738 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1739=== CONT TestIsValidUploadKey/narinfo1740=== CONT TestIsValidUploadKey/realisation_plus_in_output1741=== CONT TestIsValidUploadKey/traversal1742=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1743=== CONT TestIsValidUploadKey/unknown_type1744=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1745=== CONT TestIsValidUploadKey/empty_key1746=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1747=== CONT TestIsValidUploadKey/absolute1748=== CONT TestIsValidUploadKey/index.html1749=== CONT TestIsValidUploadKey/traversal_nar1750=== CONT TestIsValidUploadKey/nix-cache-info1751=== CONT TestIsValidUploadKey/build_log_home-manager_file1752=== CONT TestIsValidUploadKey/realisation1753=== CONT TestIsValidUploadKey/nar_plain1754=== CONT TestIsValidUploadKey/build_log_equals1755=== CONT TestIsValidUploadKey/build_log1756=== CONT TestIsValidUploadKey/build_log_question_mark1757=== CONT TestIsValidUploadKey/listing1758=== CONT TestIsValidUploadKey/build_log_plus_in_name1759=== CONT TestIsValidUploadKey/nar_xz1760=== CONT TestIsValidUploadKey/nar_zst1761=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17622026/10/06 09:19:30 INFO Received uploads request method=POST path=/1763--- PASS: TestIsValidUploadKey (0.00s)1764 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1765 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1766 --- PASS: TestIsValidUploadKey/traversal (0.00s)1767 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1768 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1769 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1770 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1771 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1772 --- PASS: TestIsValidUploadKey/absolute (0.00s)1773 --- PASS: TestIsValidUploadKey/index.html (0.00s)1774 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1775 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1776 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1777 --- PASS: TestIsValidUploadKey/realisation (0.00s)1778 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1779 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1780 --- PASS: TestIsValidUploadKey/build_log (0.00s)1781 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1782 --- PASS: TestIsValidUploadKey/listing (0.00s)1783 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1784 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1785 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)17862026/10/06 09:19:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17872026/10/06 09:19:30 WARN mTLS auth: bound subjects configured but subject DN unavailable17882026/10/06 09:19:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1789--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.42s)1790=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17912026/10/06 09:19:30 INFO Received request for more parts method=POST path=/17922026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17932026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures17952026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures17962026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures1797=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17982026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/17992026/10/06 09:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures18002026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018012026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures18022026/10/06 09:19:30 INFO Received cleanup request method=DELETE path=/api/pending_closures18032026/10/06 09:19:30 INFO Aborted multipart uploads count=1 kept=018042026/10/06 09:19:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18052026-10-06 09:19:30.548 UTC [1690] ERROR: Closure does not exist: id=118062026-10-06 09:19:30.548 UTC [1690] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE18072026-10-06 09:19:30.548 UTC [1690] STATEMENT: -- name: CommitPendingClosure :exec1808 SELECT commit_pending_closure($1::bigint)1809 1810--- PASS: TestService_cleanupPendingClosuresHandler (0.34s)1811=== CONT TestProxyWriteTimeout/narinfo1812=== CONT TestProxyWriteTimeout/unknown_size1813=== CONT TestProxyWriteTimeout/10_GiB_nar1814=== CONT TestProxyWriteTimeout/1_GiB_nar1815--- PASS: TestProxyWriteTimeout (0.00s)1816 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1817 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1818 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1819 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1820=== CONT TestService_RequireScope_OIDC/builder_may_write1821=== CONT TestService_RequireScope_OIDC/reader_may_read1822=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1823=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18242026/10/06 09:19: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]1825=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1826=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1827=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1828=== CONT TestService_RequireScope_OIDC/writer_implies_read1829=== CONT TestService_RequireScope_OIDC/reader_may_not_write1830=== CONT TestService_RequireScope_OIDC/static_token_may_write1831=== CONT TestService_RequireScope_OIDC/static_token_may_admin1832=== CONT TestService_RequireScope_OIDC/ops_may_admin1833=== CONT TestService_RequireScope_OIDC/ops_may_not_write1834=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1835--- PASS: TestService_RequireScope_OIDC (0.48s)1836 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1837 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1838 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1839 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1840 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1841 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1842 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1843 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1844 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1845 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1846 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1847 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1848 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1849 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18502026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures18512026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018522026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18532026/10/06 09:19: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=018542026/10/06 09:19:30 INFO Vacuumed table table=pending_closures18552026/10/06 09:19:30 INFO Vacuumed table table=pending_objects18562026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads18572026/10/06 09:19:30 INFO Vacuumed table table=closures18582026/10/06 09:19:30 INFO Vacuumed table table=objects18592026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures18602026/10/06 09:19:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.19734ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18612026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018622026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18632026/10/06 09:19: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=018642026/10/06 09:19:30 INFO Vacuumed table table=pending_closures18652026/10/06 09:19:30 INFO Vacuumed table table=pending_objects18662026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads18672026/10/06 09:19:30 INFO Vacuumed table table=closures18682026/10/06 09:19:30 INFO Vacuumed table table=objects1869--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1870 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.38s)1871 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.40s)18722026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=018732026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period18742026/10/06 09:19:30 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45187/bucket87/?delete=\": context canceled"18752026/10/06 09:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18762026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=01877=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token18782026/10/06 09:19:30 WARN Force mode enabled - objects will be deleted immediately without grace period1879=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1880=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1881=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1882=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1883=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1884=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1885=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1886=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1887=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1888=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured18892026/10/06 09:19: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]1890=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18912026/10/06 09:19:30 WARN Authentication failed token_preview=eyJhbGciOi...0iIRjtKhcQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]18922026-10-06 09:19:30.705 UTC [1786] ERROR: canceling statement due to user request18932026-10-06 09:19:30.705 UTC [1786] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block18942026-10-06 09:19:30.705 UTC [1786] STATEMENT: -- name: MarkStaleObjects :execrows1895 WITH RECURSIVE ct AS (1896 SELECT timezone('UTC', now()) AS now1897 ),1898 closure_reach AS (1899 -- Start with all closure keys1900 SELECT o.key, o.refs1901 FROM objects o1902 INNER JOIN closures c ON o.key = c.key1903 UNION1904 -- Recursively add all referenced objects1905 SELECT o.key, o.refs1906 FROM objects o1907 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1908 ),1909 reachable_objects AS (1910 SELECT DISTINCT key FROM closure_reach1911 ),1912 stale_objects AS (1913 SELECT o.key1914 FROM objects AS o, ct1915 WHERE1916 NOT EXISTS (1917 SELECT 11918 FROM reachable_objects ro1919 WHERE ro.key = o.key1920 )1921 AND NOT EXISTS (1922 SELECT 11923 FROM pending_objects AS po1924 WHERE po.key = o.key1925 )1926 AND o.deleted_at IS NULL -- Only mark fresh objects1927 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1928 FOR UPDATE1929 )1930 UPDATE objects1931 SET1932 deleted_at = ct.now,1933 first_deleted_at = COALESCE(first_deleted_at, ct.now)1934 FROM stale_objects, ct1935 WHERE objects.key = stale_objects.key1936 1937--- PASS: TestService_AuthMiddleware_OIDC (0.48s)1938 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1939 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1940 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1942--- PASS: TestGCEndsOnShutdown (0.00s)1943 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.31s)1944 --- PASS: TestGCEndsOnShutdown/before_the_run (0.32s)1945 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)19462026/10/06 09:19:30 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19472026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures1948--- PASS: TestPushWaitsForSweepHoldingRow (0.94s)19492026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19502026/10/06 09:19:30 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LjU1ODBkZjBiLWMwZTQtNDM1Zi04NDc5LTZmMjczNTY3MDBmZXgxNzkxMjc4MzcwNDkwMzQzNzQw parts=1019512026/10/06 09:19:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19522026/10/06 09:19:30 INFO Completed upload id=119532026/10/06 09:19:30 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019542026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures19552026/10/06 09:19:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures19562026/10/06 09:19:30 INFO Aborted multipart uploads count=0 kept=019572026/10/06 09:19:30 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=019582026/10/06 09:19:30 INFO Vacuumed table table=pending_closures19592026/10/06 09:19:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19602026/10/06 09:19:30 INFO Vacuumed table table=pending_objects19612026/10/06 09:19:30 INFO Vacuumed table table=multipart_uploads19622026/10/06 09:19:30 INFO Vacuumed table table=closures19632026/10/06 09:19:30 INFO Vacuumed table table=objects19642026/10/06 09:19:30 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWZkY2EzNzAtNjhlYy00ZDIzLTkyY2MtZjFiYmRjMTA1NDE3LmI0ODRmZWQyLTMyODYtNDgxMC1hZWYxLTQyMGQ0MTFhZjkyZHgxNzkxMjc4MzcwNTE0MDcyMTA4 parts=1019652026/10/06 09:19:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19662026/10/06 09:19:30 INFO Completed upload id=119672026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures19682026/10/06 09:19:30 INFO Received uploads request method=POST path=/api/pending_closures19692026/10/06 09:19:30 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19702026/10/06 09:19:30 WARN Found objects in DB but missing from S3, will re-upload count=11971--- PASS: TestService_verifyS3Integrity (0.68s)19722026/10/06 09:19:30 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001973--- PASS: TestService_createPendingClosureHandler (0.70s)19742026/10/06 09:19:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=856.826581ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1975=== NAME TestOrphanedObjectsGCStressTest1976 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1977 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19782026/10/06 09:19:31 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadElectsOneAndHandsOver (2.90s)1980--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)1981 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1982 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1983 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.08s)1984--- PASS: TestPendingClosureWriteTimeout (0.00s)1985 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1986 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1987 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1988 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.14s)1989=== NAME TestOrphanedObjectsGCStressTest1990 orphaned_objects_gc_test.go:509: Stress test completed successfully:1991 orphaned_objects_gc_test.go:510: - Active objects preserved: 201992 orphaned_objects_gc_test.go:511: - Objects deleted: 2101993 orphaned_objects_gc_test.go:512: - Total GC'd: 2101994--- PASS: TestOrphanedObjectsGCStressTest (1.92s)19952026/10/06 09:19:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019962026/10/06 09:19:31 INFO Received create pin request method=POST path=/api/pins/myapp19972026/10/06 09:19:31 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3123289904/001/store/cr8gpihc1avmbyng17b23hppg0s8a2c8-pinned-file.txt narinfo_key=cr8gpihc1avmbyng17b23hppg0s8a2c8.narinfo19982026/10/06 09:19:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures19992026/10/06 09:19:31 INFO Garbage collection started20002026/10/06 09:19:31 INFO Aborted multipart uploads count=0 kept=020012026/10/06 09:19:31 WARN Force mode enabled - objects will be deleted immediately without grace period20022026/10/06 09:19:31 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=020032026/10/06 09:19:31 INFO Vacuumed table table=pending_closures20042026/10/06 09:19:31 INFO Vacuumed table table=pending_objects20052026/10/06 09:19:31 INFO Vacuumed table table=multipart_uploads20062026/10/06 09:19:31 INFO Vacuumed table table=closures20072026/10/06 09:19:31 INFO Vacuumed table table=objects20082026/10/06 09:19:31 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02009=== NAME TestClientIntegration2010 client_integration_test.go:323: Objects in database after GC:2011 client_integration_test.go:323: Successfully deleted all objects with GC --force2012--- PASS: TestClientIntegration (2.73s)20132026/10/06 09:19:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.481171763s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20142026/10/06 09:19: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-config2015--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.77s)20162026/10/06 09:19:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.493296ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20172026/10/06 09:19:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.822536ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2018=== NAME TestPinProtectsFromGC2019 client_integration_test.go:840: Pin successfully protected closure from garbage collection2020--- PASS: TestPinProtectsFromGC (4.84s)2021--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20222026/10/06 09:19:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=838.32535ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20232026/10/06 09:19:34 WARN Rate limiter enabled after throttle name=s3-test rate=520242026/10/06 09:19:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2025=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2026 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102027 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002028--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.26s)20292026/10/06 09:19:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.507398419s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/06 09:19:36 INFO Aborted multipart uploads count=1 kept=020312026/10/06 09:19:36 INFO Received cleanup request method=DELETE path=/api/pending_closures20322026/10/06 09:19:36 INFO Aborted multipart uploads count=1 kept=02033--- PASS: TestPendingCleanupUsesOneCutoff (6.48s)20342026/10/06 09:19: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"20352026/10/06 09:19: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-config20362026/10/06 09:19:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.713504ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 09:19:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.80853ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20382026/10/06 09:19:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=805.626519ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 09:19:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.479709405s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 09:19: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_closures20412026/10/06 09:19:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.810135ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20422026/10/06 09:19:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.087548ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20432026/10/06 09:19:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=744.171465ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 09:19:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.51346342s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2045--- PASS: TestClientErrorHandling (0.00s)2046 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)2047 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.45s)2048 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.21s)2049PASS2050{"timestamp":"2026-10-06T09:19:42.460726323Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50904","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}20512026-10-06 09:19:42.710 UTC [129] LOG: received smart shutdown request20522026-10-06 09:19:42.713 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120532026-10-06 09:19:42.725 UTC [134] LOG: shutting down20542026-10-06 09:19:42.726 UTC [134] LOG: checkpoint starting: shutdown immediate20552026-10-06 09:19:43.770 UTC [134] LOG: checkpoint complete: wrote 11055 buffers (67.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.203 s, sync=0.808 s, total=1.045 s; sync files=31000, longest=0.002 s, average=0.001 s; distance=428465 kB, estimate=428465 kB; lsn=0/1B9D2198, redo lsn=0/1B9D219820562026-10-06 09:19:43.848 UTC [129] LOG: database system is shut down2057Running OIDC tests...2058=== RUN TestAudienceForIssuer2059=== PAUSE TestAudienceForIssuer2060=== RUN TestGlobMatch2061=== PAUSE TestGlobMatch2062=== RUN TestValidateToken_ValidToken2063=== PAUSE TestValidateToken_ValidToken2064=== RUN TestValidateToken_WrongAudience2065=== PAUSE TestValidateToken_WrongAudience2066=== RUN TestValidateToken_Expired2067=== PAUSE TestValidateToken_Expired2068=== RUN TestValidateToken_BoundClaimsMismatch2069=== PAUSE TestValidateToken_BoundClaimsMismatch2070=== RUN TestValidateToken_BoundSubjectMismatch2071=== PAUSE TestValidateToken_BoundSubjectMismatch2072=== RUN TestValidateToken_MultipleProviders2073=== PAUSE TestValidateToken_MultipleProviders2074=== RUN TestValidateToken_NoMatchingProvider2075=== PAUSE TestValidateToken_NoMatchingProvider2076=== RUN TestValidateToken_KubernetesServiceAccount2077=== PAUSE TestValidateToken_KubernetesServiceAccount2078=== RUN TestNewValidator_KubernetesRequiresCA2079=== PAUSE TestNewValidator_KubernetesRequiresCA2080=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2081=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2082=== RUN TestPins_ReservedForMatchingRule2083=== PAUSE TestPins_ReservedForMatchingRule2084=== RUN TestPins_TopLevelShorthand2085=== PAUSE TestPins_TopLevelShorthand2086=== RUN TestPins_ConfigValidation2087=== PAUSE TestPins_ConfigValidation2088=== RUN TestScopes_LegacyProviderDefaultsToWrite2089=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2090=== RUN TestScopes_Rules2091=== PAUSE TestScopes_Rules2092=== RUN TestScopes_ConfigValidation2093=== PAUSE TestScopes_ConfigValidation2094=== CONT TestAudienceForIssuer2095=== CONT TestValidateToken_BoundClaimsMismatch2096=== CONT TestValidateToken_WrongAudience2097--- PASS: TestAudienceForIssuer (0.00s)2098=== CONT TestValidateToken_ValidToken2099=== CONT TestGlobMatch2100=== RUN TestGlobMatch/foo_foo2101=== PAUSE TestGlobMatch/foo_foo2102=== RUN TestGlobMatch/foo_bar2103=== PAUSE TestGlobMatch/foo_bar2104=== RUN TestGlobMatch/*_2105=== PAUSE TestGlobMatch/*_2106=== RUN TestGlobMatch/*_anything2107=== CONT TestValidateToken_Expired2108=== CONT TestValidateToken_MultipleProviders2109=== CONT TestValidateToken_NoMatchingProvider2110=== CONT TestValidateToken_KubernetesServiceAccount2111=== CONT TestPins_ConfigValidation2112=== CONT TestScopes_ConfigValidation2113=== CONT TestScopes_Rules2114=== CONT TestPins_TopLevelShorthand2115=== CONT TestScopes_LegacyProviderDefaultsToWrite2116=== CONT TestPins_ReservedForMatchingRule2117=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2118=== CONT TestNewValidator_KubernetesRequiresCA2119=== CONT TestValidateToken_BoundSubjectMismatch2120=== PAUSE TestGlobMatch/*_anything2121=== RUN TestGlobMatch/foo*_foo2122=== PAUSE TestGlobMatch/foo*_foo2123=== RUN TestGlobMatch/foo*_foobar2124=== PAUSE TestGlobMatch/foo*_foobar2125=== RUN TestGlobMatch/foo*_bar2126=== PAUSE TestGlobMatch/foo*_bar2127=== RUN TestGlobMatch/*bar_bar2128=== PAUSE TestGlobMatch/*bar_bar2129=== RUN TestGlobMatch/*bar_foobar2130=== PAUSE TestGlobMatch/*bar_foobar2131=== RUN TestGlobMatch/*bar_foo2132=== PAUSE TestGlobMatch/*bar_foo2133=== RUN TestGlobMatch/foo*bar_foobar2134=== PAUSE TestGlobMatch/foo*bar_foobar2135=== RUN TestGlobMatch/foo*bar_foo123bar2136=== PAUSE TestGlobMatch/foo*bar_foo123bar2137=== RUN TestGlobMatch/foo*bar_foobarbaz2138=== PAUSE TestGlobMatch/foo*bar_foobarbaz2139=== RUN TestGlobMatch/*/*_foo/bar2140=== PAUSE TestGlobMatch/*/*_foo/bar2141=== RUN TestGlobMatch/*/*_foo2142=== PAUSE TestGlobMatch/*/*_foo2143=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2144=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2145=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02146=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02147=== RUN TestGlobMatch/refs/*/main_refs/heads/main2148=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2149=== RUN TestGlobMatch/fo?_foo2150=== PAUSE TestGlobMatch/fo?_foo2151=== RUN TestGlobMatch/fo?_fo2152=== PAUSE TestGlobMatch/fo?_fo2153=== RUN TestGlobMatch/fo?_fooo2154=== PAUSE TestGlobMatch/fo?_fooo2155=== RUN TestGlobMatch/?oo_foo2156=== PAUSE TestGlobMatch/?oo_foo2157=== RUN TestGlobMatch/?oo_boo2158=== PAUSE TestGlobMatch/?oo_boo2159=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2160=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2161=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2162=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2163=== CONT TestGlobMatch/foo_foo2164=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2165=== CONT TestGlobMatch/*bar_foobar2166=== CONT TestGlobMatch/*/*_foo2167=== CONT TestGlobMatch/*/*_foo/bar2168=== CONT TestGlobMatch/foo*bar_foobar2169=== CONT TestGlobMatch/*bar_foo2170=== CONT TestGlobMatch/?oo_boo2171=== CONT TestGlobMatch/?oo_foo2172=== CONT TestGlobMatch/foo*bar_foo123bar2173=== CONT TestGlobMatch/fo?_fooo2174=== CONT TestGlobMatch/fo?_fo2175=== CONT TestGlobMatch/fo?_foo2176=== CONT TestGlobMatch/refs/*/main_refs/heads/main2177=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02178=== CONT TestGlobMatch/foo*bar_foobarbaz2179=== CONT TestGlobMatch/foo*_foo2180--- PASS: TestScopes_ConfigValidation (0.00s)2181=== CONT TestGlobMatch/*bar_bar2182=== CONT TestGlobMatch/foo*_bar2183=== CONT TestGlobMatch/foo*_foobar2184=== CONT TestGlobMatch/*_2185=== CONT TestGlobMatch/*_anything2186=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2187=== CONT TestGlobMatch/foo_bar2188=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2189--- PASS: TestGlobMatch (0.00s)2190 --- PASS: TestGlobMatch/foo_foo (0.00s)2191 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2192 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2193 --- PASS: TestGlobMatch/*/*_foo (0.00s)2194 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2195 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2196 --- PASS: TestGlobMatch/*bar_foo (0.00s)2197 --- PASS: TestGlobMatch/?oo_boo (0.00s)2198 --- PASS: TestGlobMatch/?oo_foo (0.00s)2199 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2200 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fo (0.00s)2202 --- PASS: TestGlobMatch/fo?_foo (0.00s)2203 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2204 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2206 --- PASS: TestGlobMatch/foo*_foo (0.00s)2207 --- PASS: TestGlobMatch/*bar_bar (0.00s)2208 --- PASS: TestGlobMatch/foo*_bar (0.00s)2209 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2210 --- PASS: TestGlobMatch/*_ (0.00s)2211 --- PASS: TestGlobMatch/*_anything (0.00s)2212 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2213 --- PASS: TestGlobMatch/foo_bar (0.00s)2214 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2215--- PASS: TestPins_ConfigValidation (0.00s)22162026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46271/oidc2217--- PASS: TestPins_ReservedForMatchingRule (0.04s)22182026/10/06 09:19:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:404032219--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)22202026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39283/oidc22212026/10/06 09:19:45 http: TLS handshake error from 127.0.0.1:51952: remote error: tls: bad certificate2222--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)2223--- PASS: TestValidateToken_WrongAudience (0.08s)22242026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36357/oidc2225--- PASS: TestValidateToken_Expired (0.10s)22262026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33233/oidc2227--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)22282026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38479/oidc2229--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.15s)22302026/10/06 09:19:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322312026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37333/oidc2232--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.17s)2233--- PASS: TestScopes_Rules (0.18s)22342026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38475/oidc2235--- PASS: TestValidateToken_ValidToken (0.18s)22362026/10/06 09:19:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42889/oidc22372026/10/06 09:19:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35249/oidc2238--- PASS: TestValidateToken_MultipleProviders (0.27s)22392026/10/06 09:19:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35593/oidc2240--- PASS: TestValidateToken_BoundClaimsMismatch (0.31s)22412026/10/06 09:19:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37753/oidc2242--- PASS: TestValidateToken_NoMatchingProvider (0.33s)22432026/10/06 09:19:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41607/oidc2244--- PASS: TestPins_TopLevelShorthand (0.62s)2245PASS2246Running hook tests...2247=== RUN TestSendPathsEmpty2248=== PAUSE TestSendPathsEmpty2249=== RUN TestQueueEnqueueAndFetch2250=== PAUSE TestQueueEnqueueAndFetch2251=== RUN TestQueueDeduplication2252=== PAUSE TestQueueDeduplication2253=== RUN TestQueueRemove2254=== PAUSE TestQueueRemove2255=== RUN TestQueueFetchBatchLimit2256=== PAUSE TestQueueFetchBatchLimit2257=== RUN TestQueueRetryMovesToBack2258=== PAUSE TestQueueRetryMovesToBack2259=== RUN TestQueueFetchRemoveLifecycle2260=== PAUSE TestQueueFetchRemoveLifecycle2261=== RUN TestQueueConcurrentWriters2262=== PAUSE TestQueueConcurrentWriters2263=== RUN TestQueueRemoveLargeClosure2264=== PAUSE TestQueueRemoveLargeClosure2265=== RUN TestServerClientIntegration2266=== PAUSE TestServerClientIntegration2267=== RUN TestServerQueueError2268=== PAUSE TestServerQueueError2269=== RUN TestGetListenerSocketActivation2270 server_test.go:210: === RUN TestGetListenerSocketActivation2271 --- PASS: TestGetListenerSocketActivation (0.00s)2272 PASS2273 2274--- PASS: TestGetListenerSocketActivation (0.01s)2275=== RUN TestDrainIsolatesPoisonPath2276=== PAUSE TestDrainIsolatesPoisonPath2277=== RUN TestRunNotBlockedByPoisonHead2278=== PAUSE TestRunNotBlockedByPoisonHead2279=== RUN TestDrainGivesUpWhenServerDown2280=== PAUSE TestDrainGivesUpWhenServerDown2281=== RUN TestFailedPathPrunedByLaterClosure2282=== PAUSE TestFailedPathPrunedByLaterClosure2283=== RUN TestWorkerUploadsAndRemoves2284=== PAUSE TestWorkerUploadsAndRemoves2285=== RUN TestWorkerSkipsGCdPaths2286=== PAUSE TestWorkerSkipsGCdPaths2287=== RUN TestWorkerPrunesClosureDeps2288=== PAUSE TestWorkerPrunesClosureDeps2289=== RUN TestDrainTimeout2290=== PAUSE TestDrainTimeout2291=== CONT TestSendPathsEmpty2292--- PASS: TestSendPathsEmpty (0.00s)2293=== CONT TestFailedPathPrunedByLaterClosure2294=== CONT TestQueueRemove2295=== CONT TestQueueFetchRemoveLifecycle2296=== CONT TestQueueDeduplication2297=== CONT TestQueueEnqueueAndFetch2298=== CONT TestWorkerPrunesClosureDeps2299=== CONT TestDrainTimeout2300=== CONT TestQueueRetryMovesToBack2301=== CONT TestQueueFetchBatchLimit2302=== CONT TestDrainIsolatesPoisonPath2303=== CONT TestDrainGivesUpWhenServerDown2304=== CONT TestRunNotBlockedByPoisonHead2305=== CONT TestWorkerSkipsGCdPaths2306=== CONT TestServerClientIntegration2307=== CONT TestServerQueueError2308=== CONT TestQueueRemoveLargeClosure2309=== CONT TestWorkerUploadsAndRemoves2310=== CONT TestQueueConcurrentWriters23112026/10/06 09:19:46 ERROR Failed to queue paths error="permission denied" count=12312--- PASS: TestServerClientIntegration (0.00s)2313--- PASS: TestServerQueueError (0.00s)23142026/10/06 09:19:46 INFO Upload queue status pending=223152026/10/06 09:19:46 INFO Uploading batch count=123162026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=123172026/10/06 09:19:46 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3450016888/002/nonexistent23182026/10/06 09:19:46 INFO Uploading batch count=223192026/10/06 09:19:46 INFO Uploading batch count=223202026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=223212026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/a23222026/10/06 09:19:46 INFO Uploading batch count=423232026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=423242026/10/06 09:19:46 INFO Upload queue status pending=223252026/10/06 09:19:46 INFO Uploading batch count=123262026/10/06 09:19:46 INFO Uploading batch count=12327--- PASS: TestQueueEnqueueAndFetch (0.02s)2328--- PASS: TestQueueDeduplication (0.02s)2329--- PASS: TestQueueRemove (0.02s)23302026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3160869433/002/bbb23312026/10/06 09:19:46 INFO Uploading batch count=123322026/10/06 09:19:46 INFO Upload queue status pending=32333--- PASS: TestQueueRetryMovesToBack (0.02s)23342026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/b23352026/10/06 09:19:46 INFO Uploading batch count=123362026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=123372026/10/06 09:19:46 INFO Uploading batch count=12338--- PASS: TestQueueFetchBatchLimit (0.02s)2339--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23402026/10/06 09:19:46 INFO Upload queue status pending=223412026/10/06 09:19:46 INFO Uploading batch count=223422026/10/06 09:19:46 INFO Uploading batch count=223432026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=223442026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/c23452026/10/06 09:19:46 INFO Uploading batch count=123462026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=123472026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/d23482026/10/06 09:19:46 INFO Uploading batch count=223492026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=223502026/10/06 09:19:46 INFO Uploading batch count=123512026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=123522026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/e2353--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)23542026/10/06 09:19:46 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown988423597/002/f23552026/10/06 09:19:46 INFO Uploading batch count=123562026/10/06 09:19:46 ERROR Upload failed error="upload failed" count=123572026/10/06 09:19:46 ERROR Drain finished with paths left in queue remaining=1023582026/10/06 09:19:46 ERROR Drain finished with paths left in queue remaining=12359--- PASS: TestDrainIsolatesPoisonPath (0.03s)2360--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2361--- PASS: TestWorkerPrunesClosureDeps (0.04s)2362--- PASS: TestWorkerSkipsGCdPaths (0.04s)2363--- PASS: TestWorkerUploadsAndRemoves (0.04s)2364--- PASS: TestQueueRemoveLargeClosure (0.15s)2365--- PASS: TestQueueConcurrentWriters (0.21s)23662026/10/06 09:19:46 ERROR Upload failed error="context deadline exceeded" count=223672026/10/06 09:19:46 ERROR Drain finished with paths left in queue remaining=42368--- PASS: TestDrainTimeout (0.22s)23692026/10/06 09:19:47 INFO Uploading batch count=123702026/10/06 09:19:47 INFO Uploading batch count=123712026/10/06 09:19:47 INFO Uploading batch count=123722026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123732026/10/06 09:19:47 INFO Uploading batch count=123742026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123752026/10/06 09:19:47 INFO Uploading batch count=123762026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123772026/10/06 09:19:47 INFO Uploading batch count=123782026/10/06 09:19:47 ERROR Upload failed error="upload failed" count=123792026/10/06 09:19:47 ERROR Drain finished with paths left in queue remaining=12380--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2381PASS2382Running signing tests...2383=== RUN TestExternalSigner2384=== PAUSE TestExternalSigner2385=== RUN TestExternalSignerWrongPublicKey2386=== PAUSE TestExternalSignerWrongPublicKey2387=== RUN TestExternalSignerErrors2388=== PAUSE TestExternalSignerErrors2389=== RUN TestExternalSignerRestartsAfterCrash2390=== PAUSE TestExternalSignerRestartsAfterCrash2391=== RUN TestExternalSignerProgramErrorKeepsProcess2392=== PAUSE TestExternalSignerProgramErrorKeepsProcess2393=== RUN TestExternalSignerClose2394=== PAUSE TestExternalSignerClose2395=== RUN TestExternalSignerRejectsInvalidPublicKey2396=== PAUSE TestExternalSignerRejectsInvalidPublicKey2397=== RUN TestExternalSignerCancellation2398=== PAUSE TestExternalSignerCancellation2399=== RUN TestGenerateFingerprint2400=== PAUSE TestGenerateFingerprint2401=== RUN TestParseSigningKey2402=== PAUSE TestParseSigningKey2403=== RUN TestSign2404=== PAUSE TestSign2405=== RUN TestSignBatch2406=== PAUSE TestSignBatch2407=== RUN TestNilKeyPublicKey2408=== PAUSE TestNilKeyPublicKey2409=== RUN TestSignErrors2410=== PAUSE TestSignErrors2411=== CONT TestExternalSigner2412=== CONT TestSignBatch2413=== CONT TestSign2414=== CONT TestExternalSignerCancellation2415=== CONT TestSignErrors2416=== CONT TestExternalSignerProgramErrorKeepsProcess2417=== CONT TestExternalSignerRejectsInvalidPublicKey2418=== RUN TestExternalSignerRejectsInvalidPublicKey/#002419=== CONT TestExternalSignerClose2420=== CONT TestParseSigningKey2421=== RUN TestParseSigningKey/valid_32-byte_key2422=== PAUSE TestParseSigningKey/valid_32-byte_key2423=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2424=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2425=== RUN TestParseSigningKey/no_colon2426=== PAUSE TestParseSigningKey/no_colon2427=== RUN TestParseSigningKey/empty_name2428=== PAUSE TestParseSigningKey/empty_name2429=== RUN TestParseSigningKey/invalid_base642430=== CONT TestGenerateFingerprint2431=== CONT TestExternalSignerErrors2432=== RUN TestGenerateFingerprint/basic_with_references2433=== RUN TestExternalSignerErrors/too_few_signatures2434=== CONT TestExternalSignerRestartsAfterCrash2435=== PAUSE TestGenerateFingerprint/basic_with_references2436=== RUN TestGenerateFingerprint/no_references2437=== PAUSE TestGenerateFingerprint/no_references2438=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2439=== CONT TestExternalSignerWrongPublicKey2440=== CONT TestNilKeyPublicKey2441--- PASS: TestNilKeyPublicKey (0.00s)2442=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002443=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2444=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2445=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2446=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2447=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2449=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2450=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2451=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2452=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2453=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2454=== RUN TestGenerateFingerprint/invalid_nar_hash_length2455=== PAUSE TestExternalSignerErrors/too_few_signatures2456=== RUN TestExternalSignerErrors/missing_signature_name2457=== PAUSE TestExternalSignerErrors/missing_signature_name2458=== RUN TestExternalSignerErrors/wrong_signature_name2459=== PAUSE TestExternalSignerErrors/wrong_signature_name2460=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2461=== RUN TestGenerateFingerprint/invalid_store_path_prefix2462=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2463=== RUN TestGenerateFingerprint/invalid_reference_prefix2464=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2465=== CONT TestGenerateFingerprint/basic_with_references2466=== CONT TestGenerateFingerprint/invalid_nar_hash_length2467=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2468=== PAUSE TestParseSigningKey/invalid_base642469=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2470=== RUN TestExternalSignerErrors/exit_at_startup2471=== PAUSE TestExternalSignerErrors/exit_at_startup2472=== RUN TestExternalSignerErrors/invalid_JSON2473=== PAUSE TestExternalSignerErrors/invalid_JSON2474=== RUN TestExternalSignerErrors/wrong_shape2475=== PAUSE TestExternalSignerErrors/wrong_shape2476=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2477=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2478=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2479=== CONT TestExternalSignerRejectsInvalidPublicKey/#002480--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2481 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2482 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2483 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2484 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2485 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2486=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2487=== CONT TestGenerateFingerprint/no_references2488=== CONT TestGenerateFingerprint/invalid_reference_prefix2489=== CONT TestGenerateFingerprint/invalid_store_path_prefix2490--- PASS: TestGenerateFingerprint (0.00s)2491 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2492 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2493 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2494 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2495 --- PASS: TestGenerateFingerprint/no_references (0.00s)2496 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2497 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2498=== RUN TestParseSigningKey/wrong_length2499=== PAUSE TestParseSigningKey/wrong_length2500=== CONT TestParseSigningKey/valid_32-byte_key2501=== CONT TestParseSigningKey/no_colon2502=== RUN TestExternalSignerErrors/null2503=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2504=== CONT TestParseSigningKey/empty_name2505=== CONT TestParseSigningKey/invalid_base642506=== CONT TestParseSigningKey/wrong_length2507=== PAUSE TestExternalSignerErrors/null2508=== RUN TestExternalSignerErrors/wrong_signature_length2509=== PAUSE TestExternalSignerErrors/wrong_signature_length2510=== RUN TestExternalSignerErrors/program_error2511=== PAUSE TestExternalSignerErrors/program_error2512=== RUN TestExternalSignerErrors/exit_on_request2513=== PAUSE TestExternalSignerErrors/exit_on_request2514=== RUN TestExternalSignerErrors/null_signatures2515=== PAUSE TestExternalSignerErrors/null_signatures2516=== RUN TestExternalSignerErrors/wrong_signatures_shape2517=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2518=== RUN TestExternalSignerErrors/unrequested_key2519=== PAUSE TestExternalSignerErrors/unrequested_key2520=== RUN TestExternalSignerErrors/invalid_signature_base642521=== PAUSE TestExternalSignerErrors/invalid_signature_base642522=== RUN TestExternalSignerErrors/wrong_id2523=== PAUSE TestExternalSignerErrors/wrong_id2524=== RUN TestExternalSignerErrors/missing_signatures2525=== PAUSE TestExternalSignerErrors/missing_signatures2526=== CONT TestExternalSignerErrors/too_few_signatures2527=== CONT TestExternalSignerErrors/program_error2528=== CONT TestExternalSignerErrors/unrequested_key2529=== CONT TestExternalSignerErrors/missing_signatures2530=== CONT TestExternalSignerErrors/missing_signature_name2531=== CONT TestExternalSignerErrors/null2532=== CONT TestExternalSignerErrors/wrong_id2533=== CONT TestExternalSignerErrors/invalid_signature_base642534=== CONT TestExternalSignerErrors/null_signatures2535=== CONT TestExternalSignerErrors/invalid_JSON2536=== CONT TestExternalSignerErrors/wrong_signatures_shape2537=== CONT TestExternalSignerErrors/wrong_signature_length2538=== CONT TestExternalSignerErrors/exit_on_request2539=== CONT TestExternalSignerErrors/wrong_shape2540=== CONT TestExternalSignerErrors/wrong_signature_name2541=== RUN TestSignErrors/nil_key2542--- PASS: TestParseSigningKey (0.00s)2543 --- PASS: TestParseSigningKey/no_colon (0.00s)2544 --- PASS: TestParseSigningKey/empty_name (0.00s)2545 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2546 --- PASS: TestParseSigningKey/wrong_length (0.00s)2547 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2548 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2549--- PASS: TestSign (0.00s)2550--- PASS: TestSignBatch (0.00s)2551=== CONT TestExternalSignerErrors/exit_at_startup2552=== PAUSE TestSignErrors/nil_key2553=== RUN TestSignErrors/nil_narinfo2554=== PAUSE TestSignErrors/nil_narinfo2555=== RUN TestSignErrors/invalid_narinfo2556=== PAUSE TestSignErrors/invalid_narinfo2557=== RUN TestSignErrors/canceled2558=== PAUSE TestSignErrors/canceled2559=== CONT TestSignErrors/nil_key2560=== CONT TestSignErrors/invalid_narinfo2561=== CONT TestSignErrors/canceled2562=== CONT TestSignErrors/nil_narinfo2563--- PASS: TestSignErrors (0.01s)2564 --- PASS: TestSignErrors/nil_key (0.00s)2565 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2566 --- PASS: TestSignErrors/canceled (0.00s)2567 --- PASS: TestSignErrors/nil_narinfo (0.00s)2568--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2569--- PASS: TestExternalSignerWrongPublicKey (0.01s)2570--- PASS: TestExternalSignerClose (0.01s)2571--- PASS: TestExternalSigner (0.01s)2572--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2573--- PASS: TestExternalSignerErrors (0.00s)2574 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2575 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2576 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2577 --- PASS: TestExternalSignerErrors/program_error (0.00s)2578 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2579 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2580 --- PASS: TestExternalSignerErrors/null (0.01s)2581 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2582 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2583 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2584 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2585 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2586 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2587 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2588 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2589 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2590--- PASS: TestExternalSignerCancellation (0.02s)2591PASS2592Running OpenBao signer tests...2593=== RUN TestSign2594=== PAUSE TestSign2595=== RUN TestSignErrors2596=== PAUSE TestSignErrors2597=== RUN TestServe2598=== PAUSE TestServe2599=== RUN TestServeRejectsGarbage2600=== PAUSE TestServeRejectsGarbage2601=== CONT TestSign2602=== CONT TestSignErrors2603=== CONT TestServe2604=== RUN TestSignErrors/http_error2605=== PAUSE TestSignErrors/http_error2606=== RUN TestSignErrors/invalid_json2607=== PAUSE TestSignErrors/invalid_json2608=== RUN TestSignErrors/no_prefix2609=== PAUSE TestSignErrors/no_prefix2610=== RUN TestSignErrors/invalid_base642611=== PAUSE TestSignErrors/invalid_base642612=== CONT TestSignErrors/http_error2613=== CONT TestServeRejectsGarbage2614=== CONT TestSignErrors/invalid_json2615--- PASS: TestServeRejectsGarbage (0.00s)2616--- PASS: TestServe (0.00s)2617=== CONT TestSignErrors/no_prefix2618=== CONT TestSignErrors/invalid_base642619--- PASS: TestSignErrors (0.00s)2620 --- PASS: TestSignErrors/invalid_json (0.00s)2621 --- PASS: TestSignErrors/http_error (0.00s)2622 --- PASS: TestSignErrors/invalid_base64 (0.00s)2623 --- PASS: TestSignErrors/no_prefix (0.00s)2624--- PASS: TestSign (0.00s)2625PASS