nixbot

builds

succeeded niks3-go-unit-tests checks.aarch64-linux.go-unit-tests · build #370 · 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 TestScriptTokenEmptyCommand101=== CONT TestDoWithRetry_BodyReplayedViaGetBody102=== CONT TestSetClientTLS103=== CONT TestClientSignaturesByStorePath104=== CONT TestFileTokenEmpty105=== CONT TestStreamPushReportsSignatures106=== CONT TestStreamPushRequestLine107=== CONT TestStreamPushGivesUpOnDeadServer108=== CONT TestStreamPushIsolatesFailures109=== CONT TestDumpPathWriterError1102026/10/06 10:46:34 ERROR Upload failed error="connection refused" count=201112026/10/06 10:46:34 ERROR Server seems unavailable, giving up on batch untried=17112=== CONT TestStreamPushBatchesUnderLoad113=== CONT TestStreamPushReportsEveryPath114=== CONT TestShellSplitErrors115=== CONT TestShellSplit116=== CONT TestSetClientTLSDoesNotMutateDefaultTransport117=== CONT TestParsePathInfoJSONMultiplePaths118=== CONT TestScriptTokenScriptFails119=== CONT TestResolveStorePath120=== CONT TestScriptTokenBadJSON121=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess122=== CONT TestScriptTokenEmptyToken1232026/10/06 10:46:34 ERROR Upload failed error=boom count=1124=== CONT TestRateLimiterFeedback125=== CONT TestFileTokenMissing126=== CONT TestScriptTokenCachesUntilRefresh127=== CONT TestDumpPathSingleFile128=== CONT TestPathInfoCACompatibility129=== CONT TestFileTokenReadsAndCaches130=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1312026/10/06 10:46:34 ERROR Upload failed error="bad path" count=3132=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1332026/10/06 10:46:34 ERROR Upload failed error=boom count=1134=== CONT TestDumpPathMatchesNix135=== CONT TestUploadMultipart_SupersededByPeer136--- PASS: TestScriptTokenEmptyCommand (0.00s)137--- PASS: TestClientSignaturesByStorePath (0.00s)138--- PASS: TestFileTokenEmpty (0.00s)139--- PASS: TestStreamPushReportsSignatures (0.00s)140--- PASS: TestShellSplitErrors (0.00s)141--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)142--- PASS: TestStreamPushReportsEveryPath (0.00s)143--- PASS: TestShellSplit (0.00s)144--- PASS: TestStreamPushIsolatesFailures (0.00s)145=== CONT TestUploadMultipart_PartsInParallel1462026/10/06 10:46:34 WARN Rate limiter enabled after throttle name=server-test rate=5147=== CONT TestScriptTokenNoExpiryRerunsEveryCall148=== CONT TestPartSizeForNAR149=== RUN TestPartSizeForNAR/zero_stays_at_minimum150=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum151=== RUN TestPartSizeForNAR/small_stays_at_minimum152=== PAUSE TestPartSizeForNAR/small_stays_at_minimum153=== CONT TestStaticToken154=== CONT TestCaseHackSuffix155=== RUN TestPathInfoCACompatibility/null_ca_field156=== PAUSE TestPathInfoCACompatibility/null_ca_field157=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158--- PASS: TestFileTokenReadsAndCaches (0.00s)159=== RUN TestRateLimiterFeedback/429_enables_limiter160=== RUN TestUploadMultipart_SupersededByPeer/exists161=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum162=== CONT TestSetClientTLSErrors163=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun164=== CONT TestPathInfoHashCompatibility165=== CONT TestParsePathInfoJSON166=== CONT TestGetStorePathHash167=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum168=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)169=== RUN TestSetClientTLS/rejects_connection_without_client_cert170=== RUN TestPathInfoCACompatibility/old_string_format_-_text171=== PAUSE TestRateLimiterFeedback/429_enables_limiter172=== RUN TestRateLimiterFeedback/503_enables_limiter173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text174=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert1752026/10/06 10:46:34 WARN Rate limiter enabled after throttle name=server-test rate=5176=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive177=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1782026/10/06 10:46:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38579179=== RUN TestPathInfoCACompatibility/new_structured_format_-_text180=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text181=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA183=== CONT TestFilterOversizedClosures184=== RUN TestFilterOversizedClosures/no_limit_keeps_everything185=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything186=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1872026/10/06 10:46:34 WARN Rate limiter backed off name=server-test rate=5188=== RUN TestParsePathInfoJSON/Nix_format1892026/10/06 10:46:34 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:38579190=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== RUN TestUploadMultipart_SupersededByPeer/missing193=== PAUSE TestUploadMultipart_SupersededByPeer/missing194=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts195=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts196=== RUN TestPartSizeForNAR/1_TiB197=== PAUSE TestPartSizeForNAR/1_TiB198=== RUN TestPartSizeForNAR/5_TiB_S3_max_object199=== CONT TestEncodeNixBase32WithRealHash200=== CONT TestRegisterUploadedObjectReusesConnections2012026/10/06 10:46:34 INFO Garbage collection started202=== PAUSE TestRateLimiterFeedback/503_enables_limiter203=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter204=== CONT TestEncodeNixBase32205=== RUN TestEncodeNixBase32/test_string_hash206=== PAUSE TestEncodeNixBase32/test_string_hash207=== RUN TestEncodeNixBase32/empty_input208=== PAUSE TestEncodeNixBase32/empty_input209--- PASS: TestScriptTokenScriptFails (0.00s)210--- PASS: TestScriptTokenBadJSON (0.01s)211--- PASS: TestFileTokenMissing (0.00s)212--- PASS: TestScriptTokenEmptyToken (0.00s)213--- PASS: TestResolveStorePath (0.00s)214--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)215--- PASS: TestStaticToken (0.00s)216--- PASS: TestDoServerRequestAttachesToken (0.04s)217=== CONT TestUploadMultipart_SupersededByPeer/exists2182026/10/06 10:46:34 INFO Garbage collection started219=== RUN TestGetStorePathHash/valid_store_path220=== PAUSE TestGetStorePathHash/valid_store_path221=== RUN TestGetStorePathHash/basename_without_hyphen_should_error222=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error223=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error224=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error225=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error226=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error227--- PASS: TestEncodeNixBase32WithRealHash (0.00s)228--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)229--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)230--- PASS: TestDumpPathSingleFile (0.03s)231=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== CONT TestUploadMultipart_SupersededByPeer/missing233--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)234=== CONT TestEncodeNixBase32/empty_input235=== CONT TestGetStorePathHash/valid_store_path236=== CONT TestPathInfoCACompatibility/null_ca_field237=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA238=== RUN TestSetClientTLS/preserves_debug_logging_transport239=== PAUSE TestSetClientTLS/preserves_debug_logging_transport240=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error242=== CONT TestGetStorePathHash/basename_without_hyphen_should_error243=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped244=== RUN TestFilterOversizedClosures/all_closures_skipped245=== PAUSE TestFilterOversizedClosures/all_closures_skipped246=== CONT TestPathInfoCACompatibility/new_structured_format_-_text247=== CONT TestPathInfoCACompatibility/old_string_format_-_text248=== PAUSE TestParsePathInfoJSON/Nix_format249=== RUN TestParsePathInfoJSON/Lix_format250=== PAUSE TestParsePathInfoJSON/Lix_format251=== RUN TestParsePathInfoJSON/empty_input252=== PAUSE TestParsePathInfoJSON/empty_input253=== RUN TestParsePathInfoJSON/whitespace_only254=== PAUSE TestParsePathInfoJSON/whitespace_only255=== RUN TestParsePathInfoJSON/invalid_JSON256=== PAUSE TestParsePathInfoJSON/invalid_JSON257=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method258=== CONT TestSetClientTLS/preserves_debug_logging_transport259=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA260=== CONT TestSetClientTLS/rejects_connection_without_client_cert2612026/10/06 10:46:34 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=0262--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)263 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)264 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)265=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive266--- PASS: TestPathInfoCACompatibility (0.04s)267 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)268 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)269 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)270 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)271 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)272=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)273=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon274=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon275=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI276=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI277=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512278=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512279=== CONT TestParsePathInfoJSON/Nix_format280=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object281=== RUN TestPartSizeForNAR/capped_at_5_GiB282=== PAUSE TestPartSizeForNAR/capped_at_5_GiB283=== CONT TestParsePathInfoJSON/whitespace_only284=== CONT TestParsePathInfoJSON/invalid_JSON285=== CONT TestParsePathInfoJSON/Lix_format286=== CONT TestFilterOversizedClosures/all_closures_skipped287=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2882026/10/06 10:46:34 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=50289=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2902026/10/06 10:46:34 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=2000291=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter292=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter293=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter294=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI295--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)296=== CONT TestPartSizeForNAR/capped_at_5_GiB297=== CONT TestPartSizeForNAR/5_TiB_S3_max_object298=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts299=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum300=== CONT TestPartSizeForNAR/small_stays_at_minimum301=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon302=== CONT TestRateLimiterFeedback/429_enables_limiter303=== CONT TestPartSizeForNAR/zero_stays_at_minimum304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter305=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths3062026/10/06 10:46:34 WARN Garbage collection finished on another replica. Its statistics are not available here307--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)308 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)309 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)310=== CONT TestPartSizeForNAR/1_TiB311--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)312=== CONT TestEncodeNixBase32/test_string_hash313=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error314=== CONT TestConvertHashToNix32315=== CONT TestFilterOversizedClosures/no_limit_keeps_everything316=== CONT TestParsePathInfoJSON/empty_input317=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512318=== CONT TestRateLimiterFeedback/503_enables_limiter319--- PASS: TestPartSizeForNAR (0.03s)320 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)321 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)322 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)323 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)324 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)325 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)326 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)3272026/10/06 10:46:34 WARN Rate limiter enabled after throttle name=server-test rate=5328=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)3292026/10/06 10:46:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:35697330--- PASS: TestParsePathInfoJSON (0.00s)331 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)334 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)335 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)336--- PASS: TestEncodeNixBase32 (0.00s)337 --- PASS: TestEncodeNixBase32/empty_input (0.00s)338 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)339=== RUN TestConvertHashToNix32/SRI_format_to_Nix32340=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32341=== RUN TestConvertHashToNix32/already_Nix32_format342=== PAUSE TestConvertHashToNix32/already_Nix32_format343=== RUN TestConvertHashToNix32/invalid_format344=== PAUSE TestConvertHashToNix32/invalid_format345=== CONT TestConvertHashToNix32/SRI_format_to_Nix323462026/10/06 10:46:34 WARN Rate limiter backed off name=server-test rate=5347--- PASS: TestPathInfoHashCompatibility (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)349 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)350 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)351 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)352--- PASS: TestFilterOversizedClosures (0.00s)353 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)354 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)355 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)356=== RUN TestSetClientTLSErrors/missing_cert_file357=== PAUSE TestSetClientTLSErrors/missing_cert_file358=== RUN TestSetClientTLSErrors/missing_key_file359=== PAUSE TestSetClientTLSErrors/missing_key_file360=== RUN TestSetClientTLSErrors/missing_ca_file361=== PAUSE TestSetClientTLSErrors/missing_ca_file362=== RUN TestSetClientTLSErrors/invalid_ca_file363=== PAUSE TestSetClientTLSErrors/invalid_ca_file364=== CONT TestSetClientTLSErrors/missing_cert_file3652026/10/06 10:46:34 WARN Rate limiter enabled after throttle name=server-test rate=5366=== CONT TestConvertHashToNix32/invalid_format3672026/10/06 10:46:34 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:36483368=== CONT TestConvertHashToNix32/already_Nix32_format369--- PASS: TestConvertHashToNix32 (0.00s)370 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)371 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)372 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)373--- PASS: TestGetStorePathHash (0.00s)374 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)376 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)377 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)378=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter379=== CONT TestSetClientTLSErrors/missing_ca_file3802026/10/06 10:46:34 WARN Rate limiter backed off name=server-test rate=5381=== CONT TestSetClientTLSErrors/invalid_ca_file382=== CONT TestSetClientTLSErrors/missing_key_file383--- PASS: TestRateLimiterFeedback (0.03s)384 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)385 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)387 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)388--- PASS: TestSetClientTLSErrors (0.01s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)392 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)393--- PASS: TestStreamPushRequestLine (0.06s)3942026/10/06 10:46:34 http: TLS handshake error from 127.0.0.1:40808: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.04s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)400--- PASS: TestDumpPathWriterError (0.07s)401--- PASS: TestCaseHackSuffix (0.03s)402--- PASS: TestDumpPathMatchesNix (0.10s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)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/postgres3721161672/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/postgres3721161672/data -l logfile start434435/build/postgres3721161672:5432 - no response4362026-10-06 10:46:36.001 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-06 10:46:36.001 UTC [129] LOG: listening on Unix socket "/build/postgres3721161672/.s.PGSQL.5432"4382026-10-06 10:46:36.005 UTC [136] LOG: database system was shut down at 2026-10-06 10:46:35 UTC4392026-10-06 10:46:36.009 UTC [129] LOG: database system is ready to accept connections440/build/postgres3721161672:5432 - accepting connections441{"timestamp":"2026-10-06T10:46:36.199799111Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"37f5c223-2cfc-439e-b6b6-6683b7c526c1","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(200)"}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 TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 10:46:36 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:46:37 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:46:37 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:46:38 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.87s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:46:38 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:46:39.672 UTC [380] FATAL: terminating connection due to administrator command4992026/10/06 10:46:39 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:46:40 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:46:40 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:46:41 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (3.09s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:46:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle693=== CONT TestPush_SignsNarinfosOfItsPendingObjects694=== CONT TestService_verifyS3Integrity695=== CONT TestService_AuthMiddleware696=== CONT TestService_cleanupPendingClosuresHandler697=== CONT TestIsValidUploadKey698=== RUN TestIsValidUploadKey/narinfo699=== PAUSE TestIsValidUploadKey/narinfo700=== RUN TestIsValidUploadKey/nar_zst701=== CONT TestSkippedUploadsHandler702=== CONT TestParseSize703--- PASS: TestParseSize (0.00s)704=== CONT TestService_Rustfstest705=== CONT TestPresignedUploadRegisteredBeforeCommit7062026/10/06 10:46:41 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000707=== CONT TestCompletedNarNotReofferedAcrossClosures708=== CONT TestCompleteMultipartUpload_ErrorButObjectExists709=== CONT TestRedundantMultipartUpload710=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT711=== CONT TestCompleteMultipartUnregistered712=== CONT TestUploadHandlersRejectOversizedBody713=== CONT TestUploadHandlersRejectInvalidKeys714=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info715=== CONT TestGCTaskStore_GetReturnsLatest716=== CONT TestPush_RejectsBadRequests717=== CONT TestOrphanedObjectsGC718=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit719=== CONT TestPush_CompleteCommitsEveryRoot720=== CONT TestPush_OverlappingRootsStoreOneRowPerKey721=== CONT TestReadRedirectUsesPublicS3URL722=== CONT TestReadProxyRangeRequest723=== PAUSE TestIsValidUploadKey/nar_zst724=== CONT TestReadRedirectKeepsNarinfoProxied725=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info726=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal727=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal728=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key729=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key730=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key731=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key732=== CONT TestObjectStatsTrigger733--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)734=== RUN TestIsValidUploadKey/nar_xz735=== PAUSE TestIsValidUploadKey/nar_xz736=== RUN TestIsValidUploadKey/nar_plain737=== PAUSE TestIsValidUploadKey/nar_plain738=== RUN TestIsValidUploadKey/listing739=== PAUSE TestIsValidUploadKey/listing740=== RUN TestIsValidUploadKey/build_log741=== PAUSE TestIsValidUploadKey/build_log742=== RUN TestIsValidUploadKey/build_log_home-manager_file743=== PAUSE TestIsValidUploadKey/build_log_home-manager_file744=== RUN TestIsValidUploadKey/build_log_plus_in_name745=== PAUSE TestIsValidUploadKey/build_log_plus_in_name746=== RUN TestIsValidUploadKey/build_log_question_mark747=== PAUSE TestIsValidUploadKey/build_log_question_mark748=== RUN TestIsValidUploadKey/build_log_equals749--- PASS: TestSkippedUploadsHandler (0.02s)750=== CONT TestPendingCleanupUsesOneCutoff751=== PAUSE TestIsValidUploadKey/build_log_equals752=== RUN TestIsValidUploadKey/realisation753=== PAUSE TestIsValidUploadKey/realisation754=== RUN TestIsValidUploadKey/realisation_plus_in_output755=== PAUSE TestIsValidUploadKey/realisation_plus_in_output756=== RUN TestIsValidUploadKey/nix-cache-info757=== PAUSE TestIsValidUploadKey/nix-cache-info758=== RUN TestIsValidUploadKey/index.html759=== PAUSE TestIsValidUploadKey/index.html760=== RUN TestIsValidUploadKey/narinfo_key,_nar_type761=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type762=== RUN TestIsValidUploadKey/nar_key,_narinfo_type763=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type764=== RUN TestIsValidUploadKey/listing_key,_narinfo_type765=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type766=== RUN TestIsValidUploadKey/traversal767=== PAUSE TestIsValidUploadKey/traversal768=== RUN TestIsValidUploadKey/traversal_nar769=== PAUSE TestIsValidUploadKey/traversal_nar770=== RUN TestIsValidUploadKey/absolute771=== PAUSE TestIsValidUploadKey/absolute772=== RUN TestIsValidUploadKey/empty_key773=== PAUSE TestIsValidUploadKey/empty_key774=== RUN TestIsValidUploadKey/unknown_type775=== PAUSE TestIsValidUploadKey/unknown_type776=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded777=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure778=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure779=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart780=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart781=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts782=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts783=== CONT TestMultipartCleanup7842026/10/06 10:46:41 INFO Received push request method=POST path=/api/pushes7852026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7862026/10/06 10:46:41 INFO Signed narinfos id=1 count=17872026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7882026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7892026/10/06 10:46:41 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"7902026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7912026/10/06 10:46:41 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"7922026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7932026/10/06 10:46:41 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=17942026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7952026/10/06 10:46:41 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo796--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.26s)797=== CONT TestServerTLSConfig798=== RUN TestServerTLSConfig/no_client_CA799=== PAUSE TestServerTLSConfig/no_client_CA800=== RUN TestServerTLSConfig/missing_CA_file801=== PAUSE TestServerTLSConfig/missing_CA_file802=== RUN TestServerTLSConfig/not_a_PEM_file803=== PAUSE TestServerTLSConfig/not_a_PEM_file804=== CONT TestService_NativeMTLS8052026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8062026/10/06 10:46:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"807--- PASS: TestService_AuthMiddleware (0.28s)808=== CONT TestOrphanedObjectsGCStressTest8092026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures810--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.31s)811=== CONT TestMetricsInventory8122026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8132026/10/06 10:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures8142026/10/06 10:46:41 INFO Aborted multipart uploads count=0 kept=08152026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8162026/10/06 10:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures8172026/10/06 10:46:41 INFO Aborted multipart uploads count=1 kept=0818--- PASS: TestService_Rustfstest (0.35s)819=== CONT TestReadRedirectNar8202026/10/06 10:46:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8212026-10-06 10:46:41.851 UTC [453] ERROR: Closure does not exist: id=18222026-10-06 10:46:41.851 UTC [453] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8232026-10-06 10:46:41.851 UTC [453] STATEMENT: -- name: CommitPendingClosure :exec824 SELECT commit_pending_closure($1::bigint)825 826--- PASS: TestService_cleanupPendingClosuresHandler (0.35s)827=== CONT TestNARDeduplicationMetadataUploadBug8282026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8292026/10/06 10:46:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8302026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/06 10:46:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8322026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures833--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.40s)834=== CONT TestReadProxyDisabled8352026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8362026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8372026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8382026/10/06 10:46:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8392026/10/06 10:46:41 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LjJiODdiN2Y2LWNjMzEtNGZiYy1iM2E0LTBiOTkwNzZjMDVmYXgxNzkxMjgzNjAxOTE0NzUxOTM48402026/10/06 10:46:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LjJiODdiN2Y2LWNjMzEtNGZiYy1iM2E0LTBiOTkwNzZjMDVmYXgxNzkxMjgzNjAxOTE0NzUxOTM4 parts=1841--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.45s)842=== CONT TestCreatePendingClosureRejectsOversizedNAR8432026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures844--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)845=== CONT TestReadProxyRootRedirectsToIndexHTML8462026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures847--- PASS: TestReadRedirectUsesPublicS3URL (0.47s)848=== CONT TestCacheConfigHandlerMaxNarSize849--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)850=== CONT TestReadProxyConditionalGet8512026/10/06 10:46:41 INFO Received uploads request method=POST path=/api/pending_closures8522026/10/06 10:46:41 INFO Received cleanup request method=DELETE path=/api/pending_closures853--- PASS: TestReadRedirectKeepsNarinfoProxied (0.50s)854=== CONT TestGenerateLandingPage855--- PASS: TestGenerateLandingPage (0.00s)856=== CONT TestReadProxyOutlastsServerWriteTimeout8572026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures858--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.47s)859=== CONT TestService_readinessHandler8602026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes8612026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete862=== RUN TestPush_RejectsBadRequests/no_roots863=== PAUSE TestPush_RejectsBadRequests/no_roots864=== RUN TestPush_RejectsBadRequests/no_objects865=== PAUSE TestPush_RejectsBadRequests/no_objects866=== RUN TestPush_RejectsBadRequests/bad_root867=== PAUSE TestPush_RejectsBadRequests/bad_root868=== RUN TestPush_RejectsBadRequests/root_not_in_objects869=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects870=== CONT TestReadProxyHead871--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.55s)872=== CONT TestService_healthCheckHandler8732026/10/06 10:46:42 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LmNkZjIxNWNmLWE0ZDAtNDkzOS04NzFjLWZhNGY1MjFiYTIwY3gxNzkxMjgzNjAxNzcwMjE1ODc2 parts=108742026/10/06 10:46:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8752026/10/06 10:46:42 INFO Completed upload id=18762026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures8772026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures8782026/10/06 10:46:42 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8792026/10/06 10:46:42 WARN Found objects in DB but missing from S3, will re-upload count=1880--- PASS: TestService_verifyS3Integrity (0.58s)881=== CONT TestReadProxyInvalidPath8822026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8832026/10/06 10:46:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst884--- PASS: TestCompleteMultipartUnregistered (0.58s)885=== CONT TestGracefulShutdownDrainsInflight8862026/10/06 10:46:42 INFO Starting HTTP server address=127.0.0.1:454958872026/10/06 10:46:42 INFO Shutdown signal received, draining in-flight requests timeout=10s888--- PASS: TestObjectStatsTrigger (0.63s)889=== CONT TestReadProxy404890--- PASS: TestReadProxyRangeRequest (0.64s)891=== CONT TestGCTaskStore_Fail892--- PASS: TestGCTaskStore_Fail (0.00s)893=== CONT TestReadProxyNarStreaming894--- PASS: TestGracefulShutdownDrainsInflight (0.07s)895=== CONT TestGCTaskStore_PhaseUpdates896--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)897=== CONT TestReadProxyContentNegotiation8982026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes8992026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete9002026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes9012026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes9022026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete9032026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures904--- PASS: TestPush_CompleteCommitsEveryRoot (0.71s)905=== CONT TestGCTaskStore_CompletedAllowsNewTask906--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)907=== CONT TestReadProxyNarinfoAlreadyDecompressed9082026/10/06 10:46:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9092026/10/06 10:46:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"910--- PASS: TestService_NativeMTLS (0.47s)911=== CONT TestReadProxyNarinfo9122026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9132026/10/06 10:46:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LjEyYWEyMWEzLTU0OWItNGQ1YS1hZTU1LWRiZWVkMmRmMzY4Y3gxNzkxMjgzNjAxODcyNTg2NDY0 parts=129142026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures915=== NAME TestOrphanedObjectsGC916 orphaned_objects_gc_test.go:290: GC Test Summary:917 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A918 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B919 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)920 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)921 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects922--- PASS: TestOrphanedObjectsGC (0.74s)923=== CONT TestParseSingleRange924=== RUN TestParseSingleRange/none925=== PAUSE TestParseSingleRange/none926=== RUN TestParseSingleRange/unknown_unit927=== PAUSE TestParseSingleRange/unknown_unit928=== RUN TestParseSingleRange/multi-range_ignored929=== PAUSE TestParseSingleRange/multi-range_ignored930=== RUN TestParseSingleRange/malformed_no_dash931=== PAUSE TestParseSingleRange/malformed_no_dash932=== RUN TestParseSingleRange/malformed_both_empty933=== PAUSE TestParseSingleRange/malformed_both_empty934=== RUN TestParseSingleRange/malformed_end_before_start935=== PAUSE TestParseSingleRange/malformed_end_before_start936=== RUN TestParseSingleRange/closed937=== PAUSE TestParseSingleRange/closed938=== RUN TestParseSingleRange/open-ended939=== PAUSE TestParseSingleRange/open-ended940=== RUN TestParseSingleRange/end_clamped_to_size941=== PAUSE TestParseSingleRange/end_clamped_to_size942=== RUN TestParseSingleRange/suffix943=== PAUSE TestParseSingleRange/suffix944=== RUN TestParseSingleRange/suffix_exceeds_size945=== PAUSE TestParseSingleRange/suffix_exceeds_size946=== RUN TestParseSingleRange/single_byte947=== PAUSE TestParseSingleRange/single_byte948=== RUN TestParseSingleRange/start_past_EOF949=== PAUSE TestParseSingleRange/start_past_EOF950=== RUN TestParseSingleRange/start_far_past_EOF951=== PAUSE TestParseSingleRange/start_far_past_EOF952=== CONT TestPresentNotReportedWhileGCDeletesClosure953--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.75s)9542026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=0955=== CONT TestIsValidCachePath956=== RUN TestIsValidCachePath/narinfo957=== PAUSE TestIsValidCachePath/narinfo958=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars959=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars960=== RUN TestIsValidCachePath/nar_zst961=== PAUSE TestIsValidCachePath/nar_zst962=== RUN TestIsValidCachePath/nar_xz963=== PAUSE TestIsValidCachePath/nar_xz964=== RUN TestIsValidCachePath/nar_bz2965=== PAUSE TestIsValidCachePath/nar_bz2966=== RUN TestIsValidCachePath/nar_uncompressed967=== PAUSE TestIsValidCachePath/nar_uncompressed968=== RUN TestIsValidCachePath/ls969=== PAUSE TestIsValidCachePath/ls970=== RUN TestIsValidCachePath/log971=== PAUSE TestIsValidCachePath/log972=== RUN TestIsValidCachePath/realisation973=== PAUSE TestIsValidCachePath/realisation974=== RUN TestIsValidCachePath/nix-cache-info975=== PAUSE TestIsValidCachePath/nix-cache-info976=== RUN TestIsValidCachePath/index.html977=== PAUSE TestIsValidCachePath/index.html978=== RUN TestIsValidCachePath/traversal_parent979=== PAUSE TestIsValidCachePath/traversal_parent980=== RUN TestIsValidCachePath/traversal_in_middle981=== PAUSE TestIsValidCachePath/traversal_in_middle982=== RUN TestIsValidCachePath/invalid_char_e983=== PAUSE TestIsValidCachePath/invalid_char_e984=== RUN TestIsValidCachePath/invalid_char_u985=== PAUSE TestIsValidCachePath/invalid_char_u986=== RUN TestIsValidCachePath/random_path987=== PAUSE TestIsValidCachePath/random_path988=== RUN TestIsValidCachePath/empty989=== PAUSE TestIsValidCachePath/empty990=== RUN TestIsValidCachePath/leading_slash991=== PAUSE TestIsValidCachePath/leading_slash992=== RUN TestIsValidCachePath/wrong_extension993=== PAUSE TestIsValidCachePath/wrong_extension994=== RUN TestIsValidCachePath/short_hash995=== PAUSE TestIsValidCachePath/short_hash996=== CONT TestPresentReportsOnlyClosureRoots9972026/10/06 10:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period9982026/10/06 10:46:42 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=09992026/10/06 10:46:42 INFO Vacuumed table table=pending_closures10002026/10/06 10:46:42 INFO Vacuumed table table=pending_objects10012026/10/06 10:46:42 INFO Vacuumed table table=multipart_uploads10022026/10/06 10:46:42 INFO Vacuumed table table=closures10032026/10/06 10:46:42 INFO Vacuumed table table=objects10042026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/2/complete1005--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.78s)1006=== CONT TestProxyHeadersOnlyTrustedOnSocket10072026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1008--- PASS: TestMetricsInventory (0.47s)1009=== CONT TestCreatePin_ReservedPins1010--- PASS: TestReadRedirectNar (0.45s)1011=== CONT TestPendingClosureWriteTimeout1012=== RUN TestPendingClosureWriteTimeout/empty1013=== PAUSE TestPendingClosureWriteTimeout/empty1014=== RUN TestPendingClosureWriteTimeout/400_objects1015=== PAUSE TestPendingClosureWriteTimeout/400_objects1016=== RUN TestPendingClosureWriteTimeout/670k_objects1017=== PAUSE TestPendingClosureWriteTimeout/670k_objects1018=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1019=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1020=== CONT TestProxyWriteTimeout1021=== RUN TestProxyWriteTimeout/narinfo1022=== PAUSE TestProxyWriteTimeout/narinfo1023=== RUN TestProxyWriteTimeout/1_GiB_nar1024=== PAUSE TestProxyWriteTimeout/1_GiB_nar1025=== RUN TestProxyWriteTimeout/10_GiB_nar1026=== PAUSE TestProxyWriteTimeout/10_GiB_nar1027=== RUN TestProxyWriteTimeout/unknown_size1028=== PAUSE TestProxyWriteTimeout/unknown_size1029=== CONT TestLeadEndsOnShutdown10302026/10/06 10:46:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5Ljg0MzBmZTc5LWVkNzAtNDQ4OS1hNTMzLTBiNTk0MDU5MjgzNngxNzkxMjgzNjAxOTI3NzQzNjE0 parts=1210312026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 10:46:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10342026/10/06 10:46:42 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10352026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=110362026/10/06 10:46:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10372026/10/06 10:46:42 INFO Aborted multipart uploads count=1 kept=01038--- PASS: TestReadProxyDisabled (0.43s)1039=== CONT TestService_createPendingClosureHandler1040--- PASS: TestMultipartCleanup (0.68s)1041=== CONT TestGCTaskStore_GetEmpty1042--- PASS: TestGCTaskStore_GetEmpty (0.00s)1043=== CONT TestClientMultipleUploads1044=== NAME TestNARDeduplicationMetadataUploadBug1045 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2498715721/001/store/k8svpmr6w5hqlga0v4dpm76f2v6kzhsb-file1.txt1046--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.41s)1047=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1048--- PASS: TestReadProxyConditionalGet (0.41s)1049=== CONT TestGCTaskStore_ConflictDifferentParams1050--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1051=== CONT TestClientFallsBackToClosures10522026/10/06 10:46:42 WARN readiness check failed error="closed pool"1053--- PASS: TestService_readinessHandler (0.38s)1054=== CONT TestLeadIncumbentAnnouncesAtOnce10552026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes10562026/10/06 10:46:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10572026/10/06 10:46:42 INFO Uploading k8svpmr6w5hqlga0v4dpm76f2v6kzhsb-file1.txt (160B)1058--- PASS: TestService_healthCheckHandler (0.37s)1059=== CONT TestGCTaskStore_DeduplicateSameParams1060--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1061=== CONT TestClientPushesUseOnePush10622026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10632026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10642026/10/06 10:46:42 WARN Failed to register uploaded object key=k8svpmr6w5hqlga0v4dpm76f2v6kzhsb.ls error="server returned 404: 404 page not found\n"10652026/10/06 10:46:42 INFO Signed narinfos id=1 count=110662026/10/06 10:46:42 INFO Uploading 1 narinfos10672026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete10682026/10/06 10:46:42 WARN Failed to register uploaded object key=k8svpmr6w5hqlga0v4dpm76f2v6kzhsb.narinfo error="server returned 404: 404 page not found\n"10692026/10/06 10:46:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44779/oidc10702026/10/06 10:46:42 INFO Upload complete. (65ms)1071=== NAME TestNARDeduplicationMetadataUploadBug1072 metadata_upload_test.go:54: Retrieved narinfo from S3:1073 StorePath: /build/TestNARDeduplicationMetadataUploadBug2498715721/001/store/k8svpmr6w5hqlga0v4dpm76f2v6kzhsb-file1.txt1074 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1075 Compression: zstd1076 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1077 NarSize: 1601078 References: 1079 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1080 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1081 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1082 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1083--- PASS: TestReadProxyHead (0.40s)1084=== CONT TestGCTaskStore_StartNew1085--- PASS: TestGCTaskStore_StartNew (0.00s)1086=== CONT TestLeadElectsOneAndHandsOver1087--- PASS: TestReadProxyInvalidPath (0.39s)1088=== CONT TestPinProtectsFromGC1089=== NAME TestNARDeduplicationMetadataUploadBug1090 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2498715721/001/store/x6i5f09nprl3nf496q1ygda8aawm3x1m-file2.txt1091--- PASS: TestReadProxy404 (0.38s)1092=== CONT TestConnectWaitsForAPeerMigration1093--- PASS: TestReadProxyNarStreaming (0.37s)1094=== CONT TestClientSharedPathCommittedMidPush10952026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes10962026/10/06 10:46:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1097--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.35s)1098=== CONT TestGCEndsOnShutdown1099=== RUN TestGCEndsOnShutdown/before_the_run1100=== PAUSE TestGCEndsOnShutdown/before_the_run1101=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1102=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1103=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1104=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1105=== CONT TestResolveDBConnectionString1106=== RUN TestResolveDBConnectionString/flag_wins1107=== PAUSE TestResolveDBConnectionString/flag_wins1108=== RUN TestResolveDBConnectionString/file_when_flag_empty1109=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1110=== RUN TestResolveDBConnectionString/missing_file_is_an_error1111=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1112=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1113=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1114=== RUN TestResolveDBConnectionString/nothing_configured1115=== PAUSE TestResolveDBConnectionString/nothing_configured1116=== CONT TestClientWithDependencies11172026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11182026/10/06 10:46:42 INFO Signed narinfos id=2 count=111192026/10/06 10:46:42 WARN Failed to register uploaded object key=x6i5f09nprl3nf496q1ygda8aawm3x1m.ls error="server returned 404: 404 page not found\n"11202026/10/06 10:46:42 INFO Uploading 1 narinfos11212026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/2/complete11222026/10/06 10:46:42 WARN Failed to register uploaded object key=x6i5f09nprl3nf496q1ygda8aawm3x1m.narinfo error="server returned 404: 404 page not found\n"11232026/10/06 10:46:42 INFO Upload complete. (51ms)1124=== NAME TestNARDeduplicationMetadataUploadBug1125 metadata_upload_test.go:76: Retrieved narinfo from S3:1126 StorePath: /build/TestNARDeduplicationMetadataUploadBug2498715721/001/store/x6i5f09nprl3nf496q1ygda8aawm3x1m-file2.txt1127 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1128 Compression: zstd1129 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1130 NarSize: 1601131 References: 1132 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1133 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1134 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1135 {"version":1,"root":{"type":"regular","size":44}}1136--- PASS: TestNARDeduplicationMetadataUploadBug (0.73s)1137=== CONT TestCommitRacingPendingCleanupKeepsObjects1138--- PASS: TestReadProxyContentNegotiation (0.43s)1139=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1140--- PASS: TestPresentReportsOnlyClosureRoots (0.38s)1141=== CONT TestGCSweepDeliversEachKeyOnce11422026/10/06 10:46:42 INFO Starting HTTP server address=127.0.0.1:3891711432026/10/06 10:46:42 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3820656413/001/proxy.sock11442026/10/06 10:46:42 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11452026/10/06 10:46:42 INFO Shutdown signal received, draining in-flight requests timeout=10s1146--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.36s)1147=== CONT TestRegisterCompletedObjectNeedsPendingRow11482026/10/06 10:46:42 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1149--- PASS: TestReadProxyNarinfo (0.43s)1150=== CONT TestSweepSkipsRowsLockedByPush11512026/10/06 10:46:42 INFO lead: acquired remote=192.0.2.1:123411522026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11532026/10/06 10:46:42 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LjY0YTNjZDdkLTM5NzQtNDhiNy05NjhmLTIxMjJhYTA1Y2FhM3gxNzkxMjgzNjAyMzE0NTgzMTY1 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11542026/10/06 10:46:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LjYwMjIzZTNjLTdlNjktNDM5MC05OTk5LWQzZDk4YjlkMmQxOXgxNzkxMjgzNjAyMzA4MTc0OTQ4 parts=1211552026/10/06 10:46:42 INFO Received cleanup request method=DELETE path=/api/pending_closures11562026/10/06 10:46:42 INFO Aborted multipart uploads count=1 kept=011572026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestRedundantMultipartUpload (1.20s)1159=== CONT TestTombstonedObjectOfferedWithoutWaiting11602026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures1162=== NAME TestClientMultipleUploads1163 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads392206746/001/store/b81pwl1pnhqhh1c54aafsgkrvppy9nih-test-file-0.txt1164 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads392206746/001/store/nw35hancbx1r97viysa4ccknxzyz626r-test-file-1.txt11652026/10/06 10:46:42 INFO lead: acquired remote=192.0.2.1:123411662026/10/06 10:46:42 INFO lead: released remote=192.0.2.1:12341167--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.35s)1168=== CONT TestPushWaitsForSweepHoldingRow1169=== NAME TestClientMultipleUploads1170 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads392206746/001/store/q9qakdm82hv9cw6ksgkrza15lxnc5725-test-file-2.txt11712026/10/06 10:46:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11722026/10/06 10:46:42 WARN Refused reserved pin name=worker-x86_64-linux11732026/10/06 10:46:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11742026/10/06 10:46:42 INFO Received create pin request method=POST path=/api/pins/my-app11752026/10/06 10:46:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1176--- PASS: TestCreatePin_ReservedPins (0.52s)1177=== CONT TestFailedS3DeleteKeepsTombstone11782026/10/06 10:46:42 INFO lead: acquired remote=192.0.2.1:123411792026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes11802026/10/06 10:46:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11812026/10/06 10:46:42 INFO Uploading nw35hancbx1r97viysa4ccknxzyz626r-test-file-1.txt (160B)11822026/10/06 10:46:42 INFO Uploading b81pwl1pnhqhh1c54aafsgkrvppy9nih-test-file-0.txt (160B)11832026/10/06 10:46:42 INFO Uploading q9qakdm82hv9cw6ksgkrza15lxnc5725-test-file-2.txt (160B)11842026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11852026/10/06 10:46:42 WARN Failed to register uploaded object key=b81pwl1pnhqhh1c54aafsgkrvppy9nih.ls error="server returned 404: 404 page not found\n"11862026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11872026/10/06 10:46:42 WARN Failed to register uploaded object key=q9qakdm82hv9cw6ksgkrza15lxnc5725.ls error="server returned 404: 404 page not found\n"11882026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11892026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11902026/10/06 10:46:42 WARN Failed to register uploaded object key=nw35hancbx1r97viysa4ccknxzyz626r.ls error="server returned 404: 404 page not found\n"11912026/10/06 10:46:42 INFO Signed narinfos id=1 count=311922026/10/06 10:46:42 INFO Uploading 3 narinfos11932026/10/06 10:46:42 WARN Failed to register uploaded object key=q9qakdm82hv9cw6ksgkrza15lxnc5725.narinfo error="server returned 404: 404 page not found\n"11942026/10/06 10:46:42 WARN Failed to register uploaded object key=nw35hancbx1r97viysa4ccknxzyz626r.narinfo error="server returned 404: 404 page not found\n"11952026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete11962026/10/06 10:46:42 WARN Failed to register uploaded object key=b81pwl1pnhqhh1c54aafsgkrvppy9nih.narinfo error="server returned 404: 404 page not found\n"11972026/10/06 10:46:42 INFO Upload complete. (57ms)1198=== NAME TestClientMultipleUploads1199 client_integration_test.go:369: Uploaded 3 paths in 89.801976ms1200--- PASS: TestClientMultipleUploads (0.56s)1201=== CONT TestGCSweepSkipsPendingObjects1202=== NAME TestPinProtectsFromGC1203 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1206964221/001/store/6k4pd6h6q49c14pjnms5im96lzq0py7f-pinned-file.txt1204 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1206964221/001/store/idf7s3dxc2572sr91ixqn2w0s5s5bli6-unpinned-file.txt12052026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/06 10:46:42 INFO Received uploads request method=POST path=/api/pending_closures12082026/10/06 10:46:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12092026/10/06 10:46:42 INFO Uploading zidsplq6r10kd5r0rhqfcl2k703ny9rw-b (216B)12102026/10/06 10:46:42 INFO Uploading ik7yq9ah15vng0rqbpzkwg5xy746c8k6-shared-dep (136B)12112026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/0kfdwkdmxng2754m37g2ds91bn2hfn7376495x2h12mj9nvv2fsp.nar.zst error="server returned 404: 404 page not found\n"12122026/10/06 10:46:42 WARN Failed to register uploaded object key=x5vrdkgfxnsf04shcv5404hc5nf65xka.ls error="server returned 404: 404 page not found\n"12132026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=012142026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12152026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12162026/10/06 10:46:42 WARN Failed to register uploaded object key=zidsplq6r10kd5r0rhqfcl2k703ny9rw.ls error="server returned 404: 404 page not found\n"12172026/10/06 10:46:42 WARN Failed to register uploaded object key=ik7yq9ah15vng0rqbpzkwg5xy746c8k6.ls error="server returned 404: 404 page not found\n"12182026/10/06 10:46:42 INFO Signed narinfos id=2 count=212192026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12202026/10/06 10:46:42 INFO Signed narinfos id=1 count=212212026/10/06 10:46:42 INFO Uploading 4 narinfos12222026/10/06 10:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period12232026/10/06 10:46:42 WARN Failed to register uploaded object key=x5vrdkgfxnsf04shcv5404hc5nf65xka.narinfo error="server returned 404: 404 page not found\n"12242026/10/06 10:46:42 WARN Failed to register uploaded object key=zidsplq6r10kd5r0rhqfcl2k703ny9rw.narinfo error="server returned 404: 404 page not found\n"12252026/10/06 10:46:42 WARN Failed to register uploaded object key=ik7yq9ah15vng0rqbpzkwg5xy746c8k6.narinfo error="server returned 404: 404 page not found\n"12262026/10/06 10:46:42 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=012272026/10/06 10:46:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12282026/10/06 10:46:42 WARN Failed to register uploaded object key=ik7yq9ah15vng0rqbpzkwg5xy746c8k6.narinfo error="server returned 404: 404 page not found\n"12292026/10/06 10:46:42 INFO Vacuumed table table=pending_closures12302026/10/06 10:46:42 INFO Vacuumed table table=pending_objects12312026/10/06 10:46:42 INFO Vacuumed table table=multipart_uploads12322026/10/06 10:46:42 INFO Completed upload id=212332026/10/06 10:46:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12342026/10/06 10:46:42 INFO Completed upload id=112352026/10/06 10:46:42 INFO Vacuumed table table=closures12362026/10/06 10:46:42 INFO Upload complete. (64ms)12372026/10/06 10:46:42 INFO Vacuumed table table=objects1238=== NAME TestClientFallsBackToClosures1239 client_pushes_test.go:112: Retrieved narinfo from S3:1240 StorePath: /build/TestClientFallsBackToClosures2095829182/001/store/ik7yq9ah15vng0rqbpzkwg5xy746c8k6-shared-dep1241 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1242 Compression: zstd1243 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821244 NarSize: 1361245 References: 1246 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1247 client_pushes_test.go:112: Retrieved narinfo from S3:1248 StorePath: /build/TestClientFallsBackToClosures2095829182/001/store/x5vrdkgfxnsf04shcv5404hc5nf65xka-a1249 URL: nar/0kfdwkdmxng2754m37g2ds91bn2hfn7376495x2h12mj9nvv2fsp.nar.zst1250 Compression: zstd1251 NarHash: sha256:0kfdwkdmxng2754m37g2ds91bn2hfn7376495x2h12mj9nvv2fsp1252 NarSize: 2161253 References: /build/TestClientFallsBackToClosures2095829182/001/store/ik7yq9ah15vng0rqbpzkwg5xy746c8k6-shared-dep1254 CA: text:sha256:0rngf1k6vccv091cs158fj6b3jl6d9spaskiri2cw7jgiqsvznhc1255 client_pushes_test.go:112: Retrieved narinfo from S3:1256 StorePath: /build/TestClientFallsBackToClosures2095829182/001/store/zidsplq6r10kd5r0rhqfcl2k703ny9rw-b1257 URL: nar/0kfdwkdmxng2754m37g2ds91bn2hfn7376495x2h12mj9nvv2fsp.nar.zst1258 Compression: zstd1259 NarHash: sha256:0kfdwkdmxng2754m37g2ds91bn2hfn7376495x2h12mj9nvv2fsp1260 NarSize: 2161261 References: /build/TestClientFallsBackToClosures2095829182/001/store/ik7yq9ah15vng0rqbpzkwg5xy746c8k6-shared-dep1262 CA: text:sha256:0rngf1k6vccv091cs158fj6b3jl6d9spaskiri2cw7jgiqsvznhc1263--- PASS: TestClientFallsBackToClosures (0.57s)1264=== CONT TestForceGCDuringPushOffersSweptObject1265=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1266=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1267=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1268=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1269=== CONT TestSweepRechecksPendingAfterLocking12702026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes1271--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)1272=== CONT TestDeduplicatedObjectsRecordedAsPending12732026/10/06 10:46:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12742026/10/06 10:46:42 INFO Uploading mkjl49mzdvg29pav1d870202znf4ynsx-b (216B)12752026/10/06 10:46:42 INFO Uploading 34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz-shared-dep (136B)1276=== NAME TestClientWithDependencies1277 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1771889036/001/store/q8vah9hqw9zrwqvb9acwz93w6bd2kkm4-test-script12782026/10/06 10:46:42 WARN Failed to register uploaded object key=mkjl49mzdvg29pav1d870202znf4ynsx.ls error="server returned 404: 404 page not found\n"1279--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.32s)1280=== CONT TestGCMetrics12812026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/07ymb4c213y1p91fa5jq1ffrs8r8v3cicid55hybad25kg8f3kfv.nar.zst error="server returned 404: 404 page not found\n"12822026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12832026/10/06 10:46:42 WARN Failed to register uploaded object key=fp8hvqdxmcax48gnahkwlx1djn4xjayk.ls error="server returned 404: 404 page not found\n"12842026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12852026/10/06 10:46:42 WARN Failed to register uploaded object key=34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz.ls error="server returned 404: 404 page not found\n"12862026/10/06 10:46:42 INFO Signed narinfos id=1 count=312872026/10/06 10:46:42 INFO Uploading 3 narinfos12882026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=012892026/10/06 10:46:42 WARN Failed to register uploaded object key=mkjl49mzdvg29pav1d870202znf4ynsx.narinfo error="server returned 404: 404 page not found\n"12902026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete12912026/10/06 10:46:42 WARN Failed to register uploaded object key=34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz.narinfo error="server returned 404: 404 page not found\n"12922026/10/06 10:46:42 WARN Failed to register uploaded object key=fp8hvqdxmcax48gnahkwlx1djn4xjayk.narinfo error="server returned 404: 404 page not found\n"12932026/10/06 10:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period12942026/10/06 10:46:42 INFO Upload complete. (62ms)1295=== NAME TestClientPushesUseOnePush1296 client_pushes_test.go:97: Retrieved narinfo from S3:1297 StorePath: /build/TestClientPushesUseOnePush1943362367/001/store/34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz-shared-dep1298 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1299 Compression: zstd1300 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821301 NarSize: 1361302 References: 1303 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13042026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes1305 client_pushes_test.go:97: Retrieved narinfo from S3:1306 StorePath: /build/TestClientPushesUseOnePush1943362367/001/store/fp8hvqdxmcax48gnahkwlx1djn4xjayk-a1307 URL: nar/07ymb4c213y1p91fa5jq1ffrs8r8v3cicid55hybad25kg8f3kfv.nar.zst1308 Compression: zstd1309 NarHash: sha256:07ymb4c213y1p91fa5jq1ffrs8r8v3cicid55hybad25kg8f3kfv1310 NarSize: 2161311 References: /build/TestClientPushesUseOnePush1943362367/001/store/34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz-shared-dep1312 CA: text:sha256:0mdp925pd1m1b3vbm54s38jzbjifrvw20vvvfrvx88r6zvjwbwa713132026/10/06 10:46:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13142026/10/06 10:46:42 INFO Uploading 6k4pd6h6q49c14pjnms5im96lzq0py7f-pinned-file.txt (128B)1315 client_pushes_test.go:97: Retrieved narinfo from S3:1316 StorePath: /build/TestClientPushesUseOnePush1943362367/001/store/mkjl49mzdvg29pav1d870202znf4ynsx-b1317 URL: nar/07ymb4c213y1p91fa5jq1ffrs8r8v3cicid55hybad25kg8f3kfv.nar.zst1318 Compression: zstd1319 NarHash: sha256:07ymb4c213y1p91fa5jq1ffrs8r8v3cicid55hybad25kg8f3kfv1320 NarSize: 2161321 References: /build/TestClientPushesUseOnePush1943362367/001/store/34ljfi7k2a9hvgyn9zqn5f5mbnvdplmz-shared-dep1322 CA: text:sha256:0mdp925pd1m1b3vbm54s38jzbjifrvw20vvvfrvx88r6zvjwbwa713232026/10/06 10:46:42 WARN Failed to register uploaded object key=6k4pd6h6q49c14pjnms5im96lzq0py7f.ls error="server returned 404: 404 page not found\n"13242026/10/06 10:46:42 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=013252026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13262026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13272026/10/06 10:46:42 INFO Signed narinfos id=1 count=113282026/10/06 10:46:42 INFO Uploading 1 narinfos13292026/10/06 10:46:42 INFO Vacuumed table table=pending_closures13302026/10/06 10:46:42 INFO Vacuumed table table=pending_objects13312026/10/06 10:46:42 INFO Vacuumed table table=multipart_uploads1332--- PASS: TestClientPushesUseOnePush (0.56s)1333=== CONT TestGetExistingObjectsLocksRows13342026/10/06 10:46:42 INFO Vacuumed table table=closures13352026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete13362026/10/06 10:46:42 WARN Failed to register uploaded object key=6k4pd6h6q49c14pjnms5im96lzq0py7f.narinfo error="server returned 404: 404 page not found\n"13372026/10/06 10:46:42 INFO Vacuumed table table=objects13382026/10/06 10:46:43 INFO Upload complete. (56ms)1339--- PASS: TestGCSweepDeliversEachKeyOnce (0.37s)1340=== CONT TestGCBugBareHashReferences1341=== NAME TestClientWithDependencies1342 client_integration_test.go:615: Found 1 dependencies (including self)13432026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes13442026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=013452026/10/06 10:46:43 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13462026/10/06 10:46:43 INFO Uploading prw9cpyg5dl63vr6yl7h77di57pb617r-top (224B)13472026/10/06 10:46:43 INFO Uploading nvazqapjhkymps75zpa6vrgp3f6y70fq-shared-dep (136B)13482026/10/06 10:46:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13492026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period13502026/10/06 10:46:43 WARN Failed to register uploaded object key=nvazqapjhkymps75zpa6vrgp3f6y70fq.ls error="server returned 404: 404 page not found\n"13512026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures13522026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/0saj0hb3hbk4s5g9xdw94ysmmyjjnq6iv2xbwjxw555pn2njk98y.nar.zst error="server returned 404: 404 page not found\n"13532026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13542026/10/06 10:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13552026/10/06 10:46:43 WARN Failed to register uploaded object key=prw9cpyg5dl63vr6yl7h77di57pb617r.ls error="server returned 404: 404 page not found\n"13562026/10/06 10:46:43 INFO Signed narinfos id=1 count=213572026/10/06 10:46:43 INFO Uploading 2 narinfos13582026/10/06 10:46:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013592026/10/06 10:46:43 INFO Vacuumed table table=pending_closures13602026/10/06 10:46:43 INFO Vacuumed table table=pending_objects13612026/10/06 10:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete13622026/10/06 10:46:43 WARN Failed to register uploaded object key=prw9cpyg5dl63vr6yl7h77di57pb617r.narinfo error="server returned 404: 404 page not found\n"13632026/10/06 10:46:43 WARN Failed to register uploaded object key=nvazqapjhkymps75zpa6vrgp3f6y70fq.narinfo error="server returned 404: 404 page not found\n"13642026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads13652026/10/06 10:46:43 INFO Vacuumed table table=closures1366--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.32s)1367=== CONT TestPushDedupSurvivesConcurrentGC13682026/10/06 10:46:43 INFO Vacuumed table table=objects13692026/10/06 10:46:43 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTE0OWM2ZjgtMjNlYi00ZDI0LWI1OWMtMzg0YjU2YTczYzY5LmM0YmU4Y2I2LTc0OGMtNGNlZS1iM2JhLTdhNjJjY2VjN2IwZHgxNzkxMjgzNjAyNzA3OTI5MDMz parts=1013702026/10/06 10:46:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13712026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=013722026/10/06 10:46:43 INFO Upload complete. (61ms)1373=== NAME TestClientSharedPathCommittedMidPush1374 client_integration_test.go:680: Retrieved narinfo from S3:1375 StorePath: /build/TestClientSharedPathCommittedMidPush3994258534/001/store/nvazqapjhkymps75zpa6vrgp3f6y70fq-shared-dep1376 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1377 Compression: zstd1378 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821379 NarSize: 1361380 References: 1381 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13822026/10/06 10:46:43 INFO Completed upload id=113832026/10/06 10:46:43 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013842026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period13852026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures1386 client_integration_test.go:680: Retrieved narinfo from S3:1387 StorePath: /build/TestClientSharedPathCommittedMidPush3994258534/001/store/prw9cpyg5dl63vr6yl7h77di57pb617r-top1388 URL: nar/0saj0hb3hbk4s5g9xdw94ysmmyjjnq6iv2xbwjxw555pn2njk98y.nar.zst1389 Compression: zstd1390 NarHash: sha256:0saj0hb3hbk4s5g9xdw94ysmmyjjnq6iv2xbwjxw555pn2njk98y1391 NarSize: 2241392 References: /build/TestClientSharedPathCommittedMidPush3994258534/001/store/nvazqapjhkymps75zpa6vrgp3f6y70fq-shared-dep1393 CA: text:sha256:12a93dcxgf6p0l8m5kr0n3ziygp6kd7vp4rnzgj7ysxydpnn83xz1394--- PASS: TestClientSharedPathCommittedMidPush (0.52s)1395=== CONT TestGCAdvisoryLockBlocksConcurrentRun13962026/10/06 10:46:43 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=013972026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures13982026/10/06 10:46:43 INFO Vacuumed table table=pending_closures13992026/10/06 10:46:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures14002026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14012026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads14022026/10/06 10:46:43 INFO Vacuumed table table=closures14032026/10/06 10:46:43 INFO Vacuumed table table=objects1404--- PASS: TestSweepSkipsRowsLockedByPush (0.40s)1405=== CONT TestService_ReadScope_PublicByDefault14062026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014072026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures14082026/10/06 10:46:43 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=014092026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes14102026/10/06 10:46:43 INFO Vacuumed table table=pending_closures14112026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes14122026/10/06 10:46:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14132026/10/06 10:46:43 INFO Uploading idf7s3dxc2572sr91ixqn2w0s5s5bli6-unpinned-file.txt (128B)14142026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14152026/10/06 10:46:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14162026/10/06 10:46:43 INFO Uploading q8vah9hqw9zrwqvb9acwz93w6bd2kkm4-test-script (136B)14172026/10/06 10:46:43 WARN Failed to register uploaded object key=idf7s3dxc2572sr91ixqn2w0s5s5bli6.ls error="server returned 404: 404 page not found\n"14182026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads14192026/10/06 10:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14202026/10/06 10:46:43 INFO Signed narinfos id=2 count=114212026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14222026/10/06 10:46:43 INFO Uploading 1 narinfos14232026/10/06 10:46:43 INFO Vacuumed table table=closures14242026/10/06 10:46:43 WARN Failed to register uploaded object key=q8vah9hqw9zrwqvb9acwz93w6bd2kkm4.ls error="server returned 404: 404 page not found\n"14252026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14262026/10/06 10:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14272026/10/06 10:46:43 WARN Failed to register uploaded object key=log/g93s06j7xcpnsy4mwknbvlw6sgxbiyf5-test-script.drv error="server returned 404: 404 page not found\n"14282026/10/06 10:46:43 INFO Received complete push request method=POST path=/api/pushes/2/complete14292026/10/06 10:46:43 WARN Failed to register uploaded object key=idf7s3dxc2572sr91ixqn2w0s5s5bli6.narinfo error="server returned 404: 404 page not found\n"14302026/10/06 10:46:43 INFO Signed narinfos id=1 count=114312026/10/06 10:46:43 INFO Uploading 1 narinfos14322026/10/06 10:46:43 INFO Vacuumed table table=objects14332026/10/06 10:46:43 INFO Upload complete. (49ms)14342026/10/06 10:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete14352026/10/06 10:46:43 WARN Failed to register uploaded object key=q8vah9hqw9zrwqvb9acwz93w6bd2kkm4.narinfo error="server returned 404: 404 page not found\n"14362026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures14372026/10/06 10:46:43 INFO Upload complete. (54ms)1438=== NAME TestClientWithDependencies1439 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1771889036/001/store) requires matching store prefix1440--- PASS: TestClientWithDependencies (0.53s)1441=== CONT TestService_ReadAuthMiddleware14422026/10/06 10:46:43 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001443--- PASS: TestService_createPendingClosureHandler (0.77s)1444=== CONT TestClientIntegration14452026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014462026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period14472026/10/06 10:46:43 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=014482026/10/06 10:46:43 INFO Vacuumed table table=pending_closures1449--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.86s)1450=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14512026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14522026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads14532026/10/06 10:46:43 INFO Vacuumed table table=closures14542026/10/06 10:46:43 INFO Vacuumed table table=objects1455--- PASS: TestGCSweepSkipsPendingObjects (0.23s)1456=== CONT TestService_RequireScope_OIDC14572026/10/06 10:46:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures14582026/10/06 10:46:43 INFO Garbage collection started1459--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.78s)1460=== CONT TestClientErrorHandling1461=== RUN TestClientErrorHandling/InvalidStorePath1462=== PAUSE TestClientErrorHandling/InvalidStorePath1463=== RUN TestClientErrorHandling/InvalidAuthToken1464=== PAUSE TestClientErrorHandling/InvalidAuthToken1465=== RUN TestClientErrorHandling/ServerNotAvailable1466=== PAUSE TestClientErrorHandling/ServerNotAvailable1467--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.54s)1468=== CONT TestService_AuthMiddleware_MTLSProxyHeader1469=== CONT TestService_AuthMiddleware_OIDC14702026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014712026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014722026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period14732026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period14742026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014752026/10/06 10:46:43 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14762026/10/06 10:46:43 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14772026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period1478--- PASS: TestFailedS3DeleteKeepsTombstone (0.34s)1479=== CONT TestClientCADerivations14802026/10/06 10:46:43 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=014812026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=014822026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period14832026/10/06 10:46:43 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=014842026/10/06 10:46:43 INFO Vacuumed table table=pending_closures14852026/10/06 10:46:43 INFO Vacuumed table table=pending_closures14862026/10/06 10:46:43 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=014872026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14882026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads14892026/10/06 10:46:43 INFO Vacuumed table table=closures14902026/10/06 10:46:43 INFO Vacuumed table table=objects14912026/10/06 10:46:43 INFO Vacuumed table table=pending_closures14922026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14932026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads1494--- PASS: TestGCMetrics (0.21s)1495=== CONT TestCacheStatsHandler14962026/10/06 10:46:43 INFO Vacuumed table table=pending_objects14972026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads14982026/10/06 10:46:43 INFO Vacuumed table table=closures14992026/10/06 10:46:43 INFO Vacuumed table table=closures15002026/10/06 10:46:43 INFO Vacuumed table table=objects15012026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures15022026/10/06 10:46:43 INFO Vacuumed table table=objects1503--- PASS: TestSweepRechecksPendingAfterLocking (0.23s)1504=== CONT TestCacheConfigHandler1505=== RUN TestCacheConfigHandler/full_config,_no_issuer1506=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1507=== RUN TestCacheConfigHandler/no_cache_url_configured1508=== PAUSE TestCacheConfigHandler/no_cache_url_configured1509=== RUN TestCacheConfigHandler/no_signing_keys1510=== PAUSE TestCacheConfigHandler/no_signing_keys1511=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1512=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1513=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15142026/10/06 10:46:43 INFO Received uploads request method=POST path=/1515=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15162026/10/06 10:46:43 INFO Received request for more parts method=POST path=/1517=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15182026/10/06 10:46:43 INFO Received complete multipart upload request method=POST path=/1519=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15202026/10/06 10:46:43 INFO Received uploads request method=POST path=/1521--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1522 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1523 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1524 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1525 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1526=== CONT TestIsValidUploadKey/narinfo1527=== CONT TestIsValidUploadKey/realisation_plus_in_output1528=== CONT TestIsValidUploadKey/unknown_type1529=== CONT TestIsValidUploadKey/empty_key1530=== CONT TestIsValidUploadKey/absolute1531=== CONT TestIsValidUploadKey/traversal_nar1532=== CONT TestIsValidUploadKey/traversal1533=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1534=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1535=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1536=== CONT TestIsValidUploadKey/index.html1537=== CONT TestIsValidUploadKey/nix-cache-info1538=== CONT TestIsValidUploadKey/build_log_home-manager_file1539=== CONT TestIsValidUploadKey/realisation1540=== CONT TestIsValidUploadKey/nar_plain1541=== CONT TestIsValidUploadKey/build_log_equals1542=== CONT TestIsValidUploadKey/nar_xz1543=== CONT TestIsValidUploadKey/build_log1544=== CONT TestIsValidUploadKey/build_log_question_mark1545=== CONT TestIsValidUploadKey/listing1546=== CONT TestIsValidUploadKey/build_log_plus_in_name1547=== CONT TestIsValidUploadKey/nar_zst1548=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15492026/10/06 10:46:43 INFO Received uploads request method=POST path=/1550--- PASS: TestIsValidUploadKey (0.06s)1551 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1552 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1553 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1554 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1555 --- PASS: TestIsValidUploadKey/absolute (0.00s)1556 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1557 --- PASS: TestIsValidUploadKey/traversal (0.00s)1558 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1559 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1560 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1561 --- PASS: TestIsValidUploadKey/index.html (0.00s)1562 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1563 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1564 --- PASS: TestIsValidUploadKey/realisation (0.00s)1565 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1566 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1567 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1568 --- PASS: TestIsValidUploadKey/build_log (0.00s)1569 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1570 --- PASS: TestIsValidUploadKey/listing (0.00s)1571 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1572 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1573--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.23s)1574=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15752026/10/06 10:46:43 INFO Received request for more parts method=POST path=/1576--- PASS: TestGetExistingObjectsLocksRows (0.21s)1577=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15782026/10/06 10:46:43 INFO Received complete multipart upload request method=POST path=/1579=== CONT TestServerTLSConfig/no_client_CA1580=== CONT TestServerTLSConfig/not_a_PEM_file1581=== CONT TestServerTLSConfig/missing_CA_file1582--- PASS: TestServerTLSConfig (0.00s)1583 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1584 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1585 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1586=== CONT TestPush_RejectsBadRequests/no_roots15872026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes1588=== CONT TestPush_RejectsBadRequests/bad_root15892026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes1590=== CONT TestPush_RejectsBadRequests/root_not_in_objects15912026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes1592=== CONT TestPush_RejectsBadRequests/no_objects15932026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes1594=== CONT TestParseSingleRange/none1595--- PASS: TestPush_RejectsBadRequests (0.55s)1596 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1597 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1598 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1599 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1600=== CONT TestParseSingleRange/single_byte1601=== CONT TestParseSingleRange/suffix_exceeds_size1602=== CONT TestParseSingleRange/suffix1603=== CONT TestParseSingleRange/end_clamped_to_size1604=== CONT TestParseSingleRange/open-ended1605=== CONT TestParseSingleRange/closed1606=== CONT TestParseSingleRange/malformed_end_before_start1607=== CONT TestParseSingleRange/malformed_both_empty1608=== CONT TestParseSingleRange/malformed_no_dash1609=== CONT TestParseSingleRange/multi-range_ignored1610=== CONT TestParseSingleRange/unknown_unit1611=== CONT TestParseSingleRange/start_past_EOF1612=== CONT TestParseSingleRange/start_far_past_EOF1613--- PASS: TestParseSingleRange (0.00s)1614 --- PASS: TestParseSingleRange/none (0.00s)1615 --- PASS: TestParseSingleRange/single_byte (0.00s)1616 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1617 --- PASS: TestParseSingleRange/suffix (0.00s)1618 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1619 --- PASS: TestParseSingleRange/open-ended (0.00s)1620 --- PASS: TestParseSingleRange/closed (0.00s)1621 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1622 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1623 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1624 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1625 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1626 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1627 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1628=== CONT TestIsValidCachePath/narinfo1629=== CONT TestIsValidCachePath/short_hash1630=== CONT TestIsValidCachePath/wrong_extension1631=== CONT TestIsValidCachePath/leading_slash1632=== CONT TestIsValidCachePath/empty1633=== CONT TestIsValidCachePath/random_path1634=== CONT TestIsValidCachePath/invalid_char_u1635=== CONT TestIsValidCachePath/invalid_char_e1636=== CONT TestIsValidCachePath/traversal_in_middle1637=== CONT TestIsValidCachePath/traversal_parent1638=== CONT TestIsValidCachePath/index.html1639=== CONT TestIsValidCachePath/nix-cache-info1640=== CONT TestIsValidCachePath/realisation1641=== CONT TestIsValidCachePath/log1642=== CONT TestIsValidCachePath/ls1643=== CONT TestIsValidCachePath/nar_uncompressed1644=== CONT TestIsValidCachePath/nar_bz21645=== CONT TestIsValidCachePath/nar_xz1646=== CONT TestIsValidCachePath/nar_zst1647=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1648--- PASS: TestIsValidCachePath (0.00s)1649 --- PASS: TestIsValidCachePath/narinfo (0.00s)1650 --- PASS: TestIsValidCachePath/short_hash (0.00s)1651 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1652 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1653 --- PASS: TestIsValidCachePath/empty (0.00s)1654 --- PASS: TestIsValidCachePath/random_path (0.00s)1655 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1656 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1657 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1658 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1659 --- PASS: TestIsValidCachePath/index.html (0.00s)1660 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1661 --- PASS: TestIsValidCachePath/realisation (0.00s)1662 --- PASS: TestIsValidCachePath/log (0.00s)1663 --- PASS: TestIsValidCachePath/ls (0.00s)1664 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1665 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1666 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1667 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1668 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1669=== CONT TestPendingClosureWriteTimeout/empty1670=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16712026/10/06 10:46:43 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"1672--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.21s)1673=== CONT TestPendingClosureWriteTimeout/670k_objects1674=== CONT TestPendingClosureWriteTimeout/400_objects1675=== CONT TestProxyWriteTimeout/narinfo1676=== CONT TestProxyWriteTimeout/10_GiB_nar1677=== CONT TestProxyWriteTimeout/unknown_size1678=== CONT TestProxyWriteTimeout/1_GiB_nar1679--- PASS: TestProxyWriteTimeout (0.00s)1680 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1681 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1682 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1683 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1684=== CONT TestGCEndsOnShutdown/before_the_run16852026/10/06 10:46:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38709/oidc1686=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16872026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures16882026/10/06 10:46:43 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46123/oidc1689--- PASS: TestService_ReadScope_PublicByDefault (0.22s)1690=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1691--- PASS: TestService_ReadAuthMiddleware (0.19s)1692=== CONT TestResolveDBConnectionString/flag_wins1693=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1694=== CONT TestResolveDBConnectionString/nothing_configured1695=== CONT TestResolveDBConnectionString/missing_file_is_an_error1696=== CONT TestResolveDBConnectionString/file_when_flag_empty1697=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1698--- PASS: TestResolveDBConnectionString (0.00s)1699 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1700 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1701 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1702 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1703 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17042026/10/06 10:46:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17052026/10/06 10:46:43 WARN mTLS auth: bound subjects configured but subject DN unavailable17062026/10/06 10:46:43 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1707--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.22s)1708=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17092026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=017102026/10/06 10:46:43 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=017112026/10/06 10:46:43 INFO Vacuumed table table=pending_closures17122026/10/06 10:46:43 INFO Vacuumed table table=pending_objects17132026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads1714--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)1715=== CONT TestClientErrorHandling/InvalidStorePath17162026/10/06 10:46:43 INFO Vacuumed table table=closures1717=== NAME TestClientIntegration1718 client_integration_test.go:286: Created store path: /build/TestClientIntegration4014166415/002/store/8yjh5prbsz3c7g65kcjdyvddnl94mnml-test-file.txt17192026/10/06 10:46:43 INFO Vacuumed table table=objects17202026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=017212026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period17222026/10/06 10:46:43 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=017232026/10/06 10:46:43 INFO Vacuumed table table=pending_closures17242026/10/06 10:46:43 INFO Vacuumed table table=pending_objects17252026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads17262026/10/06 10:46:43 INFO Vacuumed table table=closures17272026/10/06 10:46:43 INFO Vacuumed table table=objects1728--- PASS: TestPushDedupSurvivesConcurrentGC (0.35s)1729=== CONT TestClientErrorHandling/InvalidAuthToken1730--- PASS: TestCacheStatsHandler (0.23s)1731=== CONT TestClientErrorHandling/ServerNotAvailable17322026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures17332026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes17342026/10/06 10:46:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17352026/10/06 10:46:43 INFO Uploading 8yjh5prbsz3c7g65kcjdyvddnl94mnml-test-file.txt (152B)17362026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17372026/10/06 10:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17382026/10/06 10:46:43 WARN Failed to register uploaded object key=8yjh5prbsz3c7g65kcjdyvddnl94mnml.ls error="server returned 404: 404 page not found\n"17392026/10/06 10:46:43 INFO Signed narinfos id=1 count=117402026/10/06 10:46:43 INFO Uploading 1 narinfos17412026/10/06 10:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete17422026/10/06 10:46:43 WARN Failed to register uploaded object key=8yjh5prbsz3c7g65kcjdyvddnl94mnml.narinfo error="server returned 404: 404 page not found\n"1743--- PASS: TestGCBugBareHashReferences (0.44s)1744=== CONT TestCacheConfigHandler/full_config,_no_issuer1745=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1746=== CONT TestCacheConfigHandler/no_signing_keys1747=== CONT TestCacheConfigHandler/no_cache_url_configured1748--- PASS: TestCacheConfigHandler (0.00s)1749 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1750 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1751 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1752 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)17532026/10/06 10:46:43 INFO Upload complete. (52ms)1754=== RUN TestService_RequireScope_OIDC/builder_may_write1755=== PAUSE TestService_RequireScope_OIDC/builder_may_write1756=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1757=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1758=== RUN TestService_RequireScope_OIDC/ops_may_admin1759=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1760=== RUN TestService_RequireScope_OIDC/ops_may_not_write1761=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1762=== RUN TestService_RequireScope_OIDC/reader_may_not_write1763=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1764=== RUN TestService_RequireScope_OIDC/static_token_may_admin1765=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1766=== RUN TestService_RequireScope_OIDC/static_token_may_write1767=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1768=== RUN TestService_RequireScope_OIDC/reader_may_read1769=== PAUSE TestService_RequireScope_OIDC/reader_may_read1770=== RUN TestService_RequireScope_OIDC/writer_implies_read1771=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1772=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1773=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1774=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1775=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1776=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1777=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1778=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1779=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1780=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1781=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1782=== CONT TestService_RequireScope_OIDC/builder_may_write1783=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1784=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1785=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17862026/10/06 10:46:43 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]1787=== CONT TestService_RequireScope_OIDC/static_token_may_write1788=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1789=== CONT TestService_RequireScope_OIDC/ops_may_not_write1790=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1791=== CONT TestService_RequireScope_OIDC/static_token_may_admin1792=== CONT TestService_RequireScope_OIDC/writer_implies_read1793=== CONT TestService_RequireScope_OIDC/reader_may_not_write1794=== CONT TestService_RequireScope_OIDC/reader_may_read1795=== CONT TestService_RequireScope_OIDC/ops_may_admin1796=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1797--- PASS: TestService_RequireScope_OIDC (0.34s)1798 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1799 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1800 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1801 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1802 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1803 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1804 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1805 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1806 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1807 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1808 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1809 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1810 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1811 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1812=== NAME TestClientCADerivations1813 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2554532173/001/store/k880z8f5pqjnq3m7rqd4dgi15c4srhvg-ca-test18142026/10/06 10:46:43 INFO All 1 paths already cached1815=== NAME TestClientIntegration1816 client_integration_test.go:312: Retrieved narinfo from S3:1817 StorePath: /build/TestClientIntegration4014166415/002/store/8yjh5prbsz3c7g65kcjdyvddnl94mnml-test-file.txt1818 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1819 Compression: zstd1820 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11821 NarSize: 1521822 References: 1823 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11824 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1825 client_integration_test.go:313: Decompressed .ls content (64 bytes):1826 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1827 client_integration_test.go:316: Testing garbage collection...18282026/10/06 10:46:43 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/present18292026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=018302026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period1831=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1832=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1833=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1834=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1835=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1836=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1837=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1838=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1839=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1840=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1841=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18422026/10/06 10:46:43 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]1843=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1844=== NAME TestClientCADerivations1845 client_ca_test.go:139: Found 1 dependencies (including self)18462026/10/06 10:46:43 WARN Authentication failed token_preview=eyJhbGciOi...oaJVqdAqmg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1847--- PASS: TestService_AuthMiddleware_OIDC (0.36s)1848 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1849 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1850 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1851 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18522026/10/06 10:46:43 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36881/bucket86/?delete=\": context canceled"18532026/10/06 10:46:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures18542026/10/06 10:46:43 INFO Garbage collection started18552026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=018562026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period18572026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=018582026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures18592026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period18602026-10-06 10:46:43.534 UTC [1570] ERROR: canceling statement due to user request18612026-10-06 10:46:43.534 UTC [1570] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block18622026-10-06 10:46:43.534 UTC [1570] STATEMENT: -- name: MarkStaleObjects :execrows1863 WITH RECURSIVE ct AS (1864 SELECT timezone('UTC', now()) AS now1865 ),1866 closure_reach AS (1867 -- Start with all closure keys1868 SELECT o.key, o.refs1869 FROM objects o1870 INNER JOIN closures c ON o.key = c.key1871 UNION1872 -- Recursively add all referenced objects1873 SELECT o.key, o.refs1874 FROM objects o1875 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1876 ),1877 reachable_objects AS (1878 SELECT DISTINCT key FROM closure_reach1879 ),1880 stale_objects AS (1881 SELECT o.key1882 FROM objects AS o, ct1883 WHERE1884 NOT EXISTS (1885 SELECT 11886 FROM reachable_objects ro1887 WHERE ro.key = o.key1888 )1889 AND NOT EXISTS (1890 SELECT 11891 FROM pending_objects AS po1892 WHERE po.key = o.key1893 )1894 AND o.deleted_at IS NULL -- Only mark fresh objects1895 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1896 FOR UPDATE1897 )1898 UPDATE objects1899 SET1900 deleted_at = ct.now,1901 first_deleted_at = COALESCE(first_deleted_at, ct.now)1902 FROM stale_objects, ct1903 WHERE objects.key = stale_objects.key1904 19052026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=019062026/10/06 10:46:43 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=019072026/10/06 10:46:43 INFO Vacuumed table table=pending_closures19082026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period1909--- PASS: TestGCEndsOnShutdown (0.00s)1910 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)1911 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.23s)1912 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.28s)19132026/10/06 10:46:43 INFO Vacuumed table table=pending_objects19142026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads19152026/10/06 10:46:43 INFO Vacuumed table table=closures19162026/10/06 10:46:43 INFO Vacuumed table table=objects19172026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures1918--- PASS: TestPushWaitsForSweepHoldingRow (0.79s)19192026/10/06 10:46:43 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=019202026/10/06 10:46:43 INFO Vacuumed table table=pending_closures19212026/10/06 10:46:43 INFO Vacuumed table table=pending_objects19222026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads19232026/10/06 10:46:43 INFO Vacuumed table table=closures19242026/10/06 10:46:43 INFO Vacuumed table table=objects19252026/10/06 10:46:43 INFO Aborted multipart uploads count=0 kept=019262026/10/06 10:46:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.825331ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19272026/10/06 10:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period19282026/10/06 10:46:43 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=019292026/10/06 10:46:43 INFO Vacuumed table table=pending_closures19302026/10/06 10:46:43 INFO Vacuumed table table=pending_objects19312026/10/06 10:46:43 INFO Vacuumed table table=multipart_uploads19322026/10/06 10:46:43 INFO Vacuumed table table=closures19332026/10/06 10:46:43 INFO Vacuumed table table=objects1934--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1935 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.36s)1936 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)19372026/10/06 10:46:43 INFO Received push request method=POST path=/api/pushes19382026/10/06 10:46:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19392026/10/06 10:46:43 INFO Uploading k880z8f5pqjnq3m7rqd4dgi15c4srhvg-ca-test (144B)19402026/10/06 10:46:43 WARN Failed to register uploaded object key=k880z8f5pqjnq3m7rqd4dgi15c4srhvg.ls error="server returned 404: 404 page not found\n"19412026/10/06 10:46:43 WARN Failed to register uploaded object key=log/1ilm5xf6ngd1qhr6y1z9w4b06hg3yjg7-ca-test.drv error="server returned 404: 404 page not found\n"19422026/10/06 10:46:43 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19432026/10/06 10:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19442026/10/06 10:46:43 INFO Signed narinfos id=1 count=119452026/10/06 10:46:43 INFO Uploading 1 narinfos19462026/10/06 10:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete19472026/10/06 10:46:43 WARN Failed to register uploaded object key=k880z8f5pqjnq3m7rqd4dgi15c4srhvg.narinfo error="server returned 404: 404 page not found\n"19482026/10/06 10:46:43 INFO Upload complete. (159ms)1949=== NAME TestClientCADerivations1950 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2554532173/001/store/k880z8f5pqjnq3m7rqd4dgi15c4srhvg-ca-test1951 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1952 Compression: zstd1953 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1954 NarSize: 1441955 References: 1956 Deriver: /build/TestClientCADerivations2554532173/001/store/1ilm5xf6ngd1qhr6y1z9w4b06hg3yjg7-ca-test.drv1957 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1958 client_ca_test.go:185: Checking for realisation files in S3...1959 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1960 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1961=== NAME TestOrphanedObjectsGCStressTest1962 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19632026/10/06 10:46:43 INFO lead: released remote=192.0.2.1:12341964--- PASS: TestLeadEndsOnShutdown (1.41s)19652026/10/06 10:46:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1966=== NAME TestOrphanedObjectsGCStressTest1967 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19682026/10/06 10:46:43 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1969=== NAME TestClientCADerivations1970 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1971 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1972 error: binary cache 's3://bucket81?endpoint=http://localhost:36881&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2554532173/001/store'1973 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11974--- PASS: TestClientCADerivations (0.63s)19752026/10/06 10:46:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.854873ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1976=== NAME TestOrphanedObjectsGCStressTest1977 orphaned_objects_gc_test.go:509: Stress test completed successfully:1978 orphaned_objects_gc_test.go:510: - Active objects preserved: 201979 orphaned_objects_gc_test.go:511: - Objects deleted: 2101980 orphaned_objects_gc_test.go:512: - Total GC'd: 2101981--- PASS: TestOrphanedObjectsGCStressTest (2.16s)19822026/10/06 10:46:44 INFO lead: released remote=192.0.2.1:123419832026/10/06 10:46:44 INFO lead: acquired remote=192.0.2.1:12341984--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)1985 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1986 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1987 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.97s)19882026/10/06 10:46:44 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=741.834674ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1989--- PASS: TestPendingClosureWriteTimeout (0.00s)1990 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1991 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1992 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1993 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.98s)19942026/10/06 10:46:44 WARN Rate limiter enabled after throttle name=s3-test rate=519952026/10/06 10:46:44 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1996=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1997 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101998 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001999--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.41s)20002026/10/06 10:46:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.45568276s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20012026/10/06 10:46:45 INFO lead: released remote=192.0.2.1:12342002--- PASS: TestLeadElectsOneAndHandsOver (2.67s)20032026/10/06 10:46:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020042026/10/06 10:46:45 INFO Received create pin request method=POST path=/api/pins/myapp20052026/10/06 10:46:45 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1206964221/001/store/6k4pd6h6q49c14pjnms5im96lzq0py7f-pinned-file.txt narinfo_key=6k4pd6h6q49c14pjnms5im96lzq0py7f.narinfo20062026/10/06 10:46:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures20072026/10/06 10:46:45 INFO Garbage collection started20082026/10/06 10:46:45 INFO Aborted multipart uploads count=0 kept=020092026/10/06 10:46:45 WARN Force mode enabled - objects will be deleted immediately without grace period20102026/10/06 10:46:45 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=020112026/10/06 10:46:45 INFO Vacuumed table table=pending_closures20122026/10/06 10:46:45 INFO Vacuumed table table=pending_objects20132026/10/06 10:46:45 INFO Vacuumed table table=multipart_uploads20142026/10/06 10:46:45 INFO Vacuumed table table=closures20152026/10/06 10:46:45 INFO Vacuumed table table=objects20162026/10/06 10:46:45 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02017=== NAME TestClientIntegration2018 client_integration_test.go:323: Objects in database after GC:2019 client_integration_test.go:323: Successfully deleted all objects with GC --force2020--- PASS: TestClientIntegration (2.42s)20212026/10/06 10:46:46 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-config20222026/10/06 10:46:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.653445ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2023--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.59s)20242026/10/06 10:46:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.240452ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/06 10:46:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.481487ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2026=== NAME TestPinProtectsFromGC2027 client_integration_test.go:840: Pin successfully protected closure from garbage collection2028--- PASS: TestPinProtectsFromGC (4.66s)2029--- PASS: TestConnectWaitsForAPeerMigration (5.12s)20302026/10/06 10:46:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.622240501s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 10:46:47 INFO Aborted multipart uploads count=1 kept=020322026/10/06 10:46:48 INFO Received cleanup request method=DELETE path=/api/pending_closures20332026/10/06 10:46:48 INFO Aborted multipart uploads count=1 kept=02034--- PASS: TestPendingCleanupUsesOneCutoff (6.49s)20352026/10/06 10:46:49 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"20362026/10/06 10:46:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 10:46:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.73475ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20382026/10/06 10:46:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.660844ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20392026/10/06 10:46:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.307078ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20402026/10/06 10:46:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.637810415s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/06 10:46:52 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_closures20422026/10/06 10:46:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.085473ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20432026/10/06 10:46:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.39615ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20442026/10/06 10:46:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=802.042509ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20452026/10/06 10:46:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.648247696s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2046--- PASS: TestClientErrorHandling (0.00s)2047 --- PASS: TestClientErrorHandling/InvalidStorePath (0.32s)2048 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2049 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.37s)2050PASS20512026-10-06 10:46:56.034 UTC [129] LOG: received smart shutdown request20522026-10-06 10:46:56.038 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120532026-10-06 10:46:56.050 UTC [134] LOG: shutting down20542026-10-06 10:46:56.050 UTC [134] LOG: checkpoint starting: shutdown immediate20552026-10-06 10:46:56.878 UTC [134] LOG: checkpoint complete: wrote 10969 buffers (66.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.176 s, sync=0.622 s, total=0.829 s; sync files=31336, longest=0.002 s, average=0.001 s; distance=433066 kB, estimate=433066 kB; lsn=0/1BE50748, redo lsn=0/1BE5074820562026-10-06 10:46:56.956 UTC [129] LOG: database system is shut down2057Running OIDC tests...2058=== RUN TestAudienceForIssuer2059=== PAUSE TestAudienceForIssuer2060=== RUN TestGlobMatch2061=== PAUSE TestGlobMatch2062=== RUN TestValidateToken_ValidToken2063=== PAUSE TestValidateToken_ValidToken2064=== RUN TestValidateToken_WrongAudience2065=== PAUSE TestValidateToken_WrongAudience2066=== RUN TestValidateToken_Expired2067=== PAUSE TestValidateToken_Expired2068=== RUN TestValidateToken_BoundClaimsMismatch2069=== PAUSE TestValidateToken_BoundClaimsMismatch2070=== RUN TestValidateToken_BoundSubjectMismatch2071=== PAUSE TestValidateToken_BoundSubjectMismatch2072=== RUN TestValidateToken_MultipleProviders2073=== PAUSE TestValidateToken_MultipleProviders2074=== RUN TestValidateToken_NoMatchingProvider2075=== PAUSE TestValidateToken_NoMatchingProvider2076=== RUN TestValidateToken_KubernetesServiceAccount2077=== PAUSE TestValidateToken_KubernetesServiceAccount2078=== RUN TestNewValidator_KubernetesRequiresCA2079=== PAUSE TestNewValidator_KubernetesRequiresCA2080=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2081=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2082=== RUN TestPins_ReservedForMatchingRule2083=== PAUSE TestPins_ReservedForMatchingRule2084=== RUN TestPins_TopLevelShorthand2085=== PAUSE TestPins_TopLevelShorthand2086=== RUN TestPins_ConfigValidation2087=== PAUSE TestPins_ConfigValidation2088=== RUN TestScopes_LegacyProviderDefaultsToWrite2089=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2090=== RUN TestScopes_Rules2091=== PAUSE TestScopes_Rules2092=== RUN TestScopes_ConfigValidation2093=== PAUSE TestScopes_ConfigValidation2094=== CONT TestAudienceForIssuer2095=== CONT TestValidateToken_KubernetesServiceAccount2096--- PASS: TestAudienceForIssuer (0.00s)2097=== CONT TestValidateToken_Expired2098=== CONT TestPins_ConfigValidation2099=== CONT TestValidateToken_WrongAudience2100=== CONT TestScopes_Rules2101=== CONT TestScopes_ConfigValidation2102=== CONT TestGlobMatch2103=== RUN TestGlobMatch/foo_foo2104=== PAUSE TestGlobMatch/foo_foo2105=== RUN TestGlobMatch/foo_bar2106=== PAUSE TestGlobMatch/foo_bar2107=== RUN TestGlobMatch/*_2108=== PAUSE TestGlobMatch/*_2109=== RUN TestGlobMatch/*_anything2110=== PAUSE TestGlobMatch/*_anything2111=== RUN TestGlobMatch/foo*_foo2112=== PAUSE TestGlobMatch/foo*_foo2113=== RUN TestGlobMatch/foo*_foobar2114=== PAUSE TestGlobMatch/foo*_foobar2115=== RUN TestGlobMatch/foo*_bar2116=== PAUSE TestGlobMatch/foo*_bar2117=== CONT TestScopes_LegacyProviderDefaultsToWrite2118=== RUN TestGlobMatch/*bar_bar2119=== PAUSE TestGlobMatch/*bar_bar2120=== RUN TestGlobMatch/*bar_foobar2121=== PAUSE TestGlobMatch/*bar_foobar2122=== RUN TestGlobMatch/*bar_foo2123--- PASS: TestScopes_ConfigValidation (0.00s)2124=== CONT TestValidateToken_MultipleProviders2125--- PASS: TestPins_ConfigValidation (0.00s)2126=== CONT TestValidateToken_BoundSubjectMismatch2127=== CONT TestValidateToken_ValidToken2128=== CONT TestPins_ReservedForMatchingRule2129=== CONT TestPins_TopLevelShorthand2130=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2131=== CONT TestNewValidator_KubernetesRequiresCA2132=== CONT TestValidateToken_BoundClaimsMismatch2133=== CONT TestValidateToken_NoMatchingProvider2134=== PAUSE TestGlobMatch/*bar_foo2135=== RUN TestGlobMatch/foo*bar_foobar2136=== PAUSE TestGlobMatch/foo*bar_foobar2137=== RUN TestGlobMatch/foo*bar_foo123bar2138=== PAUSE TestGlobMatch/foo*bar_foo123bar2139=== RUN TestGlobMatch/foo*bar_foobarbaz2140=== PAUSE TestGlobMatch/foo*bar_foobarbaz2141=== RUN TestGlobMatch/*/*_foo/bar2142=== PAUSE TestGlobMatch/*/*_foo/bar2143=== RUN TestGlobMatch/*/*_foo2144=== PAUSE TestGlobMatch/*/*_foo2145=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2146=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2147=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02148=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02149=== RUN TestGlobMatch/refs/*/main_refs/heads/main2150=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2151=== RUN TestGlobMatch/fo?_foo2152=== PAUSE TestGlobMatch/fo?_foo2153=== RUN TestGlobMatch/fo?_fo2154=== PAUSE TestGlobMatch/fo?_fo2155=== RUN TestGlobMatch/fo?_fooo2156=== PAUSE TestGlobMatch/fo?_fooo2157=== RUN TestGlobMatch/?oo_foo2158=== PAUSE TestGlobMatch/?oo_foo2159=== RUN TestGlobMatch/?oo_boo2160=== PAUSE TestGlobMatch/?oo_boo2161=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2162=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2163=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2164=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2165=== CONT TestGlobMatch/foo_foo2166=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2167=== CONT TestGlobMatch/?oo_boo2168=== CONT TestGlobMatch/?oo_foo2169=== CONT TestGlobMatch/fo?_fooo2170=== CONT TestGlobMatch/fo?_fo2171=== CONT TestGlobMatch/fo?_foo2172=== CONT TestGlobMatch/refs/*/main_refs/heads/main2173=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02174=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2175=== CONT TestGlobMatch/*/*_foo2176=== CONT TestGlobMatch/*/*_foo/bar2177=== CONT TestGlobMatch/foo*bar_foobarbaz2178=== CONT TestGlobMatch/foo*bar_foo123bar2179=== CONT TestGlobMatch/foo*bar_foobar2180=== CONT TestGlobMatch/*bar_foo2181=== CONT TestGlobMatch/*bar_foobar2182=== CONT TestGlobMatch/foo*_foo2183=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2184=== CONT TestGlobMatch/*_anything2185=== CONT TestGlobMatch/*_2186=== CONT TestGlobMatch/foo_bar2187=== CONT TestGlobMatch/foo*_bar2188=== CONT TestGlobMatch/*bar_bar2189=== CONT TestGlobMatch/foo*_foobar2190--- PASS: TestGlobMatch (0.00s)2191 --- PASS: TestGlobMatch/foo_foo (0.00s)2192 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/?oo_boo (0.00s)2194 --- PASS: TestGlobMatch/?oo_foo (0.00s)2195 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2196 --- PASS: TestGlobMatch/fo?_fo (0.00s)2197 --- PASS: TestGlobMatch/fo?_foo (0.00s)2198 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2200 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2201 --- PASS: TestGlobMatch/*/*_foo (0.00s)2202 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2203 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2204 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2205 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2206 --- PASS: TestGlobMatch/*bar_foo (0.00s)2207 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2208 --- PASS: TestGlobMatch/foo*_foo (0.00s)2209 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2210 --- PASS: TestGlobMatch/*_anything (0.00s)2211 --- PASS: TestGlobMatch/*_ (0.00s)2212 --- PASS: TestGlobMatch/foo_bar (0.00s)2213 --- PASS: TestGlobMatch/foo*_bar (0.00s)2214 --- PASS: TestGlobMatch/*bar_bar (0.00s)2215 --- PASS: TestGlobMatch/foo*_foobar (0.00s)22162026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43649/oidc2217--- PASS: TestValidateToken_Expired (0.05s)22182026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43265/oidc2219--- PASS: TestPins_ReservedForMatchingRule (0.08s)22202026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34453/oidc2221--- PASS: TestPins_TopLevelShorthand (0.08s)22222026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37921/oidc22232026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37829/oidc2224--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)22252026/10/06 10:46:58 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:455472226--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2227--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)22282026/10/06 10:46:58 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232229--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)22302026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42235/oidc2231--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)22322026/10/06 10:46:58 http: TLS handshake error from 127.0.0.1:38758: remote error: tls: bad certificate2233--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)22342026/10/06 10:46:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39585/oidc22352026/10/06 10:46:58 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42329/oidc2236--- PASS: TestValidateToken_MultipleProviders (0.16s)22372026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42803/oidc2238--- PASS: TestValidateToken_ValidToken (0.19s)22392026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42397/oidc2240--- PASS: TestScopes_Rules (0.23s)22412026/10/06 10:46:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40451/oidc2242--- PASS: TestValidateToken_NoMatchingProvider (0.26s)22432026/10/06 10:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36951/oidc2244--- PASS: TestValidateToken_WrongAudience (0.30s)2245PASS2246Running hook tests...2247=== RUN TestSendPathsEmpty2248=== PAUSE TestSendPathsEmpty2249=== RUN TestQueueEnqueueAndFetch2250=== PAUSE TestQueueEnqueueAndFetch2251=== RUN TestQueueDeduplication2252=== PAUSE TestQueueDeduplication2253=== RUN TestQueueRemove2254=== PAUSE TestQueueRemove2255=== RUN TestQueueFetchBatchLimit2256=== PAUSE TestQueueFetchBatchLimit2257=== RUN TestQueueRetryMovesToBack2258=== PAUSE TestQueueRetryMovesToBack2259=== RUN TestQueueFetchRemoveLifecycle2260=== PAUSE TestQueueFetchRemoveLifecycle2261=== RUN TestQueueConcurrentWriters2262=== PAUSE TestQueueConcurrentWriters2263=== RUN TestQueueRemoveLargeClosure2264=== PAUSE TestQueueRemoveLargeClosure2265=== RUN TestServerClientIntegration2266=== PAUSE TestServerClientIntegration2267=== RUN TestServerQueueError2268=== PAUSE TestServerQueueError2269=== RUN TestGetListenerSocketActivation2270 server_test.go:210: === RUN TestGetListenerSocketActivation2271 --- PASS: TestGetListenerSocketActivation (0.00s)2272 PASS2273 2274--- PASS: TestGetListenerSocketActivation (0.01s)2275=== RUN TestDrainIsolatesPoisonPath2276=== PAUSE TestDrainIsolatesPoisonPath2277=== RUN TestRunNotBlockedByPoisonHead2278=== PAUSE TestRunNotBlockedByPoisonHead2279=== RUN TestDrainGivesUpWhenServerDown2280=== PAUSE TestDrainGivesUpWhenServerDown2281=== RUN TestFailedPathPrunedByLaterClosure2282=== PAUSE TestFailedPathPrunedByLaterClosure2283=== RUN TestWorkerUploadsAndRemoves2284=== PAUSE TestWorkerUploadsAndRemoves2285=== RUN TestWorkerSkipsGCdPaths2286=== PAUSE TestWorkerSkipsGCdPaths2287=== RUN TestWorkerPrunesClosureDeps2288=== PAUSE TestWorkerPrunesClosureDeps2289=== RUN TestDrainTimeout2290=== PAUSE TestDrainTimeout2291=== CONT TestSendPathsEmpty2292=== CONT TestDrainIsolatesPoisonPath2293--- PASS: TestSendPathsEmpty (0.00s)2294=== CONT TestServerQueueError2295=== CONT TestServerClientIntegration2296=== CONT TestQueueRemoveLargeClosure2297=== CONT TestQueueConcurrentWriters2298=== CONT TestQueueFetchRemoveLifecycle22992026/10/06 10:46:58 ERROR Failed to queue paths error="permission denied" count=12300=== CONT TestQueueRetryMovesToBack2301--- PASS: TestServerQueueError (0.00s)2302=== CONT TestQueueFetchBatchLimit2303=== CONT TestQueueRemove2304--- PASS: TestServerClientIntegration (0.00s)2305=== CONT TestQueueDeduplication2306=== CONT TestQueueEnqueueAndFetch2307=== CONT TestDrainGivesUpWhenServerDown2308=== CONT TestFailedPathPrunedByLaterClosure2309=== CONT TestRunNotBlockedByPoisonHead2310=== CONT TestWorkerPrunesClosureDeps2311=== CONT TestDrainTimeout2312=== CONT TestWorkerSkipsGCdPaths2313=== CONT TestWorkerUploadsAndRemoves23142026/10/06 10:46:58 INFO Upload queue status pending=323152026/10/06 10:46:58 INFO Uploading batch count=123162026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=123172026/10/06 10:46:58 INFO Upload queue status pending=223182026/10/06 10:46:58 INFO Uploading batch count=223192026/10/06 10:46:58 INFO Upload queue status pending=223202026/10/06 10:46:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths323421083/002/nonexistent23212026/10/06 10:46:58 INFO Uploading batch count=42322--- PASS: TestQueueFetchBatchLimit (0.01s)23232026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=423242026/10/06 10:46:58 INFO Uploading batch count=123252026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=123262026/10/06 10:46:58 INFO Uploading batch count=223272026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath385500040/002/bbb23282026/10/06 10:46:58 INFO Uploading batch count=123292026/10/06 10:46:58 INFO Uploading batch count=12330--- PASS: TestQueueEnqueueAndFetch (0.01s)2331--- PASS: TestQueueDeduplication (0.01s)2332--- PASS: TestQueueRetryMovesToBack (0.01s)23332026/10/06 10:46:58 INFO Upload queue status pending=223342026/10/06 10:46:58 INFO Uploading batch count=223352026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=223362026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/a23372026/10/06 10:46:58 INFO Uploading batch count=123382026/10/06 10:46:58 INFO Uploading batch count=12339--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23402026/10/06 10:46:58 INFO Uploading batch count=123412026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=123422026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/b23432026/10/06 10:46:58 INFO Uploading batch count=123442026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=12345--- PASS: TestQueueRemove (0.02s)23462026/10/06 10:46:58 INFO Uploading batch count=223472026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=223482026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/c23492026/10/06 10:46:58 INFO Uploading batch count=123502026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=123512026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/d23522026/10/06 10:46:58 ERROR Drain finished with paths left in queue remaining=12353--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23542026/10/06 10:46:58 INFO Uploading batch count=223552026/10/06 10:46:58 ERROR Upload failed error="upload failed" count=223562026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/e23572026/10/06 10:46:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2776726863/002/f23582026/10/06 10:46:58 ERROR Drain finished with paths left in queue remaining=102359--- PASS: TestDrainIsolatesPoisonPath (0.02s)2360--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2361--- PASS: TestWorkerSkipsGCdPaths (0.03s)2362--- PASS: TestWorkerUploadsAndRemoves (0.03s)2363--- PASS: TestWorkerPrunesClosureDeps (0.03s)2364--- PASS: TestQueueRemoveLargeClosure (0.11s)2365--- PASS: TestQueueConcurrentWriters (0.15s)23662026/10/06 10:46:59 ERROR Upload failed error="context deadline exceeded" count=223672026/10/06 10:46:59 ERROR Drain finished with paths left in queue remaining=42368--- PASS: TestDrainTimeout (0.21s)23692026/10/06 10:46:59 INFO Uploading batch count=123702026/10/06 10:46:59 INFO Uploading batch count=123712026/10/06 10:46:59 INFO Uploading batch count=123722026/10/06 10:46:59 ERROR Upload failed error="upload failed" count=123732026/10/06 10:46:59 INFO Uploading batch count=123742026/10/06 10:46:59 ERROR Upload failed error="upload failed" count=123752026/10/06 10:46:59 INFO Uploading batch count=123762026/10/06 10:46:59 ERROR Upload failed error="upload failed" count=123772026/10/06 10:46:59 INFO Uploading batch count=123782026/10/06 10:46:59 ERROR Upload failed error="upload failed" count=123792026/10/06 10:46:59 ERROR Drain finished with paths left in queue remaining=12380--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2381PASS2382Running signing tests...2383=== RUN TestExternalSigner2384=== PAUSE TestExternalSigner2385=== RUN TestExternalSignerWrongPublicKey2386=== PAUSE TestExternalSignerWrongPublicKey2387=== RUN TestExternalSignerErrors2388=== PAUSE TestExternalSignerErrors2389=== RUN TestExternalSignerRestartsAfterCrash2390=== PAUSE TestExternalSignerRestartsAfterCrash2391=== RUN TestExternalSignerProgramErrorKeepsProcess2392=== PAUSE TestExternalSignerProgramErrorKeepsProcess2393=== RUN TestExternalSignerClose2394=== PAUSE TestExternalSignerClose2395=== RUN TestExternalSignerRejectsInvalidPublicKey2396=== PAUSE TestExternalSignerRejectsInvalidPublicKey2397=== RUN TestExternalSignerCancellation2398=== PAUSE TestExternalSignerCancellation2399=== RUN TestGenerateFingerprint2400=== PAUSE TestGenerateFingerprint2401=== RUN TestParseSigningKey2402=== PAUSE TestParseSigningKey2403=== RUN TestSign2404=== PAUSE TestSign2405=== RUN TestSignBatch2406=== PAUSE TestSignBatch2407=== RUN TestNilKeyPublicKey2408=== PAUSE TestNilKeyPublicKey2409=== RUN TestSignErrors2410=== PAUSE TestSignErrors2411=== CONT TestExternalSigner2412=== CONT TestExternalSignerCancellation2413=== CONT TestExternalSignerProgramErrorKeepsProcess2414=== CONT TestSignErrors2415=== CONT TestNilKeyPublicKey2416--- PASS: TestNilKeyPublicKey (0.00s)2417=== CONT TestSignBatch2418=== CONT TestSign2419=== CONT TestParseSigningKey2420=== RUN TestParseSigningKey/valid_32-byte_key2421=== PAUSE TestParseSigningKey/valid_32-byte_key2422=== CONT TestGenerateFingerprint2423=== CONT TestExternalSignerErrors2424=== RUN TestGenerateFingerprint/basic_with_references2425=== PAUSE TestGenerateFingerprint/basic_with_references2426=== CONT TestExternalSignerRestartsAfterCrash2427=== RUN TestExternalSignerErrors/null2428=== PAUSE TestExternalSignerErrors/null2429=== RUN TestExternalSignerErrors/wrong_id2430=== PAUSE TestExternalSignerErrors/wrong_id2431=== CONT TestExternalSignerClose2432=== CONT TestExternalSignerWrongPublicKey2433=== CONT TestExternalSignerRejectsInvalidPublicKey2434=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2435=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2436=== RUN TestParseSigningKey/no_colon2437=== PAUSE TestParseSigningKey/no_colon2438=== RUN TestParseSigningKey/empty_name2439=== PAUSE TestParseSigningKey/empty_name2440=== RUN TestExternalSignerRejectsInvalidPublicKey/#002441=== RUN TestParseSigningKey/invalid_base642442=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002443=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2444=== RUN TestGenerateFingerprint/no_references2445=== PAUSE TestGenerateFingerprint/no_references2446=== RUN TestExternalSignerErrors/missing_signatures2447=== PAUSE TestExternalSignerErrors/missing_signatures2448=== PAUSE TestParseSigningKey/invalid_base642449=== RUN TestExternalSignerErrors/unrequested_key2450=== PAUSE TestExternalSignerErrors/unrequested_key2451=== RUN TestParseSigningKey/wrong_length2452=== RUN TestExternalSignerErrors/invalid_signature_base642453=== PAUSE TestParseSigningKey/wrong_length2454=== PAUSE TestExternalSignerErrors/invalid_signature_base642455=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2456=== CONT TestParseSigningKey/valid_32-byte_key2457=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2458=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2459=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2460=== CONT TestParseSigningKey/wrong_length2461=== CONT TestParseSigningKey/invalid_base642462=== CONT TestParseSigningKey/empty_name2463=== CONT TestParseSigningKey/no_colon2464=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2465=== RUN TestExternalSignerErrors/program_error2466=== PAUSE TestExternalSignerErrors/program_error2467=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2468=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2469=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2470=== RUN TestExternalSignerErrors/null_signatures2471=== RUN TestGenerateFingerprint/invalid_nar_hash_length2472=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2473=== PAUSE TestExternalSignerErrors/null_signatures2474=== RUN TestExternalSignerErrors/wrong_signature_length2475=== PAUSE TestExternalSignerErrors/wrong_signature_length2476=== RUN TestExternalSignerErrors/exit_at_startup2477=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2478=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2479=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2481=== CONT TestExternalSignerRejectsInvalidPublicKey/#002482=== PAUSE TestExternalSignerErrors/exit_at_startup2483=== RUN TestExternalSignerErrors/wrong_signatures_shape2484=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2485=== RUN TestExternalSignerErrors/too_few_signatures2486=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2487=== RUN TestGenerateFingerprint/invalid_store_path_prefix2488=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2489=== RUN TestGenerateFingerprint/invalid_reference_prefix2490=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2491=== CONT TestGenerateFingerprint/basic_with_references2492=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2493=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2494=== CONT TestGenerateFingerprint/invalid_nar_hash_length2495=== RUN TestSignErrors/nil_key2496=== PAUSE TestSignErrors/nil_key2497=== CONT TestGenerateFingerprint/invalid_store_path_prefix2498=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2499=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2500=== PAUSE TestExternalSignerErrors/too_few_signatures2501=== RUN TestExternalSignerErrors/missing_signature_name2502=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2503=== CONT TestGenerateFingerprint/invalid_reference_prefix2504=== CONT TestGenerateFingerprint/no_references2505=== RUN TestSignErrors/nil_narinfo2506=== PAUSE TestSignErrors/nil_narinfo2507=== RUN TestSignErrors/invalid_narinfo2508=== PAUSE TestSignErrors/invalid_narinfo2509=== RUN TestSignErrors/canceled2510=== PAUSE TestSignErrors/canceled2511=== CONT TestSignErrors/nil_key2512=== PAUSE TestExternalSignerErrors/missing_signature_name2513=== RUN TestExternalSignerErrors/wrong_signature_name2514=== CONT TestSignErrors/invalid_narinfo2515=== CONT TestSignErrors/canceled2516=== PAUSE TestExternalSignerErrors/wrong_signature_name2517=== RUN TestExternalSignerErrors/exit_on_request2518--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2523 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2524--- PASS: TestSign (0.00s)2525=== CONT TestSignErrors/nil_narinfo2526=== PAUSE TestExternalSignerErrors/exit_on_request2527=== RUN TestExternalSignerErrors/invalid_JSON2528=== PAUSE TestExternalSignerErrors/invalid_JSON2529--- PASS: TestGenerateFingerprint (0.00s)2530 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2531 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2532 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2533 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2534 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2535 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2536 --- PASS: TestGenerateFingerprint/no_references (0.00s)2537=== RUN TestExternalSignerErrors/wrong_shape2538=== PAUSE TestExternalSignerErrors/wrong_shape2539=== CONT TestExternalSignerErrors/null2540=== CONT TestExternalSignerErrors/exit_at_startup2541=== CONT TestExternalSignerErrors/missing_signatures2542--- PASS: TestParseSigningKey (0.00s)2543 --- PASS: TestParseSigningKey/wrong_length (0.00s)2544 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2545 --- PASS: TestParseSigningKey/empty_name (0.00s)2546 --- PASS: TestParseSigningKey/no_colon (0.00s)2547 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2548 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2549=== CONT TestExternalSignerErrors/invalid_signature_base642550=== CONT TestExternalSignerErrors/wrong_signature_length2551=== CONT TestExternalSignerErrors/null_signatures2552=== CONT TestExternalSignerErrors/program_error2553=== CONT TestExternalSignerErrors/wrong_signature_name2554=== CONT TestExternalSignerErrors/wrong_shape2555=== CONT TestExternalSignerErrors/invalid_JSON2556=== CONT TestExternalSignerErrors/exit_on_request2557=== CONT TestExternalSignerErrors/wrong_id2558=== CONT TestExternalSignerErrors/unrequested_key2559=== CONT TestExternalSignerErrors/too_few_signatures2560=== CONT TestExternalSignerErrors/wrong_signatures_shape2561=== CONT TestExternalSignerErrors/missing_signature_name2562--- PASS: TestSignErrors (0.00s)2563 --- PASS: TestSignErrors/nil_key (0.00s)2564 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2565 --- PASS: TestSignErrors/canceled (0.00s)2566 --- PASS: TestSignErrors/nil_narinfo (0.00s)2567--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2568--- PASS: TestSignBatch (0.00s)2569--- PASS: TestExternalSignerClose (0.00s)2570--- PASS: TestExternalSignerWrongPublicKey (0.00s)2571--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2572--- PASS: TestExternalSigner (0.01s)2573--- PASS: TestExternalSignerErrors (0.00s)2574 --- PASS: TestExternalSignerErrors/null (0.00s)2575 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2576 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2577 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2578 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2579 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2580 --- PASS: TestExternalSignerErrors/program_error (0.01s)2581 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2582 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2583 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2584 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2585 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2586 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2587 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2588 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2589 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2590--- PASS: TestExternalSignerCancellation (0.02s)2591PASS2592Running OpenBao signer tests...2593=== RUN TestSign2594=== PAUSE TestSign2595=== RUN TestSignErrors2596=== PAUSE TestSignErrors2597=== RUN TestServe2598=== PAUSE TestServe2599=== RUN TestServeRejectsGarbage2600=== PAUSE TestServeRejectsGarbage2601=== CONT TestSign2602=== CONT TestServeRejectsGarbage2603=== CONT TestServe2604=== CONT TestSignErrors2605--- PASS: TestServeRejectsGarbage (0.00s)2606=== RUN TestSignErrors/http_error2607=== PAUSE TestSignErrors/http_error2608=== RUN TestSignErrors/invalid_json2609=== PAUSE TestSignErrors/invalid_json2610=== RUN TestSignErrors/no_prefix2611=== PAUSE TestSignErrors/no_prefix2612=== RUN TestSignErrors/invalid_base642613=== PAUSE TestSignErrors/invalid_base642614=== CONT TestSignErrors/http_error2615=== CONT TestSignErrors/no_prefix2616=== CONT TestSignErrors/invalid_json2617--- PASS: TestServe (0.00s)2618=== CONT TestSignErrors/invalid_base642619--- PASS: TestSign (0.00s)2620--- PASS: TestSignErrors (0.00s)2621 --- PASS: TestSignErrors/invalid_json (0.00s)2622 --- PASS: TestSignErrors/invalid_base64 (0.00s)2623 --- PASS: TestSignErrors/no_prefix (0.00s)2624 --- PASS: TestSignErrors/http_error (0.00s)2625PASS