niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #387
· 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.03s)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 TestScriptTokenEmptyToken101=== CONT TestScriptTokenScriptFails102=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess103=== CONT TestScriptTokenCachesUntilRefresh104=== CONT TestScriptTokenNoExpiryRerunsEveryCall1052026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5106=== CONT TestFileTokenEmpty107=== CONT TestFileTokenMissing108=== CONT TestScriptTokenEmptyCommand109=== CONT TestFileTokenReadsAndCaches110=== CONT TestStaticToken111=== CONT TestStreamPushGivesUpOnDeadServer112=== CONT TestStreamPushIsolatesFailures113=== CONT TestStreamPushBatchesUnderLoad114=== CONT TestSetClientTLSErrors115=== CONT TestStreamPushReportsEveryPath116=== CONT TestSetClientTLSDoesNotMutateDefaultTransport117=== CONT TestUploadMultipart_PartsInParallel118=== CONT TestDumpPathSingleFile119=== CONT TestStreamPushRequestLine120=== CONT TestFilterOversizedClosures121=== CONT TestSetClientTLS122=== CONT TestShellSplit123=== CONT TestClientSignaturesByStorePath124=== CONT TestDoWithRetry_BodyReplayedViaGetBody125=== CONT TestStreamPushReportsSignatures126=== CONT TestResolveStorePath127--- PASS: TestScriptTokenScriptFails (0.00s)128=== CONT TestScriptTokenBadJSON129--- PASS: TestFileTokenEmpty (0.00s)130--- PASS: TestScriptTokenEmptyCommand (0.00s)131--- PASS: TestScriptTokenEmptyToken (0.00s)132--- PASS: TestStaticToken (0.00s)133--- PASS: TestFileTokenMissing (0.00s)1342026/10/06 21:24:02 ERROR Upload failed error="connection refused" count=201352026/10/06 21:24:02 ERROR Server seems unavailable, giving up on batch untried=17136=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1372026/10/06 21:24:02 ERROR Upload failed error=boom count=1138=== CONT TestShellSplitErrors139=== CONT TestRegisterUploadedObjectReusesConnections140=== CONT TestPathInfoHashCompatibility141=== RUN TestFilterOversizedClosures/no_limit_keeps_everything142=== CONT TestDumpPathMatchesNix143=== CONT TestCaseHackSuffix144--- PASS: TestClientSignaturesByStorePath (0.00s)145=== RUN TestSetClientTLSErrors/missing_cert_file146=== RUN TestSetClientTLS/rejects_connection_without_client_cert147=== CONT TestPartSizeForNAR148--- PASS: TestShellSplit (0.00s)1492026/10/06 21:24:02 ERROR Upload failed error=boom count=1150=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert151=== CONT TestRateLimiterFeedback1522026/10/06 21:24:02 ERROR Upload failed error="bad path" count=3153=== RUN TestRateLimiterFeedback/429_enables_limiter154=== PAUSE TestRateLimiterFeedback/429_enables_limiter155=== RUN TestRateLimiterFeedback/503_enables_limiter156=== PAUSE TestRateLimiterFeedback/503_enables_limiter157=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter158=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter159=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter160=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter161=== CONT TestConvertHashToNix32162=== RUN TestConvertHashToNix32/SRI_format_to_Nix32163=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32164=== RUN TestConvertHashToNix32/already_Nix32_format165=== PAUSE TestConvertHashToNix32/already_Nix32_format166=== RUN TestConvertHashToNix32/invalid_format167=== PAUSE TestConvertHashToNix32/invalid_format168=== CONT TestPathInfoCACompatibility169=== RUN TestPathInfoCACompatibility/null_ca_field170=== PAUSE TestPathInfoCACompatibility/null_ca_field171=== RUN TestPathInfoCACompatibility/old_string_format_-_text172=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text173=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive174=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== RUN TestPathInfoCACompatibility/new_structured_format_-_text1762026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5177=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text1782026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34635179=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method180=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method181=== CONT TestParsePathInfoJSONMultiplePaths182=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA187=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA188=== RUN TestSetClientTLS/preserves_debug_logging_transport189=== PAUSE TestSetClientTLS/preserves_debug_logging_transport190=== CONT TestParsePathInfoJSON191=== RUN TestParsePathInfoJSON/Nix_format192=== PAUSE TestParsePathInfoJSON/Nix_format193=== RUN TestParsePathInfoJSON/Lix_format1942026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=51952026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:34635196=== PAUSE TestParsePathInfoJSON/Lix_format197=== RUN TestParsePathInfoJSON/empty_input198=== PAUSE TestParsePathInfoJSON/empty_input199=== RUN TestParsePathInfoJSON/whitespace_only200--- PASS: TestFileTokenReadsAndCaches (0.00s)201=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything202=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)203=== RUN TestPartSizeForNAR/zero_stays_at_minimum204=== CONT TestUploadMultipart_SupersededByPeer205=== PAUSE TestSetClientTLSErrors/missing_cert_file206=== CONT TestGetStorePathHash207=== CONT TestEncodeNixBase32WithRealHash208=== CONT TestRateLimiterFeedback/429_enables_limiter209=== CONT TestEncodeNixBase32210=== RUN TestEncodeNixBase32/test_string_hash211=== PAUSE TestEncodeNixBase32/test_string_hash212=== RUN TestEncodeNixBase32/empty_input213=== PAUSE TestEncodeNixBase32/empty_input214=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica215=== CONT TestDumpPathWriterError2162026/10/06 21:24:02 INFO Garbage collection started217=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths218=== RUN TestUploadMultipart_SupersededByPeer/exists219=== PAUSE TestUploadMultipart_SupersededByPeer/exists220=== RUN TestUploadMultipart_SupersededByPeer/missing221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== PAUSE TestParsePathInfoJSON/whitespace_only223=== RUN TestParsePathInfoJSON/invalid_JSON224=== PAUSE TestParsePathInfoJSON/invalid_JSON2252026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5226=== CONT TestPathInfoCACompatibility/null_ca_field2272026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:34613228=== CONT TestSetClientTLS/rejects_connection_without_client_cert229=== CONT TestConvertHashToNix32/SRI_format_to_Nix32230=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231--- PASS: TestResolveStorePath (0.00s)232--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)233--- PASS: TestStreamPushReportsEveryPath (0.03s)234--- PASS: TestShellSplitErrors (0.00s)235--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)236--- PASS: TestDoServerRequestAttachesToken (0.03s)237=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2382026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=5239--- PASS: TestStreamPushReportsSignatures (0.03s)240--- PASS: TestStreamPushIsolatesFailures (0.03s)241--- PASS: TestEncodeNixBase32WithRealHash (0.00s)242--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)243--- PASS: TestScriptTokenBadJSON (0.03s)244=== CONT TestConvertHashToNix32/already_Nix32_format245=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2462026/10/06 21:24:02 INFO Garbage collection started247=== CONT TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestPathInfoCACompatibility/old_string_format_-_text249--- PASS: TestPathInfoCACompatibility (0.00s)250 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)251 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)252 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)253 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)254 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)255=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)256=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon257=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon258=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI260=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512261=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512262=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum263=== RUN TestPartSizeForNAR/small_stays_at_minimum264=== PAUSE TestPartSizeForNAR/small_stays_at_minimum265=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum266=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum267=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts268=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts269=== RUN TestPartSizeForNAR/1_TiB270=== PAUSE TestPartSizeForNAR/1_TiB271=== RUN TestPartSizeForNAR/5_TiB_S3_max_object272=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object273=== RUN TestPartSizeForNAR/capped_at_5_GiB274=== PAUSE TestPartSizeForNAR/capped_at_5_GiB275=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped276=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped277=== RUN TestFilterOversizedClosures/all_closures_skipped278=== PAUSE TestFilterOversizedClosures/all_closures_skipped279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths280=== CONT TestParsePathInfoJSON/Nix_format281=== CONT TestEncodeNixBase32/test_string_hash282=== CONT TestParsePathInfoJSON/invalid_JSON283=== CONT TestParsePathInfoJSON/whitespace_only284=== CONT TestParsePathInfoJSON/empty_input285=== CONT TestParsePathInfoJSON/Lix_format286=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287=== CONT TestPartSizeForNAR/zero_stays_at_minimum288=== CONT TestPartSizeForNAR/1_TiB289=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI291=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon292=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts293=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum294=== CONT TestPartSizeForNAR/small_stays_at_minimum295=== CONT TestFilterOversizedClosures/all_closures_skipped2962026/10/06 21:24:02 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50297=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2982026/10/06 21:24:02 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0299=== CONT TestUploadMultipart_SupersededByPeer/exists3002026/10/06 21:24:02 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000301=== CONT TestPartSizeForNAR/5_TiB_S3_max_object302=== CONT TestFilterOversizedClosures/no_limit_keeps_everything303--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)304--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)305 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)306 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)307=== CONT TestPartSizeForNAR/capped_at_5_GiB308=== RUN TestGetStorePathHash/valid_store_path309=== PAUSE TestGetStorePathHash/valid_store_path310=== RUN TestGetStorePathHash/basename_without_hyphen_should_error311=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error312=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error313=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error314=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error315=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error316=== CONT TestGetStorePathHash/valid_store_path317=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter318=== CONT TestGetStorePathHash/basename_without_hyphen_should_error319=== CONT TestRateLimiterFeedback/503_enables_limiter320=== CONT TestConvertHashToNix32/invalid_format321=== CONT TestEncodeNixBase32/empty_input322=== CONT TestUploadMultipart_SupersededByPeer/missing323=== RUN TestSetClientTLSErrors/missing_key_file324=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA325=== CONT TestSetClientTLS/preserves_debug_logging_transport326=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error327=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error328=== PAUSE TestSetClientTLSErrors/missing_key_file329=== RUN TestSetClientTLSErrors/missing_ca_file330--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)3312026/10/06 21:24:02 WARN Garbage collection finished on another replica. Its statistics are not available here332--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)3332026/10/06 21:24:02 WARN Rate limiter enabled after throttle name=server-test rate=5334--- PASS: TestPartSizeForNAR (0.00s)335 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)336 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)337 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)338 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)339 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)340 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)341 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)3422026/10/06 21:24:02 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:39093343=== PAUSE TestSetClientTLSErrors/missing_ca_file344=== RUN TestSetClientTLSErrors/invalid_ca_file345=== PAUSE TestSetClientTLSErrors/invalid_ca_file346=== CONT TestSetClientTLSErrors/missing_cert_file347--- PASS: TestPathInfoHashCompatibility (0.01s)348 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)350 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)351 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)3522026/10/06 21:24:02 WARN Rate limiter backed off name=server-test rate=5353--- PASS: TestParsePathInfoJSON (0.01s)354 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)355 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)358 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)359--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)360--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)361 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)362 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)363=== CONT TestSetClientTLSErrors/invalid_ca_file364=== CONT TestSetClientTLSErrors/missing_ca_file365--- PASS: TestRateLimiterFeedback (0.00s)366 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)367 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)368 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)369 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)370--- PASS: TestFilterOversizedClosures (0.03s)371 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)372 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)373 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)374--- PASS: TestConvertHashToNix32 (0.00s)375 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)376 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)377 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)378--- PASS: TestEncodeNixBase32 (0.00s)379 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)380 --- PASS: TestEncodeNixBase32/empty_input (0.00s)381--- PASS: TestGetStorePathHash (0.00s)382 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)385 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)386=== CONT TestSetClientTLSErrors/missing_key_file387--- PASS: TestSetClientTLSErrors (0.05s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)3922026/10/06 21:24:02 http: TLS handshake error from 127.0.0.1:34646: remote error: tls: bad certificate393--- PASS: TestSetClientTLS (0.03s)394 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)397--- PASS: TestCaseHackSuffix (0.03s)398--- PASS: TestStreamPushRequestLine (0.06s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)400--- PASS: TestDumpPathSingleFile (0.06s)401--- PASS: TestDumpPathWriterError (0.04s)402--- PASS: TestDumpPathMatchesNix (0.07s)403--- PASS: TestStreamPushBatchesUnderLoad (0.13s)404--- PASS: TestUploadMultipart_PartsInParallel (0.65s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres4009893516/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/postgres4009893516/data -l logfile start434435/build/postgres4009893516:5432 - no response4362026-10-06 21:24:04.055 UTC [130] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 21:24:04.055 UTC [130] LOG: listening on Unix socket "/build/postgres4009893516/.s.PGSQL.5432"4382026-10-06 21:24:04.059 UTC [137] LOG: database system was shut down at 2026-10-06 21:24:03 UTC4392026-10-06 21:24:04.062 UTC [130] LOG: database system is ready to accept connections440/build/postgres4009893516:5432 - accepting connections441{"timestamp":"2026-10-06T21:24:04.25386521Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"cf70f86d-efec-44ce-bb37-72aa5ad744fa","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:24:04 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:24:05 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:24:05 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:24:06 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:24:06 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:24:07.741 UTC [381] FATAL: terminating connection due to administrator command5012026/10/06 21:24:07 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:24:08 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:24:08 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:24:09 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:24:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"679--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)680=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle682=== RUN TestProxyWriteTimeout683=== PAUSE TestProxyWriteTimeout684=== RUN TestPendingClosureWriteTimeout685=== PAUSE TestPendingClosureWriteTimeout686=== RUN TestIsValidUploadKey687=== PAUSE TestIsValidUploadKey688=== RUN TestUploadHandlersRejectInvalidKeys689=== PAUSE TestUploadHandlersRejectInvalidKeys690=== RUN TestUploadHandlersRejectOversizedBody691=== PAUSE TestUploadHandlersRejectOversizedBody692=== RUN TestService_cleanupPendingClosuresHandler693=== PAUSE TestService_cleanupPendingClosuresHandler694=== RUN TestService_createPendingClosureHandler695=== PAUSE TestService_createPendingClosureHandler696=== RUN TestService_verifyS3Integrity697=== PAUSE TestService_verifyS3Integrity698=== RUN TestCompleteMultipartUnregistered699=== PAUSE TestCompleteMultipartUnregistered700=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT701=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle703=== CONT TestService_AuthMiddleware704=== CONT TestSkippedUploadsHandler705=== CONT TestParseSize706--- PASS: TestParseSize (0.00s)707=== CONT TestService_verifyS3Integrity708=== CONT TestService_Rustfstest709=== CONT TestPresignedUploadRegisteredBeforeCommit710=== CONT TestCompletedNarNotReofferedAcrossClosures711=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7122026/10/06 21:24:09 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000713=== CONT TestRedundantMultipartUpload714=== CONT TestPush_SignsNarinfosOfItsPendingObjects715=== CONT TestPush_RejectsBadRequests716=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit717=== CONT TestPush_RootsAreLockedInByteOrder718=== CONT TestPush_CompleteWaitsForCleanupOfThePush719=== CONT TestPush_RepeatedRootCommitsOnce720=== CONT TestPush_CompleteCommitsEveryRoot721=== CONT TestPush_OverlappingRootsStoreOneRowPerKey722=== CONT TestReadRedirectUsesPublicS3URL723--- PASS: TestSkippedUploadsHandler (0.01s)724=== CONT TestReadProxyDisabled725=== CONT TestService_cleanupPendingClosuresHandler726=== CONT TestReadProxyRangeRequest727=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT728=== CONT TestReadRedirectKeepsNarinfoProxied729=== CONT TestCompleteMultipartUnregistered730=== CONT TestReadRedirectNar7312026/10/06 21:24:09 INFO Received uploads request method=POST path=/api/pending_closures7322026/10/06 21:24:09 INFO Received uploads request method=POST path=/api/pending_closures7332026/10/06 21:24:09 INFO Received uploads request method=POST path=/api/pending_closures7342026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures7352026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures7362026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures7372026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7382026/10/06 21:24:10 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7392026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures740--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.47s)741=== CONT TestService_createPendingClosureHandler7422026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures7432026/10/06 21:24:10 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"744--- PASS: TestService_AuthMiddleware (0.50s)745=== CONT TestReadProxyRootRedirectsToIndexHTML7462026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7472026/10/06 21:24:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjY4NzkyMzUwLTFjYjEtNGE5MC04MjllLWI3MmRmNWJiZDM0OHgxNzkxMzIxODUwMDUwMjYyODI57482026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjY4NzkyMzUwLTFjYjEtNGE5MC04MjllLWI3MmRmNWJiZDM0OHgxNzkxMzIxODUwMDUwMjYyODI5 parts=1749=== RUN TestPush_RejectsBadRequests/no_roots750=== PAUSE TestPush_RejectsBadRequests/no_roots751=== RUN TestPush_RejectsBadRequests/no_objects752=== PAUSE TestPush_RejectsBadRequests/no_objects753=== RUN TestPush_RejectsBadRequests/bad_root754=== PAUSE TestPush_RejectsBadRequests/bad_root755=== RUN TestPush_RejectsBadRequests/root_not_in_objects756=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects757=== CONT TestReadProxyConditionalGet758--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.51s)759=== CONT TestPendingClosureWriteTimeout760=== RUN TestPendingClosureWriteTimeout/empty761=== PAUSE TestPendingClosureWriteTimeout/empty762=== RUN TestPendingClosureWriteTimeout/400_objects763=== PAUSE TestPendingClosureWriteTimeout/400_objects764=== RUN TestPendingClosureWriteTimeout/670k_objects765=== PAUSE TestPendingClosureWriteTimeout/670k_objects766=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline767=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline768=== CONT TestReadProxyOutlastsServerWriteTimeout7692026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes770--- PASS: TestService_Rustfstest (0.56s)771=== CONT TestReadProxyHead7722026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes7732026-10-06 21:24:10.150 UTC [493] ERROR: could not obtain lock on row in relation "closures"7742026-10-06 21:24:10.150 UTC [493] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT7752026-10-06 21:24:10.150 UTC [493] ERROR: could not obtain lock on row in relation "closures"7762026-10-06 21:24:10.150 UTC [493] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT7772026-10-06 21:24:10.150 UTC [493] ERROR: could not obtain lock on row in relation "closures"7782026-10-06 21:24:10.150 UTC [493] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT7792026-10-06 21:24:10.151 UTC [493] ERROR: could not obtain lock on row in relation "closures"7802026-10-06 21:24:10.151 UTC [493] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT7812026-10-06 21:24:10.151 UTC [493] ERROR: could not obtain lock on row in relation "closures"7822026-10-06 21:24:10.151 UTC [493] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT783--- PASS: TestPush_RootsAreLockedInByteOrder (0.58s)784=== CONT TestPushWaitsForSweepHoldingRow7852026/10/06 21:24:10 INFO Received cleanup request method=DELETE path=/api/pending_closures7862026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=07872026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures7882026/10/06 21:24:10 INFO Received cleanup request method=DELETE path=/api/pending_closures7892026/10/06 21:24:10 INFO Aborted multipart uploads count=1 kept=07902026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7912026-10-06 21:24:10.187 UTC [463] ERROR: Closure does not exist: id=17922026-10-06 21:24:10.187 UTC [463] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7932026-10-06 21:24:10.187 UTC [463] STATEMENT: -- name: CommitPendingClosure :exec794 SELECT commit_pending_closure($1::bigint)795 796--- PASS: TestService_cleanupPendingClosuresHandler (0.61s)797=== CONT TestReadProxyInvalidPath798--- PASS: TestReadProxyRangeRequest (0.62s)799=== CONT TestGetExistingObjectsLocksRows8002026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8012026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete8022026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8032026/10/06 21:24:10 INFO Completed push id=1804--- PASS: TestPush_RepeatedRootCommitsOnce (0.67s)805=== CONT TestReadProxy404806--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.67s)807=== CONT TestIsValidUploadKey808=== RUN TestIsValidUploadKey/narinfo809=== PAUSE TestIsValidUploadKey/narinfo810=== RUN TestIsValidUploadKey/nar_zst811=== PAUSE TestIsValidUploadKey/nar_zst812=== RUN TestIsValidUploadKey/nar_xz813=== PAUSE TestIsValidUploadKey/nar_xz814=== RUN TestIsValidUploadKey/nar_plain815=== PAUSE TestIsValidUploadKey/nar_plain816=== RUN TestIsValidUploadKey/listing817=== PAUSE TestIsValidUploadKey/listing818=== RUN TestIsValidUploadKey/build_log819=== PAUSE TestIsValidUploadKey/build_log820=== RUN TestIsValidUploadKey/build_log_home-manager_file821=== PAUSE TestIsValidUploadKey/build_log_home-manager_file822=== RUN TestIsValidUploadKey/build_log_plus_in_name823=== PAUSE TestIsValidUploadKey/build_log_plus_in_name824=== RUN TestIsValidUploadKey/build_log_question_mark825=== PAUSE TestIsValidUploadKey/build_log_question_mark826=== RUN TestIsValidUploadKey/build_log_equals827=== PAUSE TestIsValidUploadKey/build_log_equals828=== RUN TestIsValidUploadKey/realisation829=== PAUSE TestIsValidUploadKey/realisation830=== RUN TestIsValidUploadKey/realisation_plus_in_output831=== PAUSE TestIsValidUploadKey/realisation_plus_in_output832=== RUN TestIsValidUploadKey/nix-cache-info833=== PAUSE TestIsValidUploadKey/nix-cache-info834=== RUN TestIsValidUploadKey/index.html835=== PAUSE TestIsValidUploadKey/index.html836=== RUN TestIsValidUploadKey/narinfo_key,_nar_type837=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type838=== RUN TestIsValidUploadKey/nar_key,_narinfo_type839=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type840=== RUN TestIsValidUploadKey/listing_key,_narinfo_type841=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type842=== RUN TestIsValidUploadKey/traversal843=== PAUSE TestIsValidUploadKey/traversal844=== RUN TestIsValidUploadKey/traversal_nar845=== PAUSE TestIsValidUploadKey/traversal_nar846=== RUN TestIsValidUploadKey/absolute847=== PAUSE TestIsValidUploadKey/absolute848=== RUN TestIsValidUploadKey/empty_key849=== PAUSE TestIsValidUploadKey/empty_key850=== RUN TestIsValidUploadKey/unknown_type851=== PAUSE TestIsValidUploadKey/unknown_type852=== CONT TestRegisterCompletedObjectNeedsPendingRow8532026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes854--- PASS: TestReadRedirectKeepsNarinfoProxied (0.70s)855=== CONT TestReadProxyNarStreaming8562026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8572026/10/06 21:24:10 INFO Signed narinfos id=1 count=18582026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8592026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8602026/10/06 21:24:10 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8612026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8622026/10/06 21:24:10 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8632026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8642026/10/06 21:24:10 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18652026/10/06 21:24:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8662026/10/06 21:24:10 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo867--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.72s)868=== CONT TestSweepSkipsRowsLockedByPush8692026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8702026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8712026/10/06 21:24:10 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst872--- PASS: TestCompleteMultipartUnregistered (0.72s)873=== CONT TestReadProxyContentNegotiation8742026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjg3YTZjMzkxLWQ1ZTQtNDM4ZS1iZmNhLTRhNWRmMTY1N2E4NXgxNzkxMzIxODQ5OTg0NTY3ODEz parts=108752026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8762026/10/06 21:24:10 INFO Completed upload id=18772026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8782026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures8792026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes8802026/10/06 21:24:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8812026/10/06 21:24:10 WARN Found objects in DB but missing from S3, will re-upload count=1882--- PASS: TestService_verifyS3Integrity (0.77s)883=== CONT TestSweepRechecksPendingAfterLocking884--- PASS: TestReadProxyDisabled (0.78s)885=== CONT TestFailedS3DeleteKeepsTombstone886--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.78s)887=== CONT TestReadProxyNarinfoAlreadyDecompressed8882026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8892026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8902026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLmQxMzY1MGZjLTY2YmItNGEzMy1hZTM2LWJkZTIxN2U5ZGZkNHgxNzkxMzIxODUwMDAwODkyMDk2 parts=128912026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures892--- PASS: TestReadRedirectNar (0.81s)893=== CONT TestUploadHandlersRejectOversizedBody894--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.82s)895=== CONT TestForceGCDuringPushOffersSweptObject896=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows897=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows898=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check899=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check900=== CONT TestReadProxyNarinfo9012026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjNmMTdjMDZjLTA0NDEtNGQzOS1hYjA2LTEyYjg3ODU3NDQ0OHgxNzkxMzIxODUwMDE2MDExNTQ5 parts=129022026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9042026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9052026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete9062026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9072026/10/06 21:24:10 INFO Completed push id=19082026/10/06 21:24:10 INFO Received push request method=POST path=/api/pushes9092026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/1/complete9102026/10/06 21:24:10 INFO Completed push id=1911--- PASS: TestPush_CompleteCommitsEveryRoot (0.88s)912=== CONT TestUploadHandlersRejectInvalidKeys913=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info914=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info915=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal916=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal917=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key918=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key919=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key920=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key921=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection922--- PASS: TestReadRedirectUsesPublicS3URL (0.88s)923=== CONT TestIsValidCachePath924=== RUN TestIsValidCachePath/narinfo925=== PAUSE TestIsValidCachePath/narinfo926=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars927=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars928=== RUN TestIsValidCachePath/nar_zst929=== PAUSE TestIsValidCachePath/nar_zst930=== RUN TestIsValidCachePath/nar_xz931=== PAUSE TestIsValidCachePath/nar_xz932=== RUN TestIsValidCachePath/nar_bz2933=== PAUSE TestIsValidCachePath/nar_bz2934=== RUN TestIsValidCachePath/nar_uncompressed935=== PAUSE TestIsValidCachePath/nar_uncompressed936=== RUN TestIsValidCachePath/ls937=== PAUSE TestIsValidCachePath/ls938=== RUN TestIsValidCachePath/log939=== PAUSE TestIsValidCachePath/log940=== RUN TestIsValidCachePath/realisation941=== PAUSE TestIsValidCachePath/realisation942=== RUN TestIsValidCachePath/nix-cache-info943=== PAUSE TestIsValidCachePath/nix-cache-info944=== RUN TestIsValidCachePath/index.html945=== PAUSE TestIsValidCachePath/index.html946=== RUN TestIsValidCachePath/traversal_parent947=== PAUSE TestIsValidCachePath/traversal_parent948=== RUN TestIsValidCachePath/traversal_in_middle949=== PAUSE TestIsValidCachePath/traversal_in_middle950=== RUN TestIsValidCachePath/invalid_char_e951=== PAUSE TestIsValidCachePath/invalid_char_e952=== RUN TestIsValidCachePath/invalid_char_u953=== PAUSE TestIsValidCachePath/invalid_char_u954=== RUN TestIsValidCachePath/random_path955=== PAUSE TestIsValidCachePath/random_path956=== RUN TestIsValidCachePath/empty957=== PAUSE TestIsValidCachePath/empty958=== RUN TestIsValidCachePath/leading_slash959=== PAUSE TestIsValidCachePath/leading_slash960=== RUN TestIsValidCachePath/wrong_extension961=== PAUSE TestIsValidCachePath/wrong_extension962=== RUN TestIsValidCachePath/short_hash963=== PAUSE TestIsValidCachePath/short_hash964=== CONT TestGCSweepDeliversEachKeyOnce9652026-10-06 21:24:10.458 UTC [500] ERROR: Push does not exist: id=19662026-10-06 21:24:10.458 UTC [500] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE9672026-10-06 21:24:10.458 UTC [500] STATEMENT: SELECT commit_push($1)968--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.89s)969=== CONT TestProxyHeadersOnlyTrustedOnSocket9702026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures973--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.42s)974=== CONT TestCreatePendingClosureRejectsOversizedNAR9752026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures976--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)977=== CONT TestTombstonedObjectOfferedWithoutWaiting9782026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=09792026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period9802026/10/06 21:24:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=09812026/10/06 21:24:10 INFO Vacuumed table table=pending_closures9822026/10/06 21:24:10 INFO Vacuumed table table=pending_objects9832026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads9842026/10/06 21:24:10 INFO Vacuumed table table=closures9852026/10/06 21:24:10 INFO Vacuumed table table=objects9862026/10/06 21:24:10 INFO Received complete push request method=POST path=/api/pushes/2/complete9872026/10/06 21:24:10 INFO Completed push id=2988--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.96s)989=== CONT TestCacheConfigHandlerMaxNarSize990--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)991=== CONT TestParseSingleRange992=== RUN TestParseSingleRange/none993=== PAUSE TestParseSingleRange/none994=== RUN TestParseSingleRange/unknown_unit995=== PAUSE TestParseSingleRange/unknown_unit996=== RUN TestParseSingleRange/multi-range_ignored997=== PAUSE TestParseSingleRange/multi-range_ignored998=== RUN TestParseSingleRange/malformed_no_dash999=== PAUSE TestParseSingleRange/malformed_no_dash1000=== RUN TestParseSingleRange/malformed_both_empty1001=== PAUSE TestParseSingleRange/malformed_both_empty1002=== RUN TestParseSingleRange/malformed_end_before_start1003=== PAUSE TestParseSingleRange/malformed_end_before_start1004=== RUN TestParseSingleRange/closed1005=== PAUSE TestParseSingleRange/closed1006=== RUN TestParseSingleRange/open-ended1007=== PAUSE TestParseSingleRange/open-ended1008=== RUN TestParseSingleRange/end_clamped_to_size1009=== PAUSE TestParseSingleRange/end_clamped_to_size1010=== RUN TestParseSingleRange/suffix1011=== PAUSE TestParseSingleRange/suffix1012=== RUN TestParseSingleRange/suffix_exceeds_size1013=== PAUSE TestParseSingleRange/suffix_exceeds_size1014=== RUN TestParseSingleRange/single_byte1015=== PAUSE TestParseSingleRange/single_byte1016=== RUN TestParseSingleRange/start_past_EOF1017=== PAUSE TestParseSingleRange/start_past_EOF1018=== RUN TestParseSingleRange/start_far_past_EOF1019=== PAUSE TestParseSingleRange/start_far_past_EOF1020=== CONT TestGCSweepSkipsPendingObjects1021--- PASS: TestReadProxyConditionalGet (0.45s)1022=== CONT TestGenerateLandingPage1023=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1024=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1025=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1026=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1027=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1028=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1029=== CONT TestPresentNotReportedWhileGCDeletesClosure1030=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1031=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1032=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1033=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1034=== CONT TestDeduplicatedObjectsRecordedAsPending1035--- PASS: TestGenerateLandingPage (0.00s)1036=== CONT TestService_readinessHandler1037--- PASS: TestReadProxyHead (0.43s)1038=== CONT TestPresentRefreshesOnlyStaleClosures10392026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures1040--- PASS: TestReadProxyInvalidPath (0.41s)1041=== CONT TestPushDedupSurvivesConcurrentGC1042--- PASS: TestGetExistingObjectsLocksRows (0.43s)1043=== CONT TestService_healthCheckHandler1044--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.40s)1045=== CONT TestPresentReportsOnlyClosureRoots1046--- PASS: TestReadProxy404 (0.44s)1047=== CONT TestGracefulShutdownDrainsInflight10482026/10/06 21:24:10 INFO Starting HTTP server address=127.0.0.1:4140710492026/10/06 21:24:10 INFO Shutdown signal received, draining in-flight requests timeout=10s1050--- PASS: TestReadProxyNarStreaming (0.42s)1051=== CONT TestGCMetrics10522026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=010532026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period10542026/10/06 21:24:10 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=010552026/10/06 21:24:10 INFO Vacuumed table table=pending_closures10562026/10/06 21:24:10 INFO Vacuumed table table=pending_objects10572026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads10582026/10/06 21:24:10 INFO Vacuumed table table=closures10592026/10/06 21:24:10 INFO Vacuumed table table=objects10602026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=010612026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period1062--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1063=== CONT TestMultipartCleanup10642026/10/06 21:24:10 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=010652026/10/06 21:24:10 INFO Vacuumed table table=pending_closures10662026/10/06 21:24:10 INFO Vacuumed table table=pending_objects10672026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads10682026/10/06 21:24:10 INFO Vacuumed table table=closures10692026/10/06 21:24:10 INFO Vacuumed table table=objects1070--- PASS: TestSweepSkipsRowsLockedByPush (0.47s)1071=== CONT TestGCTaskStore_Fail1072--- PASS: TestGCTaskStore_Fail (0.00s)1073=== CONT TestGCBugBareHashReferences10742026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=010752026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10762026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period10782026/10/06 21:24:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10792026/10/06 21:24:10 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjExOWY0OGRmLTAwNGYtNDRlYi05ZTM5LWNiMTE3NTlkYzIwZXgxNzkxMzIxODUwNDAyNDk0NTAw error="Get \"http://127.0.0.1:1/bucket6/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10802026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLmE4MjMyYzg5LTY3YTYtNDkxZC1hMjc3LTQ5ZjQ4MTQ5ZWU5YngxNzkxMzIxODUwMzk2NDc5NDA3 parts=1210812026/10/06 21:24:10 INFO Received cleanup request method=DELETE path=/api/pending_closures10822026/10/06 21:24:10 INFO Aborted multipart uploads count=1 kept=010832026/10/06 21:24:10 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=01084--- PASS: TestReadProxyContentNegotiation (0.49s)1085=== CONT TestServerTLSConfig1086=== RUN TestServerTLSConfig/no_client_CA1087=== PAUSE TestServerTLSConfig/no_client_CA1088=== RUN TestServerTLSConfig/missing_CA_file1089=== PAUSE TestServerTLSConfig/missing_CA_file1090=== RUN TestServerTLSConfig/not_a_PEM_file1091=== PAUSE TestServerTLSConfig/not_a_PEM_file1092=== CONT TestGCTaskStore_PhaseUpdates1093--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1094=== CONT TestGCAdvisoryLockBlocksConcurrentRun10952026/10/06 21:24:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzRjMTIwNTMtNmYzMS00ZTdjLWFkMmQtYmIzMjBjYzUzOTVkLjYzNTJhZmUzLWE0ZTgtNGUzZi04ZTIyLThkMDU2ZGFjYmYwYXgxNzkxMzIxODUwNDcwMzQ5OTk1 parts=1010962026/10/06 21:24:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10972026/10/06 21:24:10 INFO Vacuumed table table=pending_closures1098--- PASS: TestRedundantMultipartUpload (1.22s)1099=== CONT TestService_NativeMTLS11002026/10/06 21:24:10 INFO Vacuumed table table=pending_objects11012026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads11022026/10/06 21:24:10 INFO Vacuumed table table=closures11032026/10/06 21:24:10 INFO Completed upload id=111042026/10/06 21:24:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011052026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/06 21:24:10 INFO Vacuumed table table=objects1107--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.44s)1108=== CONT TestLeadEndsOnShutdown1109--- PASS: TestSweepRechecksPendingAfterLocking (0.46s)1110=== CONT TestMetricsInventory11112026/10/06 21:24:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures11122026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=011132026/10/06 21:24:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011142026/10/06 21:24:10 INFO Vacuumed table table=pending_closures11152026/10/06 21:24:10 INFO Vacuumed table table=pending_objects11162026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads11172026/10/06 21:24:10 INFO Vacuumed table table=closures11182026/10/06 21:24:10 INFO Vacuumed table table=objects11192026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=011212026/10/06 21:24:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001122--- PASS: TestService_createPendingClosureHandler (0.81s)1123=== CONT TestLeadIncumbentAnnouncesAtOnce11242026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/06 21:24:10 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11262026/10/06 21:24:10 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1127--- PASS: TestFailedS3DeleteKeepsTombstone (0.52s)1128=== CONT TestNARDeduplicationMetadataUploadBug11292026/10/06 21:24:10 INFO Starting HTTP server address=127.0.0.1:4469511302026/10/06 21:24:10 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3312427636/001/proxy.sock11312026/10/06 21:24:10 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11322026/10/06 21:24:10 INFO Shutdown signal received, draining in-flight requests timeout=10s1133--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.42s)1134=== CONT TestGCTaskStore_CompletedAllowsNewTask1135--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1136=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11372026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=011382026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period11392026/10/06 21:24:10 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1140--- PASS: TestReadProxyNarinfo (0.52s)1141=== CONT TestProxyWriteTimeout1142=== RUN TestProxyWriteTimeout/narinfo1143=== PAUSE TestProxyWriteTimeout/narinfo1144=== RUN TestProxyWriteTimeout/1_GiB_nar1145=== PAUSE TestProxyWriteTimeout/1_GiB_nar1146=== RUN TestProxyWriteTimeout/10_GiB_nar1147=== PAUSE TestProxyWriteTimeout/10_GiB_nar1148=== RUN TestProxyWriteTimeout/unknown_size1149=== PAUSE TestProxyWriteTimeout/unknown_size1150=== CONT TestGCTaskStore_GetReturnsLatest1151--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1152=== CONT TestCreatePin_ReservedPins11532026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures11542026/10/06 21:24:10 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=011552026/10/06 21:24:10 INFO Vacuumed table table=pending_closures11562026/10/06 21:24:10 INFO Vacuumed table table=pending_objects11572026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads11582026/10/06 21:24:10 INFO Vacuumed table table=closures1159--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1160=== CONT TestGCTaskStore_GetEmpty11612026/10/06 21:24:10 INFO Vacuumed table table=objects1162--- PASS: TestGCTaskStore_GetEmpty (0.00s)1163=== CONT TestClientIntegration1164--- PASS: TestGCSweepDeliversEachKeyOnce (0.45s)1165=== CONT TestGCTaskStore_ConflictDifferentParams1166--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1167=== CONT TestOrphanedObjectsGCStressTest11682026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures11692026/10/06 21:24:10 WARN readiness check failed error="closed pool"1170--- PASS: TestService_readinessHandler (0.40s)1171=== CONT TestConnectWaitsForAPeerMigration11722026/10/06 21:24:10 INFO Aborted multipart uploads count=0 kept=011732026/10/06 21:24:10 WARN Force mode enabled - objects will be deleted immediately without grace period11742026/10/06 21:24:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011752026/10/06 21:24:10 INFO Vacuumed table table=pending_closures11762026/10/06 21:24:10 INFO Vacuumed table table=pending_objects11772026/10/06 21:24:10 INFO Vacuumed table table=multipart_uploads11782026/10/06 21:24:10 INFO Vacuumed table table=closures11792026/10/06 21:24:10 INFO Vacuumed table table=objects11802026/10/06 21:24:10 INFO Received uploads request method=POST path=/api/pending_closures1181--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1182=== CONT TestGCTaskStore_DeduplicateSameParams1183--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1184=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1185--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.43s)1186=== CONT TestOrphanedObjectsGC1187--- PASS: TestPresentRefreshesOnlyStaleClosures (0.44s)1188=== CONT TestDeleteClosuresRacingPins1189--- PASS: TestService_healthCheckHandler (0.39s)1190=== CONT TestResolveDBConnectionString1191=== RUN TestResolveDBConnectionString/flag_wins1192=== PAUSE TestResolveDBConnectionString/flag_wins1193=== RUN TestResolveDBConnectionString/file_when_flag_empty1194=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1195=== RUN TestResolveDBConnectionString/missing_file_is_an_error1196=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1197=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1198=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1199=== RUN TestResolveDBConnectionString/nothing_configured1200=== PAUSE TestResolveDBConnectionString/nothing_configured1201=== CONT TestClientFallsBackToClosures12022026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1203--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.60s)1204=== CONT TestObjectStatsTrigger1205--- PASS: TestPresentReportsOnlyClosureRoots (0.43s)1206=== CONT TestPendingCleanupUsesOneCutoff12072026/10/06 21:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39061/oidc1208--- PASS: TestPushWaitsForSweepHoldingRow (0.93s)1209=== CONT TestClientPushesUseOnePush12102026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=012112026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period12122026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012132026/10/06 21:24:11 INFO Vacuumed table table=pending_closures12142026/10/06 21:24:11 INFO Vacuumed table table=pending_objects12152026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads12162026/10/06 21:24:11 INFO Vacuumed table table=closures12172026/10/06 21:24:11 INFO Vacuumed table table=objects1218--- PASS: TestGCMetrics (0.40s)1219=== CONT TestGCEndsOnShutdown1220=== RUN TestGCEndsOnShutdown/before_the_run1221=== PAUSE TestGCEndsOnShutdown/before_the_run1222=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1223=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1224=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1225=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1226=== CONT TestClientSharedPathCommittedMidPush12272026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=012282026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures12292026/10/06 21:24:11 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=012302026/10/06 21:24:11 INFO Vacuumed table table=pending_closures12312026/10/06 21:24:11 INFO Vacuumed table table=pending_objects12322026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads12332026/10/06 21:24:11 INFO Vacuumed table table=closures12342026/10/06 21:24:11 INFO Vacuumed table table=objects12352026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=012362026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period12372026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012382026/10/06 21:24:11 INFO Vacuumed table table=pending_closures12392026/10/06 21:24:11 INFO Vacuumed table table=pending_objects12402026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads12412026/10/06 21:24:11 INFO Vacuumed table table=closures12422026/10/06 21:24:11 INFO Vacuumed table table=objects1243--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1244=== CONT TestGCTaskStore_StartNew1245--- PASS: TestGCTaskStore_StartNew (0.00s)1246=== CONT TestCommitRacingPendingCleanupKeepsObjects12472026/10/06 21:24:11 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"1248--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)1249=== CONT TestPinProtectsFromGC12502026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12512026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1252--- PASS: TestService_NativeMTLS (0.37s)1253=== CONT TestClientWithDependencies12542026/10/06 21:24:11 INFO lead: acquired remote=192.0.2.1:123412552026/10/06 21:24:11 INFO Received cleanup request method=DELETE path=/api/pending_closures12562026/10/06 21:24:11 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket56/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12572026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=11258--- PASS: TestObjectStatsTrigger (0.16s)1259=== CONT TestService_ReadScope_PublicByDefault12602026/10/06 21:24:11 INFO Received cleanup request method=DELETE path=/api/pending_closures12612026/10/06 21:24:11 INFO Aborted multipart uploads count=1 kept=01262--- PASS: TestMultipartCleanup (0.47s)1263=== CONT TestService_ReadAuthMiddleware1264--- PASS: TestMetricsInventory (0.44s)1265=== CONT TestClientMultipleUploads12662026/10/06 21:24:11 INFO lead: acquired remote=192.0.2.1:123412672026/10/06 21:24:11 INFO lead: released remote=192.0.2.1:12341268--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.40s)1269=== CONT TestLeadElectsOneAndHandsOver12702026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1271--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)1272=== CONT TestService_RequireScope_OIDC1273=== NAME TestNARDeduplicationMetadataUploadBug1274 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug731460362/001/store/1niak4yqgj776dy8y5h3li3l2psc1a2g-file1.txt1275--- PASS: TestGCBugBareHashReferences (0.59s)1276=== CONT TestClientErrorHandling1277=== RUN TestClientErrorHandling/InvalidStorePath1278=== PAUSE TestClientErrorHandling/InvalidStorePath1279=== RUN TestClientErrorHandling/InvalidAuthToken1280=== PAUSE TestClientErrorHandling/InvalidAuthToken1281=== RUN TestClientErrorHandling/ServerNotAvailable1282=== PAUSE TestClientErrorHandling/ServerNotAvailable1283=== CONT TestCacheStatsHandler1284=== NAME TestClientIntegration1285 client_integration_test.go:286: Created store path: /build/TestClientIntegration3889286144/002/store/0pkbffry8fx2sc84zgm7jckpmrmcmydq-test-file.txt12862026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes12872026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12882026/10/06 21:24:11 INFO Uploading 1niak4yqgj776dy8y5h3li3l2psc1a2g-file1.txt (160B)12892026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12902026/10/06 21:24:11 WARN Failed to register uploaded object key=1niak4yqgj776dy8y5h3li3l2psc1a2g.ls error="server returned 404: 404 page not found\n"12912026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12922026/10/06 21:24:11 INFO Signed narinfos id=1 count=112932026/10/06 21:24:11 INFO Uploading 1 narinfos12942026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026/10/06 21:24:11 WARN Failed to register uploaded object key=1niak4yqgj776dy8y5h3li3l2psc1a2g.narinfo error="server returned 404: 404 page not found\n"12962026/10/06 21:24:11 INFO Completed push id=112972026/10/06 21:24:11 INFO Upload complete. (68ms)1298=== NAME TestNARDeduplicationMetadataUploadBug1299 metadata_upload_test.go:54: Retrieved narinfo from S3:1300 StorePath: /build/TestNARDeduplicationMetadataUploadBug731460362/001/store/1niak4yqgj776dy8y5h3li3l2psc1a2g-file1.txt1301 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1302 Compression: zstd1303 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1304 NarSize: 1601305 References: 1306 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13072026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1308 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1309 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1310 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13112026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13122026/10/06 21:24:11 INFO Uploading 0pkbffry8fx2sc84zgm7jckpmrmcmydq-test-file.txt (152B)13132026/10/06 21:24:11 WARN Failed to register uploaded object key=0pkbffry8fx2sc84zgm7jckpmrmcmydq.ls error="server returned 404: 404 page not found\n"13142026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13152026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13162026/10/06 21:24:11 INFO Signed narinfos id=1 count=113172026/10/06 21:24:11 INFO Uploading 1 narinfos13182026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13192026/10/06 21:24:11 WARN Refused reserved pin name=worker-x86_64-linux13202026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13212026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/my-app13222026/10/06 21:24:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1323--- PASS: TestCreatePin_ReservedPins (0.53s)1324=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13252026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13262026/10/06 21:24:11 WARN Failed to register uploaded object key=0pkbffry8fx2sc84zgm7jckpmrmcmydq.narinfo error="server returned 404: 404 page not found\n"13272026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures13282026/10/06 21:24:11 INFO Completed push id=113292026/10/06 21:24:11 INFO Upload complete. (60ms)13302026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1331=== NAME TestNARDeduplicationMetadataUploadBug1332 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug731460362/001/store/masfp8myw1yyzkvqagaj9507v69dpgiy-file2.txt13332026/10/06 21:24:11 INFO Received cleanup request method=DELETE path=/api/pending_closures13342026/10/06 21:24:11 INFO All 1 paths already cached1335=== NAME TestClientIntegration1336 client_integration_test.go:312: Retrieved narinfo from S3:1337 StorePath: /build/TestClientIntegration3889286144/002/store/0pkbffry8fx2sc84zgm7jckpmrmcmydq-test-file.txt1338 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1339 Compression: zstd1340 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11341 NarSize: 1521342 References: 1343 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11344 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1345 client_integration_test.go:313: Decompressed .ls content (64 bytes):1346 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1347 client_integration_test.go:316: Testing garbage collection...13482026/10/06 21:24:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures13492026/10/06 21:24:11 INFO Garbage collection started13502026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=013512026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes13522026/10/06 21:24:11 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13532026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period13542026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=013552026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13562026/10/06 21:24:11 INFO Signed narinfos id=2 count=113572026/10/06 21:24:11 WARN Failed to register uploaded object key=masfp8myw1yyzkvqagaj9507v69dpgiy.ls error="server returned 404: 404 page not found\n"13582026/10/06 21:24:11 INFO Uploading 1 narinfos13592026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period13602026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/2/complete13612026/10/06 21:24:11 WARN Failed to register uploaded object key=masfp8myw1yyzkvqagaj9507v69dpgiy.narinfo error="server returned 404: 404 page not found\n"13622026/10/06 21:24:11 INFO Completed push id=213632026/10/06 21:24:11 INFO Upload complete. (44ms)13642026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01365=== NAME TestNARDeduplicationMetadataUploadBug1366 metadata_upload_test.go:76: Retrieved narinfo from S3:1367 StorePath: /build/TestNARDeduplicationMetadataUploadBug731460362/001/store/masfp8myw1yyzkvqagaj9507v69dpgiy-file2.txt1368 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1369 Compression: zstd1370 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1371 NarSize: 1601372 References: 1373 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13742026/10/06 21:24:11 INFO Vacuumed table table=pending_closures13752026/10/06 21:24:11 INFO Vacuumed table table=pending_objects13762026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads1377 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1378 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1379 {"version":1,"root":{"type":"regular","size":44}}13802026/10/06 21:24:11 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=013812026/10/06 21:24:11 INFO Vacuumed table table=closures13822026/10/06 21:24:11 INFO Vacuumed table table=objects1383--- PASS: TestNARDeduplicationMetadataUploadBug (0.68s)1384=== CONT TestService_AuthMiddleware_OIDC13852026/10/06 21:24:11 INFO Vacuumed table table=pending_closures13862026/10/06 21:24:11 INFO Vacuumed table table=pending_objects13872026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads1388--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.41s)1389=== CONT TestCacheConfigHandler1390=== RUN TestCacheConfigHandler/full_config,_no_issuer1391=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1392=== RUN TestCacheConfigHandler/no_cache_url_configured1393=== PAUSE TestCacheConfigHandler/no_cache_url_configured1394=== RUN TestCacheConfigHandler/no_signing_keys1395=== PAUSE TestCacheConfigHandler/no_signing_keys1396=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1397=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1398=== CONT TestClientCADerivations13992026/10/06 21:24:11 INFO Vacuumed table table=closures14002026/10/06 21:24:11 INFO Vacuumed table table=objects1401--- PASS: TestService_ReadAuthMiddleware (0.34s)1402=== CONT TestService_AuthMiddleware_MTLSProxyHeader14032026/10/06 21:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42277/oidc1404--- PASS: TestService_ReadScope_PublicByDefault (0.37s)1405=== CONT TestPush_RejectsBadRequests/no_roots14062026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1407=== CONT TestPush_RejectsBadRequests/bad_root14082026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1409=== CONT TestPush_RejectsBadRequests/no_objects14102026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1411=== CONT TestPush_RejectsBadRequests/root_not_in_objects14122026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1413=== CONT TestPendingClosureWriteTimeout/empty1414=== CONT TestPendingClosureWriteTimeout/670k_objects1415=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1416--- PASS: TestPush_RejectsBadRequests (0.51s)1417 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1418 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1419 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1420 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)14212026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1422=== NAME TestPinProtectsFromGC1423 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC4288637461/001/store/7wml6l98knla8k032wapzcph850ypdz0-pinned-file.txt1424 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC4288637461/001/store/cldzc8dhcxqd4nlmgkhqlh321ikvgwg0-unpinned-file.txt14252026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures14262026/10/06 21:24:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14272026/10/06 21:24:11 INFO Uploading jdpglq5n9d6lr7jg3qf893frd3h4v08p-shared-dep (136B)14282026/10/06 21:24:11 INFO Uploading zjxb10nai2334hamvqv5a9r504gxi1mm-b (216B)1429=== NAME TestClientWithDependencies1430 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2464634149/001/store/c8nafh04nl4mmil5xzq3iqh22zsqmz50-test-script14312026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes14322026/10/06 21:24:11 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14332026/10/06 21:24:11 INFO Uploading 4xzk2abjvq7irhk67az8qclm4ri35wzp-top (224B)14342026/10/06 21:24:11 INFO Uploading 32bfkl31qfzmkwisikwaby320pc74cba-shared-dep (136B)14352026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14362026/10/06 21:24:11 WARN Failed to register uploaded object key=jdpglq5n9d6lr7jg3qf893frd3h4v08p.ls error="server returned 404: 404 page not found\n"14372026/10/06 21:24:11 WARN Failed to register uploaded object key=nbvvpmc8956ya9wcfagwmdbz5287qzwi.ls error="server returned 404: 404 page not found\n"14382026/10/06 21:24:11 WARN Failed to register uploaded object key=zjxb10nai2334hamvqv5a9r504gxi1mm.ls error="server returned 404: 404 page not found\n"14392026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14402026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/04y1qrnv0l3shpdy9bvslrd59ffl88rzkw6npjnxc8qm3dp8r798.nar.zst error="server returned 404: 404 page not found\n"14412026/10/06 21:24:11 INFO Signed narinfos id=1 count=214422026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14432026/10/06 21:24:11 INFO Signed narinfos id=2 count=214442026/10/06 21:24:11 INFO Uploading 4 narinfos14452026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14462026/10/06 21:24:11 WARN Failed to register uploaded object key=32bfkl31qfzmkwisikwaby320pc74cba.ls error="server returned 404: 404 page not found\n"14472026/10/06 21:24:11 WARN Failed to register uploaded object key=4xzk2abjvq7irhk67az8qclm4ri35wzp.ls error="server returned 404: 404 page not found\n"14482026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1fv91zh6nzq2r2b30vdxvhjj118drf86mnz7hwkkkxfgkxiiayz7.nar.zst error="server returned 404: 404 page not found\n"14492026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1450=== NAME TestClientMultipleUploads1451 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1222347740/001/store/83g9bm6bkzigbl98vdlya6dkqdrnn0lh-test-file-0.txt14522026/10/06 21:24:11 INFO Signed narinfos id=1 count=214532026/10/06 21:24:11 INFO Uploading 2 narinfos14542026/10/06 21:24:11 WARN Failed to register uploaded object key=jdpglq5n9d6lr7jg3qf893frd3h4v08p.narinfo error="server returned 404: 404 page not found\n"14552026/10/06 21:24:11 WARN Failed to register uploaded object key=zjxb10nai2334hamvqv5a9r504gxi1mm.narinfo error="server returned 404: 404 page not found\n"14562026/10/06 21:24:11 WARN Failed to register uploaded object key=nbvvpmc8956ya9wcfagwmdbz5287qzwi.narinfo error="server returned 404: 404 page not found\n"14572026/10/06 21:24:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14582026/10/06 21:24:11 WARN Failed to register uploaded object key=jdpglq5n9d6lr7jg3qf893frd3h4v08p.narinfo error="server returned 404: 404 page not found\n"14592026/10/06 21:24:11 WARN Failed to register uploaded object key=4xzk2abjvq7irhk67az8qclm4ri35wzp.narinfo error="server returned 404: 404 page not found\n"14602026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete14612026/10/06 21:24:11 WARN Failed to register uploaded object key=32bfkl31qfzmkwisikwaby320pc74cba.narinfo error="server returned 404: 404 page not found\n"14622026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes14632026/10/06 21:24:11 INFO lead: acquired remote=192.0.2.1:123414642026/10/06 21:24:11 INFO Completed upload id=114652026/10/06 21:24:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14662026/10/06 21:24:11 INFO Completed push id=114672026/10/06 21:24:11 INFO Upload complete. (68ms)14682026/10/06 21:24:11 INFO Completed upload id=214692026/10/06 21:24:11 INFO Upload complete. (96ms)14702026/10/06 21:24:11 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14712026/10/06 21:24:11 INFO Uploading w10qp8q4fwvanfil1yc74xskp1ykvgy2-a (216B)14722026/10/06 21:24:11 INFO Uploading 82ar48jgk8fyr1nkzcm7v8ak48iw7106-shared-dep (136B)1473=== NAME TestClientSharedPathCommittedMidPush1474 client_integration_test.go:680: Retrieved narinfo from S3:1475 StorePath: /build/TestClientSharedPathCommittedMidPush3816505106/001/store/32bfkl31qfzmkwisikwaby320pc74cba-shared-dep1476 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1477 Compression: zstd1478=== NAME TestClientFallsBackToClosures1479 client_pushes_test.go:112: Retrieved narinfo from S3:1480 StorePath: /build/TestClientFallsBackToClosures4151399599/001/store/jdpglq5n9d6lr7jg3qf893frd3h4v08p-shared-dep1481 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1482 Compression: zstd1483 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821484 NarSize: 1361485 References: 1486 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1487=== NAME TestClientSharedPathCommittedMidPush1488 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821489 NarSize: 1361490 References: 1491 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1492 client_integration_test.go:680: Retrieved narinfo from S3:1493 StorePath: /build/TestClientSharedPathCommittedMidPush3816505106/001/store/4xzk2abjvq7irhk67az8qclm4ri35wzp-top1494 URL: nar/1fv91zh6nzq2r2b30vdxvhjj118drf86mnz7hwkkkxfgkxiiayz7.nar.zst1495 Compression: zstd1496 NarHash: sha256:1fv91zh6nzq2r2b30vdxvhjj118drf86mnz7hwkkkxfgkxiiayz71497 NarSize: 2241498 References: /build/TestClientSharedPathCommittedMidPush3816505106/001/store/32bfkl31qfzmkwisikwaby320pc74cba-shared-dep1499 CA: text:sha256:1dcfbwz8jniz92d78mdqhzvhpcmipgzkb580vx5n1nnb9v7wha871500=== NAME TestClientFallsBackToClosures1501 client_pushes_test.go:112: Retrieved narinfo from S3:1502 StorePath: /build/TestClientFallsBackToClosures4151399599/001/store/nbvvpmc8956ya9wcfagwmdbz5287qzwi-a1503 URL: nar/04y1qrnv0l3shpdy9bvslrd59ffl88rzkw6npjnxc8qm3dp8r798.nar.zst1504 Compression: zstd1505 NarHash: sha256:04y1qrnv0l3shpdy9bvslrd59ffl88rzkw6npjnxc8qm3dp8r7981506 NarSize: 2161507 References: /build/TestClientFallsBackToClosures4151399599/001/store/jdpglq5n9d6lr7jg3qf893frd3h4v08p-shared-dep1508 CA: text:sha256:04r5r5iwnqi6y71cb7cdcjiq3myy0zmk5qz0fpr8jark3rafi3js15092026/10/06 21:24:11 WARN Failed to register uploaded object key=8jy0pmwhzivffvz7mnpfp7w07y66dgcs.ls error="server returned 404: 404 page not found\n"15102026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1kcdza74933kdyaa6l9yzqq827xrlinm45zbyvdjsy370q9ckixx.nar.zst error="server returned 404: 404 page not found\n"15112026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15122026/10/06 21:24:11 WARN Failed to register uploaded object key=w10qp8q4fwvanfil1yc74xskp1ykvgy2.ls error="server returned 404: 404 page not found\n"15132026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15142026/10/06 21:24:11 WARN Failed to register uploaded object key=82ar48jgk8fyr1nkzcm7v8ak48iw7106.ls error="server returned 404: 404 page not found\n"15152026/10/06 21:24:11 INFO Signed narinfos id=1 count=315162026/10/06 21:24:11 INFO Uploading 3 narinfos1517=== NAME TestClientWithDependencies1518 client_integration_test.go:615: Found 1 dependencies (including self)1519=== NAME TestClientFallsBackToClosures1520 client_pushes_test.go:112: Retrieved narinfo from S3:1521 StorePath: /build/TestClientFallsBackToClosures4151399599/001/store/zjxb10nai2334hamvqv5a9r504gxi1mm-b1522 URL: nar/04y1qrnv0l3shpdy9bvslrd59ffl88rzkw6npjnxc8qm3dp8r798.nar.zst1523 Compression: zstd1524 NarHash: sha256:04y1qrnv0l3shpdy9bvslrd59ffl88rzkw6npjnxc8qm3dp8r7981525 NarSize: 2161526 References: /build/TestClientFallsBackToClosures4151399599/001/store/jdpglq5n9d6lr7jg3qf893frd3h4v08p-shared-dep1527 CA: text:sha256:04r5r5iwnqi6y71cb7cdcjiq3myy0zmk5qz0fpr8jark3rafi3js1528--- PASS: TestClientSharedPathCommittedMidPush (0.57s)1529=== CONT TestPendingClosureWriteTimeout/400_objects1530=== CONT TestIsValidUploadKey/narinfo1531=== CONT TestIsValidUploadKey/realisation_plus_in_output1532=== CONT TestIsValidUploadKey/unknown_type1533=== CONT TestIsValidUploadKey/empty_key1534=== CONT TestIsValidUploadKey/absolute1535=== CONT TestIsValidUploadKey/traversal_nar1536=== CONT TestIsValidUploadKey/traversal1537=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1538=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1539=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1540=== CONT TestIsValidUploadKey/index.html1541=== CONT TestIsValidUploadKey/nix-cache-info1542=== CONT TestIsValidUploadKey/build_log_home-manager_file1543=== CONT TestIsValidUploadKey/realisation1544=== CONT TestIsValidUploadKey/build_log_equals1545=== CONT TestIsValidUploadKey/build_log_question_mark1546=== CONT TestIsValidUploadKey/build_log_plus_in_name1547=== CONT TestIsValidUploadKey/build_log1548=== CONT TestIsValidUploadKey/nar_xz1549=== CONT TestIsValidUploadKey/listing1550=== CONT TestIsValidUploadKey/nar_zst1551=== CONT TestIsValidUploadKey/nar_plain1552--- PASS: TestIsValidUploadKey (0.00s)1553 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1554 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1555 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1556 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1557 --- PASS: TestIsValidUploadKey/absolute (0.00s)1558 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1559 --- PASS: TestIsValidUploadKey/traversal (0.00s)1560 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1561 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1562 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1563 --- PASS: TestIsValidUploadKey/index.html (0.00s)1564 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1565 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1566 --- PASS: TestIsValidUploadKey/realisation (0.00s)1567 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1568 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1569 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1570 --- PASS: TestIsValidUploadKey/build_log (0.00s)1571 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1572 --- PASS: TestIsValidUploadKey/listing (0.00s)1573 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1574 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1575=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15762026/10/06 21:24:11 WARN Failed to register uploaded object key=w10qp8q4fwvanfil1yc74xskp1ykvgy2.narinfo error="server returned 404: 404 page not found\n"15772026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/06 21:24:11 WARN Failed to register uploaded object key=8jy0pmwhzivffvz7mnpfp7w07y66dgcs.narinfo error="server returned 404: 404 page not found\n"15792026/10/06 21:24:11 WARN Failed to register uploaded object key=82ar48jgk8fyr1nkzcm7v8ak48iw7106.narinfo error="server returned 404: 404 page not found\n"1580--- PASS: TestClientFallsBackToClosures (0.65s)1581=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15822026/10/06 21:24:11 INFO Completed push id=115832026/10/06 21:24:11 INFO Upload complete. (68ms)1584=== NAME TestClientPushesUseOnePush1585 client_pushes_test.go:97: Retrieved narinfo from S3:1586 StorePath: /build/TestClientPushesUseOnePush2717278324/001/store/82ar48jgk8fyr1nkzcm7v8ak48iw7106-shared-dep1587 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1588 Compression: zstd1589 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821590 NarSize: 1361591 References: 1592 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1593 client_pushes_test.go:97: Retrieved narinfo from S3:1594 StorePath: /build/TestClientPushesUseOnePush2717278324/001/store/w10qp8q4fwvanfil1yc74xskp1ykvgy2-a1595 URL: nar/1kcdza74933kdyaa6l9yzqq827xrlinm45zbyvdjsy370q9ckixx.nar.zst1596 Compression: zstd1597 NarHash: sha256:1kcdza74933kdyaa6l9yzqq827xrlinm45zbyvdjsy370q9ckixx1598 NarSize: 2161599 References: /build/TestClientPushesUseOnePush2717278324/001/store/82ar48jgk8fyr1nkzcm7v8ak48iw7106-shared-dep1600 CA: text:sha256:08ph0dgdqfjghzz1910wlcdiqd62brcxa7pjvciwwz5j8fj6kw1y16012026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1602 client_pushes_test.go:97: Retrieved narinfo from S3:1603 StorePath: /build/TestClientPushesUseOnePush2717278324/001/store/8jy0pmwhzivffvz7mnpfp7w07y66dgcs-b1604 URL: nar/1kcdza74933kdyaa6l9yzqq827xrlinm45zbyvdjsy370q9ckixx.nar.zst1605 Compression: zstd1606 NarHash: sha256:1kcdza74933kdyaa6l9yzqq827xrlinm45zbyvdjsy370q9ckixx1607 NarSize: 2161608 References: /build/TestClientPushesUseOnePush2717278324/001/store/82ar48jgk8fyr1nkzcm7v8ak48iw7106-shared-dep1609 CA: text:sha256:08ph0dgdqfjghzz1910wlcdiqd62brcxa7pjvciwwz5j8fj6kw1y1610--- PASS: TestCacheStatsHandler (0.34s)1611=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16122026/10/06 21:24:11 INFO Received uploads request method=POST path=/1613=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16142026/10/06 21:24:11 INFO Received complete multipart upload request method=POST path=/1615=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16162026/10/06 21:24:11 INFO Received uploads request method=POST path=/1617=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16182026/10/06 21:24:11 INFO Received request for more parts method=POST path=/1619--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1620 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1621 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1622 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1623 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1624=== CONT TestIsValidCachePath/narinfo1625=== CONT TestIsValidCachePath/wrong_extension1626=== CONT TestIsValidCachePath/leading_slash1627=== NAME TestClientMultipleUploads1628 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1222347740/001/store/bkzw9nsawni7yh5r3ryjpx2rgpjzq84q-test-file-1.txt1629=== CONT TestIsValidCachePath/empty1630=== CONT TestIsValidCachePath/short_hash1631=== CONT TestIsValidCachePath/random_path1632=== CONT TestIsValidCachePath/log1633=== CONT TestIsValidCachePath/ls1634=== CONT TestIsValidCachePath/nar_uncompressed1635=== CONT TestIsValidCachePath/nar_bz21636=== CONT TestIsValidCachePath/nar_xz1637=== CONT TestIsValidCachePath/nar_zst1638=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1639=== CONT TestIsValidCachePath/realisation1640=== CONT TestIsValidCachePath/traversal_in_middle1641=== CONT TestIsValidCachePath/invalid_char_u1642=== CONT TestIsValidCachePath/invalid_char_e1643=== CONT TestIsValidCachePath/traversal_parent1644=== CONT TestIsValidCachePath/nix-cache-info1645=== CONT TestIsValidCachePath/index.html1646--- PASS: TestIsValidCachePath (0.00s)1647 --- PASS: TestIsValidCachePath/narinfo (0.00s)1648 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1649 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1650 --- PASS: TestIsValidCachePath/empty (0.00s)1651 --- PASS: TestIsValidCachePath/short_hash (0.00s)1652 --- PASS: TestIsValidCachePath/random_path (0.00s)1653 --- PASS: TestIsValidCachePath/log (0.00s)1654 --- PASS: TestIsValidCachePath/ls (0.00s)1655 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1656 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1657 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1658 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1659 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1660 --- PASS: TestIsValidCachePath/realisation (0.00s)1661 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1662 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1663 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1664 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1665 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1666 --- PASS: TestIsValidCachePath/index.html (0.00s)1667=== CONT TestParseSingleRange/none1668=== CONT TestParseSingleRange/single_byte1669=== CONT TestParseSingleRange/suffix_exceeds_size1670=== CONT TestParseSingleRange/suffix1671=== CONT TestParseSingleRange/start_past_EOF1672=== CONT TestParseSingleRange/end_clamped_to_size1673=== CONT TestParseSingleRange/open-ended1674=== CONT TestParseSingleRange/closed1675=== CONT TestParseSingleRange/malformed_end_before_start1676=== CONT TestParseSingleRange/malformed_both_empty1677=== CONT TestParseSingleRange/unknown_unit1678=== CONT TestParseSingleRange/start_far_past_EOF1679=== CONT TestParseSingleRange/malformed_no_dash1680=== CONT TestParseSingleRange/multi-range_ignored1681=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16822026/10/06 21:24:11 INFO Received uploads request method=POST path=/1683--- PASS: TestParseSingleRange (0.00s)1684 --- PASS: TestParseSingleRange/none (0.00s)1685 --- PASS: TestParseSingleRange/single_byte (0.00s)1686 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1687 --- PASS: TestParseSingleRange/suffix (0.00s)1688 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1689 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1690 --- PASS: TestParseSingleRange/open-ended (0.00s)1691 --- PASS: TestParseSingleRange/closed (0.00s)1692 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1693 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1694 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1695 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1696 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1697 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)16982026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16992026/10/06 21:24:11 INFO Uploading 7wml6l98knla8k032wapzcph850ypdz0-pinned-file.txt (128B)1700--- PASS: TestClientPushesUseOnePush (0.61s)1701=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17022026/10/06 21:24:11 INFO Received complete multipart upload request method=POST path=/17032026/10/06 21:24:11 WARN Failed to register uploaded object key=7wml6l98knla8k032wapzcph850ypdz0.ls error="server returned 404: 404 page not found\n"17042026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17052026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17062026/10/06 21:24:11 INFO Signed narinfos id=1 count=117072026/10/06 21:24:11 INFO Uploading 1 narinfos17082026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete17092026/10/06 21:24:11 WARN Failed to register uploaded object key=7wml6l98knla8k032wapzcph850ypdz0.narinfo error="server returned 404: 404 page not found\n"17102026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17112026/10/06 21:24:11 WARN mTLS auth: bound subjects configured but subject DN unavailable17122026/10/06 21:24:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1713--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.26s)1714=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17152026/10/06 21:24:11 INFO Received request for more parts method=POST path=/17162026/10/06 21:24:11 INFO Completed push id=117172026/10/06 21:24:11 INFO Upload complete. (61ms)1718=== NAME TestOrphanedObjectsGC1719 orphaned_objects_gc_test.go:287: GC Test Summary:1720 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1721 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1722 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1723 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1724 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1725--- PASS: TestOrphanedObjectsGC (0.75s)1726=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1727=== NAME TestClientMultipleUploads1728 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1222347740/001/store/w8y4srk77x5ha76kv5lsryc5k49f3b4c-test-file-2.txt17292026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes1730--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.18s)1731=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh17322026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17332026/10/06 21:24:11 INFO Uploading c8nafh04nl4mmil5xzq3iqh22zsqmz50-test-script (136B)17342026/10/06 21:24:11 WARN Failed to register uploaded object key=c8nafh04nl4mmil5xzq3iqh22zsqmz50.ls error="server returned 404: 404 page not found\n"17352026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17362026/10/06 21:24:11 WARN Failed to register uploaded object key=log/1r9g0b0c1xwfrr1v4p3dfwbhhv9m7mfh-test-script.drv error="server returned 404: 404 page not found\n"17372026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17382026/10/06 21:24:11 INFO Signed narinfos id=1 count=117392026/10/06 21:24:11 INFO Uploading 1 narinfos17402026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete17412026/10/06 21:24:11 WARN Failed to register uploaded object key=c8nafh04nl4mmil5xzq3iqh22zsqmz50.narinfo error="server returned 404: 404 page not found\n"1742=== CONT TestServerTLSConfig/no_client_CA1743=== CONT TestServerTLSConfig/missing_CA_file1744=== CONT TestServerTLSConfig/not_a_PEM_file1745--- PASS: TestServerTLSConfig (0.00s)1746 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1747 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1748 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1749=== CONT TestProxyWriteTimeout/narinfo1750=== CONT TestProxyWriteTimeout/unknown_size1751=== CONT TestProxyWriteTimeout/1_GiB_nar1752=== CONT TestProxyWriteTimeout/10_GiB_nar1753--- PASS: TestProxyWriteTimeout (0.00s)1754 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1755 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1756 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1757 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1758=== CONT TestResolveDBConnectionString/flag_wins1759=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1760=== CONT TestResolveDBConnectionString/nothing_configured1761=== CONT TestResolveDBConnectionString/missing_file_is_an_error1762=== CONT TestResolveDBConnectionString/file_when_flag_empty1763=== CONT TestGCEndsOnShutdown/before_the_run1764--- PASS: TestResolveDBConnectionString (0.00s)1765 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1766 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1767 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1768 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1769 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17702026/10/06 21:24:11 INFO Completed push id=117712026/10/06 21:24:11 INFO Upload complete. (62ms)1772=== NAME TestClientWithDependencies1773 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2464634149/001/store) requires matching store prefix1774--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.80s)1775=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1776--- PASS: TestClientWithDependencies (0.60s)1777=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1778=== CONT TestClientErrorHandling/InvalidStorePath17792026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes17802026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17812026/10/06 21:24:11 INFO Uploading cldzc8dhcxqd4nlmgkhqlh321ikvgwg0-unpinned-file.txt (128B)17822026/10/06 21:24:11 WARN Failed to register uploaded object key=cldzc8dhcxqd4nlmgkhqlh321ikvgwg0.ls error="server returned 404: 404 page not found\n"17832026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17842026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17852026/10/06 21:24:11 INFO Signed narinfos id=2 count=117862026/10/06 21:24:11 INFO Uploading 1 narinfos17872026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/2/complete1788=== RUN TestService_RequireScope_OIDC/builder_may_write1789=== PAUSE TestService_RequireScope_OIDC/builder_may_write1790=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1791=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1792=== RUN TestService_RequireScope_OIDC/ops_may_admin1793=== PAUSE TestService_RequireScope_OIDC/ops_may_admin17942026/10/06 21:24:11 WARN Failed to register uploaded object key=cldzc8dhcxqd4nlmgkhqlh321ikvgwg0.narinfo error="server returned 404: 404 page not found\n"1795=== RUN TestService_RequireScope_OIDC/ops_may_not_write1796=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1797=== RUN TestService_RequireScope_OIDC/reader_may_not_write1798=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1799=== RUN TestService_RequireScope_OIDC/static_token_may_admin1800=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1801=== RUN TestService_RequireScope_OIDC/static_token_may_write1802=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1803=== RUN TestService_RequireScope_OIDC/reader_may_read1804=== PAUSE TestService_RequireScope_OIDC/reader_may_read18052026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures1806=== RUN TestService_RequireScope_OIDC/writer_implies_read1807=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1808=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1809=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1810=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1811=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1812=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1813=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1814=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1815=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18162026/10/06 21:24:11 INFO Completed push id=21817=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1818=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1819=== CONT TestClientErrorHandling/ServerNotAvailable18202026/10/06 21:24:11 INFO Upload complete. (55ms)18212026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes18222026/10/06 21:24:11 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18232026/10/06 21:24:11 INFO Uploading w8y4srk77x5ha76kv5lsryc5k49f3b4c-test-file-2.txt (160B)18242026/10/06 21:24:11 INFO Uploading 83g9bm6bkzigbl98vdlya6dkqdrnn0lh-test-file-0.txt (160B)18252026/10/06 21:24:11 INFO Uploading bkzw9nsawni7yh5r3ryjpx2rgpjzq84q-test-file-1.txt (160B)18262026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18272026/10/06 21:24:11 WARN Failed to register uploaded object key=83g9bm6bkzigbl98vdlya6dkqdrnn0lh.ls error="server returned 404: 404 page not found\n"18282026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18292026/10/06 21:24:11 WARN Failed to register uploaded object key=w8y4srk77x5ha76kv5lsryc5k49f3b4c.ls error="server returned 404: 404 page not found\n"18302026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18312026/10/06 21:24:11 WARN Failed to register uploaded object key=bkzw9nsawni7yh5r3ryjpx2rgpjzq84q.ls error="server returned 404: 404 page not found\n"18322026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18332026/10/06 21:24:11 INFO Signed narinfos id=1 count=318342026/10/06 21:24:11 INFO Uploading 3 narinfos18352026/10/06 21:24:11 WARN Failed to register uploaded object key=w8y4srk77x5ha76kv5lsryc5k49f3b4c.narinfo error="server returned 404: 404 page not found\n"1836=== NAME TestClientCADerivations1837 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1127431768/001/store/7sg4z74i06wfdm8yld8ipr2ndmk4g6vr-ca-test18382026/10/06 21:24:11 WARN Failed to register uploaded object key=bkzw9nsawni7yh5r3ryjpx2rgpjzq84q.narinfo error="server returned 404: 404 page not found\n"18392026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete18402026/10/06 21:24:11 WARN Failed to register uploaded object key=83g9bm6bkzigbl98vdlya6dkqdrnn0lh.narinfo error="server returned 404: 404 page not found\n"18412026/10/06 21:24:11 INFO Completed push id=118422026/10/06 21:24:11 INFO Upload complete. (60ms)1843=== NAME TestClientMultipleUploads1844 client_integration_test.go:369: Uploaded 3 paths in 95.135335ms18452026/10/06 21:24:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39567/oidc18462026/10/06 21:24:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures18472026/10/06 21:24:11 INFO Garbage collection started1848--- PASS: TestClientMultipleUploads (0.59s)1849=== CONT TestClientErrorHandling/InvalidAuthToken18502026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures18512026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=018522026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=018532026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period18542026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period1855=== NAME TestClientCADerivations1856 client_ca_test.go:139: Found 1 dependencies (including self)18572026/10/06 21:24:11 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=018582026/10/06 21:24:11 INFO Received uploads request method=POST path=/api/pending_closures18592026/10/06 21:24:11 INFO Vacuumed table table=pending_closures18602026/10/06 21:24:11 INFO Vacuumed table table=pending_objects18612026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads18622026/10/06 21:24:11 INFO Vacuumed table table=closures18632026/10/06 21:24:11 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=018642026/10/06 21:24:11 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/present18652026/10/06 21:24:11 INFO Vacuumed table table=objects18662026/10/06 21:24:11 INFO Vacuumed table table=pending_closures18672026/10/06 21:24:11 INFO Vacuumed table table=pending_objects18682026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads18692026/10/06 21:24:11 INFO Vacuumed table table=closures18702026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=018712026/10/06 21:24:11 INFO Vacuumed table table=objects18722026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period18732026/10/06 21:24:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018742026/10/06 21:24:11 INFO Vacuumed table table=pending_closures1875=== CONT TestCacheConfigHandler/full_config,_no_issuer1876=== CONT TestCacheConfigHandler/no_signing_keys1877=== CONT TestCacheConfigHandler/no_cache_url_configured1878=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1879--- PASS: TestCacheConfigHandler (0.00s)1880 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1881 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1882 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1883 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1884=== CONT TestService_RequireScope_OIDC/builder_may_write1885=== CONT TestService_RequireScope_OIDC/reader_may_read1886=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1887=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18882026/10/06 21:24:11 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]1889=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1890=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1891=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1892=== CONT TestService_RequireScope_OIDC/writer_implies_read1893=== CONT TestService_RequireScope_OIDC/reader_may_not_write1894=== CONT TestService_RequireScope_OIDC/static_token_may_write1895=== CONT TestService_RequireScope_OIDC/static_token_may_admin1896=== CONT TestService_RequireScope_OIDC/ops_may_admin1897=== CONT TestService_RequireScope_OIDC/ops_may_not_write1898=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1899--- PASS: TestService_RequireScope_OIDC (0.48s)1900 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19142026/10/06 21:24:11 INFO Vacuumed table table=pending_objects19152026/10/06 21:24:11 INFO Vacuumed table table=multipart_uploads19162026/10/06 21:24:11 INFO Vacuumed table table=closures19172026/10/06 21:24:11 INFO Vacuumed table table=objects1918--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1919 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.22s)1920 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.23s)19212026/10/06 21:24:11 INFO Received push request method=POST path=/api/pushes19222026/10/06 21:24:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19232026/10/06 21:24:11 INFO Uploading 7sg4z74i06wfdm8yld8ipr2ndmk4g6vr-ca-test (144B)19242026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=019252026/10/06 21:24:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.398887ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19262026/10/06 21:24:11 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19272026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period19282026/10/06 21:24:11 WARN Failed to register uploaded object key=7sg4z74i06wfdm8yld8ipr2ndmk4g6vr.ls error="server returned 404: 404 page not found\n"19292026/10/06 21:24:11 WARN Failed to register uploaded object key=log/70wcs08w8spniza4j7rnxq09j82alxsm-ca-test.drv error="server returned 404: 404 page not found\n"19302026/10/06 21:24:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19312026/10/06 21:24:11 INFO Signed narinfos id=1 count=119322026/10/06 21:24:11 INFO Uploading 1 narinfos19332026/10/06 21:24:11 INFO Received complete push request method=POST path=/api/pushes/1/complete19342026/10/06 21:24:11 WARN Failed to register uploaded object key=7sg4z74i06wfdm8yld8ipr2ndmk4g6vr.narinfo error="server returned 404: 404 page not found\n"19352026/10/06 21:24:11 INFO Aborted multipart uploads count=0 kept=019362026/10/06 21:24:11 INFO Completed push id=119372026/10/06 21:24:11 INFO Upload complete. (95ms)19382026/10/06 21:24:11 WARN Force mode enabled - objects will be deleted immediately without grace period19392026-10-06 21:24:11.984 UTC [1655] ERROR: canceling statement due to user request19402026-10-06 21:24:11.984 UTC [1655] CONTEXT: PL/pgSQL expression "d_count <> 0 OR d_bytes <> 0"1941 PL/pgSQL function object_stats_apply() line 16 at IF19422026-10-06 21:24:11.984 UTC [1655] STATEMENT: -- name: MarkStaleObjects :execrows1943 WITH RECURSIVE ct AS (1944 SELECT timezone('UTC', now()) AS now1945 ),1946 closure_reach AS (1947 -- Start with all closure keys1948 SELECT o.key, o.refs1949 FROM objects o1950 INNER JOIN closures c ON o.key = c.key1951 UNION1952 -- Recursively add all referenced objects1953 SELECT o.key, o.refs1954 FROM objects o1955 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1956 ),1957 reachable_objects AS (1958 SELECT DISTINCT key FROM closure_reach1959 ),1960 stale_objects AS (1961 SELECT o.key1962 FROM objects AS o, ct1963 WHERE1964 NOT EXISTS (1965 SELECT 11966 FROM reachable_objects ro1967 WHERE ro.key = o.key1968 )1969 AND NOT EXISTS (1970 SELECT 11971 FROM pending_objects AS po1972 WHERE po.key = o.key1973 )1974 AND o.deleted_at IS NULL -- Only mark fresh objects1975 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1976 FOR UPDATE1977 )1978 UPDATE objects1979 SET1980 deleted_at = ct.now,1981 first_deleted_at = COALESCE(first_deleted_at, ct.now)1982 FROM stale_objects, ct1983 WHERE objects.key = stale_objects.key1984 1985=== NAME TestClientCADerivations1986 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1127431768/001/store/7sg4z74i06wfdm8yld8ipr2ndmk4g6vr-ca-test1987 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1988 Compression: zstd1989 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1990 NarSize: 1441991 References: 1992 Deriver: /build/TestClientCADerivations1127431768/001/store/70wcs08w8spniza4j7rnxq09j82alxsm-ca-test.drv1993 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1994 client_ca_test.go:185: Checking for realisation files in S3...1995 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1996 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19972026/10/06 21:24:11 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44679/bucket95/?delete=\": context canceled"1998--- PASS: TestGCEndsOnShutdown (0.00s)1999 --- PASS: TestGCEndsOnShutdown/before_the_run (0.17s)2000 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)2001 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.22s)2002=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2003=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2004=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2005=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2006=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2007=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2008=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2009=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2010=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2011=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2012=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20132026/10/06 21:24:12 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2014=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20152026/10/06 21:24:12 WARN Authentication failed token_preview=eyJhbGciOi...Zmb6inW1ZA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2016--- PASS: TestService_AuthMiddleware_OIDC (0.45s)2017 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2018 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2019 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2020 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2021=== NAME TestClientCADerivations2022 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2023 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2024 error: binary cache 's3://bucket85?endpoint=http://localhost:44679®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1127431768/001/store'2025 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12026--- PASS: TestClientCADerivations (0.52s)20272026/10/06 21:24:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20282026/10/06 21:24:12 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20292026/10/06 21:24:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.094292ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20302026/10/06 21:24:12 INFO lead: released remote=192.0.2.1:12342031--- PASS: TestLeadEndsOnShutdown (1.44s)2032--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2033 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.66s)2034 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.67s)20352026/10/06 21:24:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=845.239156ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2036=== NAME TestOrphanedObjectsGCStressTest2037 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2038--- PASS: TestPendingClosureWriteTimeout (0.00s)2039 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2040 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2041 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2042 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.01s)2043=== NAME TestOrphanedObjectsGCStressTest2044 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2045--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2046 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2047 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2048 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.98s)2049--- PASS: TestDeleteClosuresRacingPins (1.70s)2050=== NAME TestOrphanedObjectsGCStressTest2051 orphaned_objects_gc_test.go:503: Stress test completed successfully:2052 orphaned_objects_gc_test.go:504: - Active objects preserved: 202053 orphaned_objects_gc_test.go:505: - Objects deleted: 2102054 orphaned_objects_gc_test.go:506: - Total GC'd: 2102055--- PASS: TestOrphanedObjectsGCStressTest (1.92s)20562026/10/06 21:24:12 INFO lead: released remote=192.0.2.1:123420572026/10/06 21:24:12 INFO lead: acquired remote=192.0.2.1:123420582026/10/06 21:24:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.676484073s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20592026/10/06 21:24:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02060=== NAME TestClientIntegration2061 client_integration_test.go:323: Objects in database after GC:2062 client_integration_test.go:323: Successfully deleted all objects with GC --force2063--- PASS: TestClientIntegration (2.61s)20642026/10/06 21:24:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020652026/10/06 21:24:13 INFO Received create pin request method=POST path=/api/pins/myapp20662026/10/06 21:24:13 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4288637461/001/store/7wml6l98knla8k032wapzcph850ypdz0-pinned-file.txt narinfo_key=7wml6l98knla8k032wapzcph850ypdz0.narinfo20672026/10/06 21:24:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures20682026/10/06 21:24:13 INFO Garbage collection started20692026/10/06 21:24:13 INFO Aborted multipart uploads count=0 kept=020702026/10/06 21:24:13 WARN Force mode enabled - objects will be deleted immediately without grace period20712026/10/06 21:24:13 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=020722026/10/06 21:24:13 INFO Vacuumed table table=pending_closures20732026/10/06 21:24:13 INFO Vacuumed table table=pending_objects20742026/10/06 21:24:13 INFO Vacuumed table table=multipart_uploads20752026/10/06 21:24:13 INFO Vacuumed table table=closures20762026/10/06 21:24:13 INFO Vacuumed table table=objects20772026/10/06 21:24:14 INFO lead: released remote=192.0.2.1:12342078--- PASS: TestLeadElectsOneAndHandsOver (2.76s)20792026/10/06 21:24:14 WARN Rate limiter enabled after throttle name=s3-test rate=520802026/10/06 21:24:14 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2081=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2082 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102083 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002084--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.96s)2085--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.63s)20862026/10/06 21:24:15 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-config20872026/10/06 21:24:15 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.540311ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20882026/10/06 21:24:15 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.705203ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/06 21:24:15 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=825.681829ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2090=== NAME TestPinProtectsFromGC2091 client_integration_test.go:840: Pin successfully protected closure from garbage collection2092--- PASS: TestPinProtectsFromGC (4.69s)2093--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20942026/10/06 21:24:16 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.684904761s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/06 21:24:17 INFO Aborted multipart uploads count=1 kept=020962026/10/06 21:24:17 INFO Received cleanup request method=DELETE path=/api/pending_closures20972026/10/06 21:24:17 INFO Aborted multipart uploads count=1 kept=02098--- PASS: TestPendingCleanupUsesOneCutoff (6.40s)20992026/10/06 21:24:18 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"21002026/10/06 21:24:18 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-config21012026/10/06 21:24:18 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.972493ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21022026/10/06 21:24:18 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=421.947045ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21032026/10/06 21:24:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=802.179623ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21042026/10/06 21:24:19 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.618580836s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21052026/10/06 21:24:21 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_closures21062026/10/06 21:24:21 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.064747ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21072026/10/06 21:24:21 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=430.264765ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21082026/10/06 21:24:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=858.430468ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21092026/10/06 21:24:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.457907681s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2110--- PASS: TestClientErrorHandling (0.00s)2111 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)2112 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.30s)2113 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.71s)2114PASS21152026-10-06 21:24:24.750 UTC [130] LOG: received smart shutdown request21162026-10-06 21:24:24.754 UTC [130] LOG: background worker "logical replication launcher" (PID 140) exited with exit code 121172026-10-06 21:24:24.765 UTC [135] LOG: shutting down21182026-10-06 21:24:24.765 UTC [135] LOG: checkpoint starting: shutdown immediate21192026-10-06 21:24:25.615 UTC [135] LOG: checkpoint complete: wrote 10664 buffers (65.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.174 s, sync=0.643 s, total=0.850 s; sync files=33373, longest=0.002 s, average=0.001 s; distance=484158 kB, estimate=484158 kB; lsn=0/1F0356B0, redo lsn=0/1F0356B021202026-10-06 21:24:25.688 UTC [130] LOG: database system is shut down2121Running OIDC tests...2122=== RUN TestAudienceForIssuer2123=== PAUSE TestAudienceForIssuer2124=== RUN TestGlobMatch2125=== PAUSE TestGlobMatch2126=== RUN TestValidateToken_ValidToken2127=== PAUSE TestValidateToken_ValidToken2128=== RUN TestValidateToken_WrongAudience2129=== PAUSE TestValidateToken_WrongAudience2130=== RUN TestValidateToken_Expired2131=== PAUSE TestValidateToken_Expired2132=== RUN TestValidateToken_BoundClaimsMismatch2133=== PAUSE TestValidateToken_BoundClaimsMismatch2134=== RUN TestValidateToken_BoundSubjectMismatch2135=== PAUSE TestValidateToken_BoundSubjectMismatch2136=== RUN TestValidateToken_MultipleProviders2137=== PAUSE TestValidateToken_MultipleProviders2138=== RUN TestValidateToken_NoMatchingProvider2139=== PAUSE TestValidateToken_NoMatchingProvider2140=== RUN TestValidateToken_KubernetesServiceAccount2141=== PAUSE TestValidateToken_KubernetesServiceAccount2142=== RUN TestNewValidator_KubernetesRequiresCA2143=== PAUSE TestNewValidator_KubernetesRequiresCA2144=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2145=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2146=== RUN TestPins_ReservedForMatchingRule2147=== PAUSE TestPins_ReservedForMatchingRule2148=== RUN TestPins_TopLevelShorthand2149=== PAUSE TestPins_TopLevelShorthand2150=== RUN TestPins_ConfigValidation2151=== PAUSE TestPins_ConfigValidation2152=== RUN TestScopes_LegacyProviderDefaultsToWrite2153=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2154=== RUN TestScopes_Rules2155=== PAUSE TestScopes_Rules2156=== RUN TestScopes_ConfigValidation2157=== PAUSE TestScopes_ConfigValidation2158=== CONT TestAudienceForIssuer2159=== CONT TestValidateToken_KubernetesServiceAccount2160=== CONT TestValidateToken_BoundClaimsMismatch2161=== CONT TestPins_ConfigValidation2162--- PASS: TestAudienceForIssuer (0.00s)2163=== CONT TestScopes_ConfigValidation2164=== CONT TestValidateToken_Expired2165=== CONT TestValidateToken_WrongAudience2166=== CONT TestScopes_Rules2167--- PASS: TestPins_ConfigValidation (0.00s)2168=== CONT TestValidateToken_ValidToken2169=== CONT TestGlobMatch2170=== RUN TestGlobMatch/foo_foo2171=== PAUSE TestGlobMatch/foo_foo2172=== RUN TestGlobMatch/foo_bar2173=== PAUSE TestGlobMatch/foo_bar2174=== RUN TestGlobMatch/*_2175=== PAUSE TestGlobMatch/*_2176=== RUN TestGlobMatch/*_anything2177=== PAUSE TestGlobMatch/*_anything2178=== RUN TestGlobMatch/foo*_foo2179=== PAUSE TestGlobMatch/foo*_foo2180=== RUN TestGlobMatch/foo*_foobar2181=== PAUSE TestGlobMatch/foo*_foobar2182=== RUN TestGlobMatch/foo*_bar2183=== CONT TestScopes_LegacyProviderDefaultsToWrite2184=== CONT TestValidateToken_MultipleProviders2185=== CONT TestValidateToken_NoMatchingProvider2186=== CONT TestPins_ReservedForMatchingRule2187=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2188=== CONT TestPins_TopLevelShorthand2189=== CONT TestNewValidator_KubernetesRequiresCA2190=== CONT TestValidateToken_BoundSubjectMismatch2191--- PASS: TestScopes_ConfigValidation (0.00s)2192=== PAUSE TestGlobMatch/foo*_bar2193=== RUN TestGlobMatch/*bar_bar2194=== PAUSE TestGlobMatch/*bar_bar2195=== RUN TestGlobMatch/*bar_foobar2196=== PAUSE TestGlobMatch/*bar_foobar2197=== RUN TestGlobMatch/*bar_foo2198=== PAUSE TestGlobMatch/*bar_foo2199=== RUN TestGlobMatch/foo*bar_foobar2200=== PAUSE TestGlobMatch/foo*bar_foobar2201=== RUN TestGlobMatch/foo*bar_foo123bar2202=== PAUSE TestGlobMatch/foo*bar_foo123bar2203=== RUN TestGlobMatch/foo*bar_foobarbaz2204=== PAUSE TestGlobMatch/foo*bar_foobarbaz2205=== RUN TestGlobMatch/*/*_foo/bar2206=== PAUSE TestGlobMatch/*/*_foo/bar2207=== RUN TestGlobMatch/*/*_foo2208=== PAUSE TestGlobMatch/*/*_foo2209=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2210=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2211=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02212=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02213=== RUN TestGlobMatch/refs/*/main_refs/heads/main2214=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2215=== RUN TestGlobMatch/fo?_foo2216=== PAUSE TestGlobMatch/fo?_foo2217=== RUN TestGlobMatch/fo?_fo2218=== PAUSE TestGlobMatch/fo?_fo2219=== RUN TestGlobMatch/fo?_fooo2220=== PAUSE TestGlobMatch/fo?_fooo2221=== RUN TestGlobMatch/?oo_foo2222=== PAUSE TestGlobMatch/?oo_foo2223=== RUN TestGlobMatch/?oo_boo2224=== PAUSE TestGlobMatch/?oo_boo2225=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2226=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2227=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2228=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2229=== CONT TestGlobMatch/foo_foo2230=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2231=== CONT TestGlobMatch/?oo_boo2232=== CONT TestGlobMatch/?oo_foo2233=== CONT TestGlobMatch/fo?_fooo2234=== CONT TestGlobMatch/fo?_fo2235=== CONT TestGlobMatch/fo?_foo2236=== CONT TestGlobMatch/refs/*/main_refs/heads/main2237=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2238=== CONT TestGlobMatch/*bar_bar2239=== CONT TestGlobMatch/foo*_bar2240=== CONT TestGlobMatch/foo*_foobar2241=== CONT TestGlobMatch/foo*_foo2242=== CONT TestGlobMatch/*_anything2243=== CONT TestGlobMatch/*_2244=== CONT TestGlobMatch/foo_bar2245=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02246=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2247=== CONT TestGlobMatch/*/*_foo2248=== CONT TestGlobMatch/*/*_foo/bar2249=== CONT TestGlobMatch/foo*bar_foobarbaz2250=== CONT TestGlobMatch/foo*bar_foo123bar2251=== CONT TestGlobMatch/foo*bar_foobar2252=== CONT TestGlobMatch/*bar_foo2253=== CONT TestGlobMatch/*bar_foobar2254--- PASS: TestGlobMatch (0.00s)2255 --- PASS: TestGlobMatch/foo_foo (0.00s)2256 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2257 --- PASS: TestGlobMatch/?oo_boo (0.00s)2258 --- PASS: TestGlobMatch/?oo_foo (0.00s)2259 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2260 --- PASS: TestGlobMatch/fo?_fo (0.00s)2261 --- PASS: TestGlobMatch/fo?_foo (0.00s)2262 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2263 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2264 --- PASS: TestGlobMatch/*bar_bar (0.00s)2265 --- PASS: TestGlobMatch/foo*_bar (0.00s)2266 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2267 --- PASS: TestGlobMatch/foo*_foo (0.00s)2268 --- PASS: TestGlobMatch/*_anything (0.00s)2269 --- PASS: TestGlobMatch/*_ (0.00s)2270 --- PASS: TestGlobMatch/foo_bar (0.00s)2271 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2272 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2273 --- PASS: TestGlobMatch/*/*_foo (0.00s)2274 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2275 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2276 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2277 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2278 --- PASS: TestGlobMatch/*bar_foo (0.00s)2279 --- PASS: TestGlobMatch/*bar_foobar (0.00s)22802026/10/06 21:24:27 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:466892281--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)22822026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41419/oidc2283--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)22842026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43667/oidc22852026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34421/oidc2286--- PASS: TestValidateToken_ValidToken (0.09s)2287--- PASS: TestScopes_Rules (0.10s)22882026/10/06 21:24:27 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322892026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33647/oidc22902026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34937/oidc2291--- PASS: TestValidateToken_WrongAudience (0.11s)2292--- PASS: TestPins_TopLevelShorthand (0.11s)2293--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)22942026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34887/oidc2295--- PASS: TestValidateToken_Expired (0.16s)22962026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45407/oidc2297--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)22982026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34729/oidc2299--- PASS: TestPins_ReservedForMatchingRule (0.17s)23002026/10/06 21:24:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46359/oidc23012026/10/06 21:24:27 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41647/oidc23022026/10/06 21:24:27 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41505/oidc2303--- PASS: TestValidateToken_NoMatchingProvider (0.19s)2304--- PASS: TestValidateToken_MultipleProviders (0.19s)23052026/10/06 21:24:27 http: TLS handshake error from 127.0.0.1:46416: remote error: tls: bad certificate2306--- PASS: TestNewValidator_KubernetesRequiresCA (0.26s)23072026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41213/oidc2308--- PASS: TestValidateToken_BoundSubjectMismatch (0.29s)2309PASS2310Running hook tests...2311=== RUN TestSendPathsEmpty2312=== PAUSE TestSendPathsEmpty2313=== RUN TestQueueEnqueueAndFetch2314=== PAUSE TestQueueEnqueueAndFetch2315=== RUN TestQueueDeduplication2316=== PAUSE TestQueueDeduplication2317=== RUN TestQueueRemove2318=== PAUSE TestQueueRemove2319=== RUN TestQueueFetchBatchLimit2320=== PAUSE TestQueueFetchBatchLimit2321=== RUN TestQueueRetryMovesToBack2322=== PAUSE TestQueueRetryMovesToBack2323=== RUN TestQueueFetchRemoveLifecycle2324=== PAUSE TestQueueFetchRemoveLifecycle2325=== RUN TestQueueConcurrentWriters2326=== PAUSE TestQueueConcurrentWriters2327=== RUN TestQueueRemoveLargeClosure2328=== PAUSE TestQueueRemoveLargeClosure2329=== RUN TestServerClientIntegration2330=== PAUSE TestServerClientIntegration2331=== RUN TestServerQueueError2332=== PAUSE TestServerQueueError2333=== RUN TestGetListenerSocketActivation2334 server_test.go:210: === RUN TestGetListenerSocketActivation2335 --- PASS: TestGetListenerSocketActivation (0.00s)2336 PASS2337 2338--- PASS: TestGetListenerSocketActivation (0.01s)2339=== RUN TestDrainIsolatesPoisonPath2340=== PAUSE TestDrainIsolatesPoisonPath2341=== RUN TestRunNotBlockedByPoisonHead2342=== PAUSE TestRunNotBlockedByPoisonHead2343=== RUN TestDrainGivesUpWhenServerDown2344=== PAUSE TestDrainGivesUpWhenServerDown2345=== RUN TestFailedPathPrunedByLaterClosure2346=== PAUSE TestFailedPathPrunedByLaterClosure2347=== RUN TestWorkerUploadsAndRemoves2348=== PAUSE TestWorkerUploadsAndRemoves2349=== RUN TestWorkerSkipsGCdPaths2350=== PAUSE TestWorkerSkipsGCdPaths2351=== RUN TestWorkerPrunesClosureDeps2352=== PAUSE TestWorkerPrunesClosureDeps2353=== RUN TestDrainTimeout2354=== PAUSE TestDrainTimeout2355=== CONT TestSendPathsEmpty2356=== CONT TestRunNotBlockedByPoisonHead2357--- PASS: TestSendPathsEmpty (0.00s)2358=== CONT TestDrainIsolatesPoisonPath2359=== CONT TestServerQueueError2360=== CONT TestServerClientIntegration2361=== CONT TestQueueRemoveLargeClosure2362=== CONT TestQueueConcurrentWriters23632026/10/06 21:24:27 ERROR Failed to queue paths error="permission denied" count=12364=== CONT TestQueueFetchRemoveLifecycle2365=== CONT TestQueueRetryMovesToBack2366=== CONT TestQueueFetchBatchLimit2367=== CONT TestQueueRemove2368=== CONT TestQueueDeduplication2369=== CONT TestQueueEnqueueAndFetch2370=== CONT TestFailedPathPrunedByLaterClosure2371=== CONT TestWorkerUploadsAndRemoves2372=== CONT TestDrainTimeout2373=== CONT TestWorkerPrunesClosureDeps2374=== CONT TestDrainGivesUpWhenServerDown2375=== CONT TestWorkerSkipsGCdPaths2376--- PASS: TestServerClientIntegration (0.00s)2377--- PASS: TestServerQueueError (0.00s)23782026/10/06 21:24:27 INFO Uploading batch count=423792026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=423802026/10/06 21:24:27 INFO Uploading batch count=223812026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=223822026/10/06 21:24:27 INFO Uploading batch count=123832026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=123842026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/a23852026/10/06 21:24:27 INFO Uploading batch count=223862026/10/06 21:24:27 INFO Uploading batch count=123872026/10/06 21:24:27 INFO Upload queue status pending=223882026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2059102105/002/bbb23892026/10/06 21:24:27 INFO Upload queue status pending=223902026/10/06 21:24:27 INFO Uploading batch count=223912026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/b23922026/10/06 21:24:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths761015769/002/nonexistent23932026/10/06 21:24:27 INFO Upload queue status pending=32394--- PASS: TestQueueEnqueueAndFetch (0.01s)23952026/10/06 21:24:27 INFO Uploading batch count=123962026/10/06 21:24:27 INFO Uploading batch count=123972026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=123982026/10/06 21:24:27 INFO Uploading batch count=223992026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=224002026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/c2401--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2402--- PASS: TestQueueRemove (0.01s)2403--- PASS: TestQueueRetryMovesToBack (0.02s)24042026/10/06 21:24:27 INFO Uploading batch count=124052026/10/06 21:24:27 INFO Upload queue status pending=224062026/10/06 21:24:27 INFO Uploading batch count=12407--- PASS: TestQueueFetchBatchLimit (0.02s)24082026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/d24092026/10/06 21:24:27 INFO Uploading batch count=124102026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=12411--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24122026/10/06 21:24:27 INFO Uploading batch count=224132026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=224142026/10/06 21:24:27 INFO Uploading batch count=124152026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=124162026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/e2417--- PASS: TestQueueDeduplication (0.02s)24182026/10/06 21:24:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4185893217/002/f24192026/10/06 21:24:27 INFO Uploading batch count=124202026/10/06 21:24:27 ERROR Upload failed error="upload failed" count=124212026/10/06 21:24:27 ERROR Drain finished with paths left in queue remaining=1024222026/10/06 21:24:27 ERROR Drain finished with paths left in queue remaining=12423--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2424--- PASS: TestDrainIsolatesPoisonPath (0.02s)2425--- PASS: TestWorkerUploadsAndRemoves (0.03s)2426--- PASS: TestWorkerSkipsGCdPaths (0.03s)2427--- PASS: TestWorkerPrunesClosureDeps (0.03s)2428--- PASS: TestQueueRemoveLargeClosure (0.09s)2429--- PASS: TestQueueConcurrentWriters (0.16s)24302026/10/06 21:24:27 ERROR Upload failed error="context deadline exceeded" count=224312026/10/06 21:24:27 ERROR Drain finished with paths left in queue remaining=42432--- PASS: TestDrainTimeout (0.21s)24332026/10/06 21:24:28 INFO Uploading batch count=124342026/10/06 21:24:28 INFO Uploading batch count=124352026/10/06 21:24:28 INFO Uploading batch count=124362026/10/06 21:24:28 ERROR Upload failed error="upload failed" count=124372026/10/06 21:24:28 INFO Uploading batch count=124382026/10/06 21:24:28 ERROR Upload failed error="upload failed" count=124392026/10/06 21:24:28 INFO Uploading batch count=124402026/10/06 21:24:28 ERROR Upload failed error="upload failed" count=124412026/10/06 21:24:28 INFO Uploading batch count=124422026/10/06 21:24:28 ERROR Upload failed error="upload failed" count=124432026/10/06 21:24:28 ERROR Drain finished with paths left in queue remaining=12444--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2445PASS2446Running signing tests...2447=== RUN TestExternalSigner2448=== PAUSE TestExternalSigner2449=== RUN TestExternalSignerWrongPublicKey2450=== PAUSE TestExternalSignerWrongPublicKey2451=== RUN TestExternalSignerErrors2452=== PAUSE TestExternalSignerErrors2453=== RUN TestExternalSignerRestartsAfterCrash2454=== PAUSE TestExternalSignerRestartsAfterCrash2455=== RUN TestExternalSignerProgramErrorKeepsProcess2456=== PAUSE TestExternalSignerProgramErrorKeepsProcess2457=== RUN TestExternalSignerClose2458=== PAUSE TestExternalSignerClose2459=== RUN TestExternalSignerRejectsInvalidPublicKey2460=== PAUSE TestExternalSignerRejectsInvalidPublicKey2461=== RUN TestExternalSignerCancellation2462=== PAUSE TestExternalSignerCancellation2463=== RUN TestGenerateFingerprint2464=== PAUSE TestGenerateFingerprint2465=== RUN TestParseSigningKey2466=== PAUSE TestParseSigningKey2467=== RUN TestSign2468=== PAUSE TestSign2469=== RUN TestSignBatch2470=== PAUSE TestSignBatch2471=== RUN TestNilKeyPublicKey2472=== PAUSE TestNilKeyPublicKey2473=== RUN TestSignErrors2474=== PAUSE TestSignErrors2475=== CONT TestExternalSigner2476=== CONT TestExternalSignerCancellation2477=== CONT TestExternalSignerProgramErrorKeepsProcess2478=== CONT TestExternalSignerRejectsInvalidPublicKey2479=== RUN TestExternalSignerRejectsInvalidPublicKey/#002480=== CONT TestSignErrors2481=== CONT TestNilKeyPublicKey2482--- PASS: TestNilKeyPublicKey (0.00s)2483=== CONT TestSignBatch2484=== CONT TestSign2485=== CONT TestParseSigningKey2486=== RUN TestParseSigningKey/valid_32-byte_key2487=== PAUSE TestParseSigningKey/valid_32-byte_key2488=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2489=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2490=== CONT TestGenerateFingerprint2491=== RUN TestGenerateFingerprint/basic_with_references2492=== CONT TestExternalSignerClose2493=== CONT TestExternalSignerErrors2494=== RUN TestExternalSignerErrors/invalid_JSON2495=== CONT TestExternalSignerRestartsAfterCrash2496=== CONT TestExternalSignerWrongPublicKey2497=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002498=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2499=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2500=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2501=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2502=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2503=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2504=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2505=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2506=== CONT TestExternalSignerRejectsInvalidPublicKey/#002507=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2508=== RUN TestParseSigningKey/no_colon2509=== PAUSE TestParseSigningKey/no_colon2510=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2511=== PAUSE TestGenerateFingerprint/basic_with_references2512=== PAUSE TestExternalSignerErrors/invalid_JSON2513=== RUN TestExternalSignerErrors/missing_signature_name2514=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2515=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2516--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2517 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2522=== RUN TestParseSigningKey/empty_name2523=== RUN TestGenerateFingerprint/no_references2524=== PAUSE TestGenerateFingerprint/no_references2525=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2526=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2527=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2528=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2529=== RUN TestGenerateFingerprint/invalid_nar_hash_length2530=== PAUSE TestExternalSignerErrors/missing_signature_name2531=== PAUSE TestParseSigningKey/empty_name2532=== RUN TestParseSigningKey/invalid_base642533=== PAUSE TestParseSigningKey/invalid_base642534=== RUN TestParseSigningKey/wrong_length2535=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2536=== RUN TestExternalSignerErrors/program_error2537=== PAUSE TestParseSigningKey/wrong_length2538=== CONT TestParseSigningKey/valid_32-byte_key2539=== CONT TestParseSigningKey/no_colon2540=== CONT TestParseSigningKey/invalid_base642541=== CONT TestParseSigningKey/wrong_length2542=== PAUSE TestExternalSignerErrors/program_error2543=== RUN TestExternalSignerErrors/wrong_shape2544=== PAUSE TestExternalSignerErrors/wrong_shape2545=== RUN TestGenerateFingerprint/invalid_store_path_prefix2546=== CONT TestParseSigningKey/empty_name2547=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2548=== RUN TestExternalSignerErrors/wrong_signature_name2549=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2550=== PAUSE TestExternalSignerErrors/wrong_signature_name2551=== RUN TestGenerateFingerprint/invalid_reference_prefix2552=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2553=== CONT TestGenerateFingerprint/basic_with_references2554=== CONT TestGenerateFingerprint/no_references2555=== RUN TestExternalSignerErrors/exit_at_startup2556=== PAUSE TestExternalSignerErrors/exit_at_startup2557=== RUN TestExternalSignerErrors/wrong_id2558=== PAUSE TestExternalSignerErrors/wrong_id2559=== CONT TestGenerateFingerprint/invalid_nar_hash_length2560=== CONT TestGenerateFingerprint/invalid_reference_prefix2561=== CONT TestGenerateFingerprint/invalid_store_path_prefix2562=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2563=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2564--- PASS: TestGenerateFingerprint (0.00s)2565 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2566 --- PASS: TestGenerateFingerprint/no_references (0.00s)2567 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2568 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2569 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2570 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2571 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2572=== RUN TestExternalSignerErrors/unrequested_key2573=== RUN TestSignErrors/nil_key2574=== PAUSE TestExternalSignerErrors/unrequested_key2575=== RUN TestExternalSignerErrors/exit_on_request2576--- PASS: TestParseSigningKey (0.00s)2577 --- PASS: TestParseSigningKey/no_colon (0.00s)2578 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2579 --- PASS: TestParseSigningKey/wrong_length (0.00s)2580 --- PASS: TestParseSigningKey/empty_name (0.00s)2581 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2582 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2583--- PASS: TestSign (0.00s)2584=== PAUSE TestSignErrors/nil_key2585=== PAUSE TestExternalSignerErrors/exit_on_request2586=== RUN TestSignErrors/nil_narinfo2587=== PAUSE TestSignErrors/nil_narinfo2588=== RUN TestSignErrors/invalid_narinfo2589=== PAUSE TestSignErrors/invalid_narinfo2590=== RUN TestSignErrors/canceled2591=== PAUSE TestSignErrors/canceled2592=== CONT TestSignErrors/nil_key2593=== CONT TestSignErrors/invalid_narinfo2594=== RUN TestExternalSignerErrors/null2595=== PAUSE TestExternalSignerErrors/null2596--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2597=== CONT TestSignErrors/canceled2598=== RUN TestExternalSignerErrors/missing_signatures2599=== PAUSE TestExternalSignerErrors/missing_signatures2600=== CONT TestSignErrors/nil_narinfo2601--- PASS: TestSignErrors (0.00s)2602 --- PASS: TestSignErrors/nil_key (0.00s)2603 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2604 --- PASS: TestSignErrors/canceled (0.00s)2605 --- PASS: TestSignErrors/nil_narinfo (0.00s)2606=== RUN TestExternalSignerErrors/null_signatures2607=== PAUSE TestExternalSignerErrors/null_signatures2608=== RUN TestExternalSignerErrors/wrong_signatures_shape2609=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2610=== RUN TestExternalSignerErrors/too_few_signatures2611--- PASS: TestSignBatch (0.00s)2612=== PAUSE TestExternalSignerErrors/too_few_signatures2613=== RUN TestExternalSignerErrors/invalid_signature_base642614=== PAUSE TestExternalSignerErrors/invalid_signature_base642615=== RUN TestExternalSignerErrors/wrong_signature_length2616=== PAUSE TestExternalSignerErrors/wrong_signature_length2617=== CONT TestExternalSignerErrors/invalid_JSON2618=== CONT TestExternalSignerErrors/exit_on_request2619=== CONT TestExternalSignerErrors/wrong_signature_name2620=== CONT TestExternalSignerErrors/exit_at_startup2621=== CONT TestExternalSignerErrors/null2622=== CONT TestExternalSignerErrors/wrong_signatures_shape2623=== CONT TestExternalSignerErrors/wrong_signature_length2624=== CONT TestExternalSignerErrors/invalid_signature_base642625=== CONT TestExternalSignerErrors/too_few_signatures2626=== CONT TestExternalSignerErrors/wrong_id2627=== CONT TestExternalSignerErrors/unrequested_key2628=== CONT TestExternalSignerErrors/program_error2629=== CONT TestExternalSignerErrors/wrong_shape2630=== CONT TestExternalSignerErrors/missing_signature_name2631=== CONT TestExternalSignerErrors/missing_signatures2632=== CONT TestExternalSignerErrors/null_signatures2633--- PASS: TestExternalSignerWrongPublicKey (0.00s)2634--- PASS: TestExternalSignerClose (0.00s)2635--- PASS: TestExternalSigner (0.01s)2636--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2637--- PASS: TestExternalSignerErrors (0.00s)2638 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2639 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2640 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2641 --- PASS: TestExternalSignerErrors/program_error (0.00s)2642 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2643 --- PASS: TestExternalSignerErrors/null (0.01s)2644 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2645 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2646 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2647 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2648 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2649 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2650 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2651 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2652 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2653 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2654--- PASS: TestExternalSignerCancellation (0.02s)2655PASS2656Running OpenBao signer tests...2657=== RUN TestSign2658=== PAUSE TestSign2659=== RUN TestSignErrors2660=== PAUSE TestSignErrors2661=== RUN TestServe2662=== PAUSE TestServe2663=== RUN TestServeRejectsGarbage2664=== PAUSE TestServeRejectsGarbage2665=== CONT TestSign2666=== CONT TestServe2667=== CONT TestSignErrors2668=== CONT TestServeRejectsGarbage2669=== RUN TestSignErrors/http_error2670=== PAUSE TestSignErrors/http_error2671=== RUN TestSignErrors/invalid_json2672=== PAUSE TestSignErrors/invalid_json2673--- PASS: TestServeRejectsGarbage (0.00s)2674=== RUN TestSignErrors/no_prefix2675=== PAUSE TestSignErrors/no_prefix2676=== RUN TestSignErrors/invalid_base642677=== PAUSE TestSignErrors/invalid_base642678=== CONT TestSignErrors/http_error2679=== CONT TestSignErrors/no_prefix2680--- PASS: TestServe (0.00s)2681=== CONT TestSignErrors/invalid_base642682=== CONT TestSignErrors/invalid_json2683--- PASS: TestSign (0.00s)2684--- PASS: TestSignErrors (0.00s)2685 --- PASS: TestSignErrors/no_prefix (0.00s)2686 --- PASS: TestSignErrors/http_error (0.00s)2687 --- PASS: TestSignErrors/invalid_base64 (0.00s)2688 --- PASS: TestSignErrors/invalid_json (0.00s)2689PASS