niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #393
· 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 TestResolveStorePath101=== CONT TestScriptTokenScriptFails102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestStreamPushIsolatesFailures105=== CONT TestParsePathInfoJSON106=== RUN TestParsePathInfoJSON/Nix_format107=== PAUSE TestParsePathInfoJSON/Nix_format108=== RUN TestParsePathInfoJSON/Lix_format109=== PAUSE TestParsePathInfoJSON/Lix_format110=== RUN TestParsePathInfoJSON/empty_input111=== PAUSE TestParsePathInfoJSON/empty_input112=== RUN TestParsePathInfoJSON/whitespace_only113=== PAUSE TestParsePathInfoJSON/whitespace_only114=== RUN TestParsePathInfoJSON/invalid_JSON115=== PAUSE TestParsePathInfoJSON/invalid_JSON116--- PASS: TestResolveStorePath (0.00s)117=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess118=== CONT TestRateLimiterFeedback119=== RUN TestRateLimiterFeedback/429_enables_limiter120=== PAUSE TestRateLimiterFeedback/429_enables_limiter121=== RUN TestRateLimiterFeedback/503_enables_limiter122=== PAUSE TestRateLimiterFeedback/503_enables_limiter123=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter124=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter125=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter126=== CONT TestPathInfoCACompatibility127=== CONT TestParsePathInfoJSONMultiplePaths128=== CONT TestSetClientTLS129=== CONT TestScriptTokenBadJSON130=== CONT TestScriptTokenEmptyToken131=== CONT TestScriptTokenCachesUntilRefresh132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== CONT TestFileTokenEmpty134=== CONT TestFileTokenMissing135=== CONT TestDumpPathWriterError136=== CONT TestFileTokenReadsAndCaches137=== CONT TestStaticToken138=== CONT TestPathInfoHashCompatibility139=== CONT TestSetClientTLSErrors1402026/10/07 06:22:25 ERROR Upload failed error="bad path" count=3141=== CONT TestGetStorePathHash1422026/10/07 06:22:25 WARN Rate limiter enabled after throttle name=server-test rate=5143=== CONT TestSetClientTLSDoesNotMutateDefaultTransport144=== CONT TestConvertHashToNix32145=== CONT TestClientSignaturesByStorePath146--- PASS: TestClientSignaturesByStorePath (0.00s)147=== CONT TestEncodeNixBase32148=== RUN TestEncodeNixBase32/test_string_hash149=== PAUSE TestEncodeNixBase32/test_string_hash150=== RUN TestEncodeNixBase32/empty_input151=== PAUSE TestEncodeNixBase32/empty_input152=== RUN TestPathInfoCACompatibility/null_ca_field153--- PASS: TestStaticToken (0.00s)154=== PAUSE TestPathInfoCACompatibility/null_ca_field155=== RUN TestPathInfoCACompatibility/old_string_format_-_text156=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text157=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive158=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive159--- PASS: TestStreamPushIsolatesFailures (0.00s)160=== CONT TestDumpPathMatchesNix161=== CONT TestEncodeNixBase32WithRealHash162=== CONT TestStreamPushRequestLine163=== CONT TestStreamPushReportsSignatures164=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter165=== CONT TestStreamPushGivesUpOnDeadServer166=== RUN TestPathInfoCACompatibility/new_structured_format_-_text167--- PASS: TestScriptTokenScriptFails (0.00s)168=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text169=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method170=== RUN TestGetStorePathHash/valid_store_path171=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths172=== CONT TestDumpPathSingleFile173=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon177=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512180=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512181=== RUN TestConvertHashToNix32/SRI_format_to_Nix32182=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32183=== RUN TestConvertHashToNix32/already_Nix32_format184=== PAUSE TestConvertHashToNix32/already_Nix32_format185=== RUN TestConvertHashToNix32/invalid_format186=== PAUSE TestConvertHashToNix32/invalid_format187=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun188=== CONT TestUploadMultipart_SupersededByPeer189=== RUN TestUploadMultipart_SupersededByPeer/exists190--- PASS: TestEncodeNixBase32WithRealHash (0.00s)191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== RUN TestUploadMultipart_SupersededByPeer/missing193--- PASS: TestScriptTokenBadJSON (0.00s)194--- PASS: TestFileTokenMissing (0.00s)195=== CONT TestCaseHackSuffix196--- PASS: TestFileTokenReadsAndCaches (0.00s)197=== CONT TestShellSplitErrors198--- PASS: TestShellSplitErrors (0.00s)199=== CONT TestShellSplit200--- PASS: TestShellSplit (0.00s)201=== CONT TestStreamPushBatchesUnderLoad202=== RUN TestSetClientTLSErrors/missing_cert_file203=== PAUSE TestSetClientTLSErrors/missing_cert_file204=== RUN TestSetClientTLSErrors/missing_key_file205=== PAUSE TestSetClientTLSErrors/missing_key_file206=== RUN TestSetClientTLSErrors/missing_ca_file2072026/10/07 06:22:25 INFO Garbage collection started208=== CONT TestPartSizeForNAR209=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method210=== CONT TestDoWithRetry_BodyReplayedViaGetBody211=== PAUSE TestUploadMultipart_SupersededByPeer/missing212=== CONT TestStreamPushReportsEveryPath213--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)214=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths215=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths216=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2172026/10/07 06:22:25 ERROR Upload failed error=boom count=1218=== PAUSE TestGetStorePathHash/valid_store_path219=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica220=== CONT TestFilterOversizedClosures221--- PASS: TestStreamPushReportsSignatures (0.00s)222--- PASS: TestScriptTokenEmptyToken (0.01s)223=== CONT TestUploadMultipart_PartsInParallel2242026/10/07 06:22:25 ERROR Upload failed error="connection refused" count=202252026/10/07 06:22:25 ERROR Server seems unavailable, giving up on batch untried=17226=== CONT TestParsePathInfoJSON/Nix_format2272026/10/07 06:22:25 ERROR Upload failed error=boom count=1228=== RUN TestPartSizeForNAR/zero_stays_at_minimum229=== CONT TestRegisterUploadedObjectReusesConnections230=== RUN TestFilterOversizedClosures/no_limit_keeps_everything231=== PAUSE TestSetClientTLSErrors/missing_ca_file232--- PASS: TestFileTokenEmpty (0.01s)233--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)234=== RUN TestSetClientTLS/rejects_connection_without_client_cert235=== CONT TestParsePathInfoJSON/whitespace_only236=== CONT TestParsePathInfoJSON/Lix_format237=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert238=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA239=== CONT TestEncodeNixBase32/test_string_hash240=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum241=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA242=== RUN TestSetClientTLS/preserves_debug_logging_transport2432026/10/07 06:22:25 INFO Garbage collection started2442026/10/07 06:22:25 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=02452026/10/07 06:22:25 WARN Rate limiter enabled after throttle name=server-test rate=52462026/10/07 06:22:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:433672472026/10/07 06:22:25 WARN Rate limiter backed off name=server-test rate=52482026/10/07 06:22:25 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:43367249=== CONT TestParsePathInfoJSON/empty_input250=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha5122512026/10/07 06:22:25 WARN Garbage collection finished on another replica. Its statistics are not available here252=== CONT TestConvertHashToNix32/SRI_format_to_Nix32253=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon254=== CONT TestConvertHashToNix32/invalid_format255=== CONT TestConvertHashToNix32/already_Nix32_format256=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI257=== CONT TestUploadMultipart_SupersededByPeer/missing258=== CONT TestParsePathInfoJSON/invalid_JSON259=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths260=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths261=== CONT TestPathInfoCACompatibility/null_ca_field262=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestPathInfoCACompatibility/new_structured_format_-_text264=== CONT TestPathInfoCACompatibility/old_string_format_-_text265=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything268=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped269=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped270=== RUN TestFilterOversizedClosures/all_closures_skipped271=== PAUSE TestFilterOversizedClosures/all_closures_skipped272=== CONT TestFilterOversizedClosures/no_limit_keeps_everything273=== RUN TestSetClientTLSErrors/invalid_ca_file274=== PAUSE TestSetClientTLSErrors/invalid_ca_file275=== CONT TestSetClientTLSErrors/missing_cert_file276=== RUN TestGetStorePathHash/basename_without_hyphen_should_error277=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error278=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error279=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error280=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error281=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error282=== CONT TestEncodeNixBase32/empty_input283=== CONT TestGetStorePathHash/valid_store_path284=== CONT TestSetClientTLSErrors/missing_key_file285=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error286=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error287=== CONT TestGetStorePathHash/basename_without_hyphen_should_error288=== PAUSE TestSetClientTLS/preserves_debug_logging_transport289=== CONT TestSetClientTLS/rejects_connection_without_client_cert290=== CONT TestSetClientTLS/preserves_debug_logging_transport291=== CONT TestRateLimiterFeedback/429_enables_limiter292=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA293=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter294=== RUN TestPartSizeForNAR/small_stays_at_minimum295=== PAUSE TestPartSizeForNAR/small_stays_at_minimum296=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum297=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum298=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts299=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts300=== RUN TestPartSizeForNAR/1_TiB301=== PAUSE TestPartSizeForNAR/1_TiB302=== RUN TestPartSizeForNAR/5_TiB_S3_max_object303=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object304=== RUN TestPartSizeForNAR/capped_at_5_GiB305=== PAUSE TestPartSizeForNAR/capped_at_5_GiB306=== CONT TestPartSizeForNAR/zero_stays_at_minimum307=== CONT TestRateLimiterFeedback/503_enables_limiter308=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3102026/10/07 06:22:25 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=20003112026/10/07 06:22:25 WARN Rate limiter enabled after throttle name=server-test rate=53122026/10/07 06:22:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:44429313=== CONT TestPartSizeForNAR/capped_at_5_GiB314=== CONT TestPartSizeForNAR/5_TiB_S3_max_object315=== CONT TestPartSizeForNAR/1_TiB316=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts317=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum318=== CONT TestPartSizeForNAR/small_stays_at_minimum319=== CONT TestFilterOversizedClosures/all_closures_skipped3202026/10/07 06:22:25 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=50321=== CONT TestSetClientTLSErrors/invalid_ca_file3222026/10/07 06:22:25 WARN Rate limiter backed off name=server-test rate=5323=== CONT TestSetClientTLSErrors/missing_ca_file324--- PASS: TestStreamPushReportsEveryPath (0.00s)325--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)326--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)327--- PASS: TestDoServerRequestAttachesToken (0.04s)328--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)329--- PASS: TestConvertHashToNix32 (0.00s)330 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)331 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)332 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)333--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)334--- PASS: TestParsePathInfoJSON (0.00s)335 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)336 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)337 --- PASS: TestParsePathInfoJSON/Nix_format (0.03s)338 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)339 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)340--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)3432026/10/07 06:22:25 WARN Rate limiter enabled after throttle name=server-test rate=5344--- PASS: TestPathInfoCACompatibility (0.01s)345 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)346 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)347 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)349 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)3502026/10/07 06:22:25 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45203351--- PASS: TestDumpPathSingleFile (0.03s)352--- PASS: TestEncodeNixBase32 (0.00s)353 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)354 --- PASS: TestEncodeNixBase32/empty_input (0.00s)355--- PASS: TestGetStorePathHash (0.04s)356 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)357 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)359 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)360--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)361 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)362 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)363--- PASS: TestPathInfoHashCompatibility (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)365 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)366 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)367 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)368--- PASS: TestPartSizeForNAR (0.03s)369 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376--- PASS: TestFilterOversizedClosures (0.03s)377 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)378 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)379 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)3802026/10/07 06:22:25 WARN Rate limiter backed off name=server-test rate=5381--- PASS: TestSetClientTLSErrors (0.04s)382 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)384 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)385 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)386=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter387--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)388--- PASS: TestRateLimiterFeedback (0.00s)389 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)392 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)3932026/10/07 06:22:25 http: TLS handshake error from 127.0.0.1:35084: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.04s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)398--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)399--- PASS: TestCaseHackSuffix (0.06s)400--- PASS: TestDumpPathWriterError (0.07s)401--- PASS: TestStreamPushRequestLine (0.07s)402--- PASS: TestDumpPathMatchesNix (0.10s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2423869298/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/postgres2423869298/data -l logfile start434435/build/postgres2423869298:5432 - no response4362026-10-07 06:22:27.327 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-07 06:22:27.327 UTC [128] LOG: listening on Unix socket "/build/postgres2423869298/.s.PGSQL.5432"4382026-10-07 06:22:27.331 UTC [135] LOG: database system was shut down at 2026-10-07 06:22:27 UTC4392026-10-07 06:22:27.335 UTC [128] LOG: database system is ready to accept connections440/build/postgres2423869298:5432 - accepting connections441{"timestamp":"2026-10-07T06:22:27.5250106Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"40e2f70a-23d6-4293-827d-ab06e10f2d22","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 TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/07 06:22:27 INFO lead: acquired remote=192.0.2.1:12344902026/10/07 06:22:28 INFO lead: released remote=192.0.2.1:12344912026/10/07 06:22:28 INFO lead: acquired remote=192.0.2.1:12344922026/10/07 06:22:29 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.87s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/07 06:22:29 INFO lead: acquired remote=192.0.2.1:12345002026-10-07 06:22:31.008 UTC [379] FATAL: terminating connection due to administrator command5012026/10/07 06:22:31 INFO lead: acquired remote=192.0.2.1:12345022026/10/07 06:22:32 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/07 06:22:32 INFO lead: released remote=192.0.2.1:12345042026/10/07 06:22:32 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestMetricsCommit575=== PAUSE TestMetricsCommit576=== RUN TestService_NativeMTLS577=== PAUSE TestService_NativeMTLS578=== RUN TestServerTLSConfig579=== PAUSE TestServerTLSConfig580=== RUN TestMultipartCleanup581=== PAUSE TestMultipartCleanup582=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded584=== RUN TestPendingCleanupUsesOneCutoff585=== PAUSE TestPendingCleanupUsesOneCutoff586=== RUN TestObjectStatsTrigger587=== PAUSE TestObjectStatsTrigger588=== RUN TestObjectStatsLargeCommit589=== PAUSE TestObjectStatsLargeCommit590=== RUN TestOrphanedObjectsGC591=== PAUSE TestOrphanedObjectsGC592=== RUN TestOrphanedObjectsGCStressTest593=== PAUSE TestOrphanedObjectsGCStressTest594=== RUN TestCreatePin_ReservedPins595=== PAUSE TestCreatePin_ReservedPins596=== RUN TestPresentReportsOnlyClosureRoots597=== PAUSE TestPresentReportsOnlyClosureRoots598=== RUN TestPresentRefreshesOnlyStaleClosures599=== PAUSE TestPresentRefreshesOnlyStaleClosures600=== RUN TestPresentNotReportedWhileGCDeletesClosure601=== PAUSE TestPresentNotReportedWhileGCDeletesClosure602=== RUN TestParseSingleRange603=== PAUSE TestParseSingleRange604=== RUN TestProxyHeadersOnlyTrustedOnSocket6052026/10/07 06:22:32 INFO Starting HTTP server address=127.0.0.1:401116062026/10/07 06:22:32 INFO Starting HTTP server address=proxy.sock6072026/10/07 06:22:32 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6082026/10/07 06:22:32 INFO Shutdown signal received, draining in-flight requests timeout=10s609--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)610=== RUN TestIsValidCachePath611=== PAUSE TestIsValidCachePath612=== RUN TestReadProxyNarinfo613=== PAUSE TestReadProxyNarinfo614=== RUN TestReadProxyNarinfoAlreadyDecompressed615=== PAUSE TestReadProxyNarinfoAlreadyDecompressed616=== RUN TestReadProxyContentNegotiation617=== PAUSE TestReadProxyContentNegotiation618=== RUN TestReadProxyNarStreaming619=== PAUSE TestReadProxyNarStreaming620=== RUN TestReadProxy404621=== PAUSE TestReadProxy404622=== RUN TestReadProxyInvalidPath623=== PAUSE TestReadProxyInvalidPath624=== RUN TestReadProxyHead625=== PAUSE TestReadProxyHead626=== RUN TestReadProxyOutlastsServerWriteTimeout627=== PAUSE TestReadProxyOutlastsServerWriteTimeout628=== RUN TestReadProxyConditionalGet629=== PAUSE TestReadProxyConditionalGet630=== RUN TestReadProxyRootRedirectsToIndexHTML631=== PAUSE TestReadProxyRootRedirectsToIndexHTML632=== RUN TestReadProxyDisabled633=== PAUSE TestReadProxyDisabled634=== RUN TestReadRedirectNar635=== PAUSE TestReadRedirectNar636=== RUN TestReadRedirectKeepsNarinfoProxied637=== PAUSE TestReadRedirectKeepsNarinfoProxied638=== RUN TestReadProxyRangeRequest639=== PAUSE TestReadProxyRangeRequest640=== RUN TestReadRedirectUsesPublicS3URL641=== PAUSE TestReadRedirectUsesPublicS3URL642=== RUN TestPush_OverlappingRootsStoreOneRowPerKey643=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey644=== RUN TestPush_CompleteCommitsEveryRoot645=== PAUSE TestPush_CompleteCommitsEveryRoot646=== RUN TestPush_RepeatedRootCommitsOnce647=== PAUSE TestPush_RepeatedRootCommitsOnce648=== RUN TestPush_CompleteWaitsForCleanupOfThePush649=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush650=== RUN TestPush_RootsAreLockedInByteOrder651=== PAUSE TestPush_RootsAreLockedInByteOrder652=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit653=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit654=== RUN TestPush_RejectsBadRequests655=== PAUSE TestPush_RejectsBadRequests656=== RUN TestPush_SignsNarinfosOfItsPendingObjects657=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects658=== RUN TestRedundantMultipartUpload659=== PAUSE TestRedundantMultipartUpload660=== RUN TestCompleteMultipartUpload_ErrorButObjectExists661=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists662=== RUN TestCompletedNarNotReofferedAcrossClosures663=== PAUSE TestCompletedNarNotReofferedAcrossClosures664=== RUN TestPresignedUploadRegisteredBeforeCommit665=== PAUSE TestPresignedUploadRegisteredBeforeCommit666=== RUN TestService_Rustfstest667=== PAUSE TestService_Rustfstest668=== RUN TestParseSize669=== PAUSE TestParseSize670=== RUN TestSkippedUploadsHandler671=== PAUSE TestSkippedUploadsHandler672=== RUN TestSystemdListenerNotActivated673--- PASS: TestSystemdListenerNotActivated (0.00s)674=== RUN TestWatchdogBeatsWhenHealthy675--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)676=== RUN TestWatchdogSkipsWhenUnhealthy6772026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6792026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6802026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6812026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/07 06:22:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"687--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)688=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle689=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle690=== RUN TestProxyWriteTimeout691=== PAUSE TestProxyWriteTimeout692=== RUN TestPendingClosureWriteTimeout693=== PAUSE TestPendingClosureWriteTimeout694=== RUN TestIsValidUploadKey695=== PAUSE TestIsValidUploadKey696=== RUN TestUploadHandlersRejectInvalidKeys697=== PAUSE TestUploadHandlersRejectInvalidKeys698=== RUN TestUploadHandlersRejectOversizedBody699=== PAUSE TestUploadHandlersRejectOversizedBody700=== RUN TestService_cleanupPendingClosuresHandler701=== PAUSE TestService_cleanupPendingClosuresHandler702=== RUN TestService_createPendingClosureHandler703=== PAUSE TestService_createPendingClosureHandler704=== RUN TestService_verifyS3Integrity705=== PAUSE TestService_verifyS3Integrity706=== RUN TestCompleteMultipartUnregistered707=== PAUSE TestCompleteMultipartUnregistered708=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT709=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT710=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle711=== CONT TestService_AuthMiddleware712=== CONT TestSkippedUploadsHandler713=== CONT TestGracefulShutdownDrainsInflight714=== CONT TestGCTaskStore_Fail715--- PASS: TestGCTaskStore_Fail (0.00s)716=== CONT TestPresignedUploadRegisteredBeforeCommit717=== CONT TestGCTaskStore_PhaseUpdates718--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)719=== CONT TestGCTaskStore_CompletedAllowsNewTask720--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)721=== CONT TestCompletedNarNotReofferedAcrossClosures722=== CONT TestIsValidCachePath7232026/10/07 06:22:32 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000724=== CONT TestGCTaskStore_GetReturnsLatest725--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)726=== CONT TestParseSingleRange7272026/10/07 06:22:32 INFO Starting HTTP server address=127.0.0.1:39413728=== CONT TestGCTaskStore_GetEmpty729--- PASS: TestGCTaskStore_GetEmpty (0.00s)730=== RUN TestParseSingleRange/none731=== PAUSE TestParseSingleRange/none732=== RUN TestParseSingleRange/unknown_unit733=== PAUSE TestParseSingleRange/unknown_unit734=== RUN TestParseSingleRange/multi-range_ignored735=== PAUSE TestParseSingleRange/multi-range_ignored736=== RUN TestParseSingleRange/malformed_no_dash737=== PAUSE TestParseSingleRange/malformed_no_dash738=== RUN TestParseSingleRange/malformed_both_empty739=== PAUSE TestParseSingleRange/malformed_both_empty740=== RUN TestParseSingleRange/malformed_end_before_start741=== PAUSE TestParseSingleRange/malformed_end_before_start742=== RUN TestParseSingleRange/closed743=== PAUSE TestParseSingleRange/closed744=== CONT TestCompleteMultipartUpload_ErrorButObjectExists745=== CONT TestService_healthCheckHandler746=== CONT TestGCTaskStore_StartNew7472026/10/07 06:22:32 INFO Shutdown signal received, draining in-flight requests timeout=10s748--- PASS: TestGCTaskStore_StartNew (0.00s)749=== CONT TestParseSize750=== CONT TestGCEndsOnShutdown751=== CONT TestReadProxyContentNegotiation752=== CONT TestCommitRacingPendingCleanupKeepsObjects753=== CONT TestReadProxyNarinfoAlreadyDecompressed754=== CONT TestPushWaitsForSweepHoldingRow755=== CONT TestReadProxyNarStreaming756=== CONT TestSweepRechecksPendingAfterLocking757=== CONT TestService_Rustfstest758=== CONT TestReadProxyNarinfo759=== CONT TestGetExistingObjectsLocksRows760=== RUN TestIsValidCachePath/narinfo761=== PAUSE TestIsValidCachePath/narinfo762=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars763=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars764=== RUN TestIsValidCachePath/nar_zst765=== PAUSE TestIsValidCachePath/nar_zst766=== RUN TestIsValidCachePath/nar_xz767=== PAUSE TestIsValidCachePath/nar_xz768=== RUN TestIsValidCachePath/nar_bz2769=== PAUSE TestIsValidCachePath/nar_bz2770=== RUN TestIsValidCachePath/nar_uncompressed771=== PAUSE TestIsValidCachePath/nar_uncompressed772=== RUN TestIsValidCachePath/ls773=== PAUSE TestIsValidCachePath/ls774=== RUN TestIsValidCachePath/log775=== PAUSE TestIsValidCachePath/log776=== RUN TestIsValidCachePath/realisation777=== PAUSE TestIsValidCachePath/realisation778=== RUN TestIsValidCachePath/nix-cache-info779=== PAUSE TestIsValidCachePath/nix-cache-info780=== RUN TestIsValidCachePath/index.html781=== PAUSE TestIsValidCachePath/index.html782=== RUN TestIsValidCachePath/traversal_parent783=== PAUSE TestIsValidCachePath/traversal_parent784=== RUN TestIsValidCachePath/traversal_in_middle785=== PAUSE TestIsValidCachePath/traversal_in_middle786=== RUN TestIsValidCachePath/invalid_char_e787=== PAUSE TestIsValidCachePath/invalid_char_e788=== RUN TestIsValidCachePath/invalid_char_u789=== PAUSE TestIsValidCachePath/invalid_char_u790=== RUN TestIsValidCachePath/random_path791=== PAUSE TestIsValidCachePath/random_path792=== RUN TestIsValidCachePath/empty793=== PAUSE TestIsValidCachePath/empty794=== RUN TestIsValidCachePath/leading_slash795=== PAUSE TestIsValidCachePath/leading_slash796=== RUN TestIsValidCachePath/wrong_extension797=== PAUSE TestIsValidCachePath/wrong_extension798=== RUN TestIsValidCachePath/short_hash799=== PAUSE TestIsValidCachePath/short_hash800=== CONT TestGCTaskStore_ConflictDifferentParams801=== CONT TestPush_SignsNarinfosOfItsPendingObjects802=== RUN TestGCEndsOnShutdown/before_the_run803=== PAUSE TestGCEndsOnShutdown/before_the_run804=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete805=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete806=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark807=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark808=== CONT TestRegisterCompletedObjectNeedsPendingRow809=== CONT TestPresentRefreshesOnlyStaleClosures810=== CONT TestGCTaskStore_DeduplicateSameParams811=== CONT TestPresentReportsOnlyClosureRoots812=== RUN TestParseSingleRange/open-ended813=== CONT TestRedundantMultipartUpload814--- PASS: TestParseSize (0.00s)815=== CONT TestPresentNotReportedWhileGCDeletesClosure816=== CONT TestPush_RejectsBadRequests817=== PAUSE TestParseSingleRange/open-ended818=== RUN TestParseSingleRange/end_clamped_to_size819=== PAUSE TestParseSingleRange/end_clamped_to_size820=== RUN TestParseSingleRange/suffix821=== PAUSE TestParseSingleRange/suffix822=== RUN TestParseSingleRange/suffix_exceeds_size823--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)824=== PAUSE TestParseSingleRange/suffix_exceeds_size825=== RUN TestParseSingleRange/single_byte826=== PAUSE TestParseSingleRange/single_byte827=== RUN TestParseSingleRange/start_past_EOF828=== PAUSE TestParseSingleRange/start_past_EOF829=== RUN TestParseSingleRange/start_far_past_EOF830=== PAUSE TestParseSingleRange/start_far_past_EOF831=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale832=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale833=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh834=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh835--- PASS: TestSkippedUploadsHandler (0.00s)836--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)837=== CONT TestSweepSkipsRowsLockedByPush838=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit839=== CONT TestCreatePin_ReservedPins840--- PASS: TestGracefulShutdownDrainsInflight (0.07s)8412026/10/07 06:22:33 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"842--- PASS: TestService_AuthMiddleware (0.25s)843=== CONT TestPush_RootsAreLockedInByteOrder8442026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures845--- PASS: TestService_Rustfstest (0.29s)846=== CONT TestFailedS3DeleteKeepsTombstone8472026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures8482026/10/07 06:22:33 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8492026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures850--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.33s)851=== CONT TestOrphanedObjectsGCStressTest8522026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures8532026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=08542026/10/07 06:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8552026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period8562026/10/07 06:22:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43835/oidc857--- PASS: TestService_healthCheckHandler (0.35s)858=== CONT TestPush_CompleteWaitsForCleanupOfThePush8592026/10/07 06:22:33 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=08602026/10/07 06:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8612026/10/07 06:22:33 INFO Vacuumed table table=pending_closures8622026/10/07 06:22:33 INFO Vacuumed table table=pending_objects8632026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads8642026/10/07 06:22:33 INFO Vacuumed table table=closures8652026/10/07 06:22:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjE2NDMwYjNiLTA0ODAtNDMzNy1hOGVhLTFiZGVlYmI5ZjQ2ZngxNzkxMzU0MTUzMjcwMDUzNDU48662026/10/07 06:22:33 INFO Vacuumed table table=objects867--- PASS: TestSweepRechecksPendingAfterLocking (0.36s)868=== CONT TestForceGCDuringPushOffersSweptObject869=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows870=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows871=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check872=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check873=== CONT TestPush_RepeatedRootCommitsOnce8742026/10/07 06:22:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjE2NDMwYjNiLTA0ODAtNDMzNy1hOGVhLTFiZGVlYmI5ZjQ2ZngxNzkxMzU0MTUzMjcwMDUzNDU4 parts=1875--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.37s)876=== CONT TestMetricsCommit877--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.39s)878=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection879--- PASS: TestReadProxyNarStreaming (0.43s)880=== CONT TestPush_CompleteCommitsEveryRoot8812026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures882--- PASS: TestReadProxyContentNegotiation (0.46s)883=== CONT TestMetricsInventory8842026/10/07 06:22:33 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>885--- PASS: TestReadProxyNarinfo (0.47s)886=== CONT TestGCSweepDeliversEachKeyOnce8872026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=08892026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period8902026/10/07 06:22:33 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=08912026/10/07 06:22:33 INFO Vacuumed table table=pending_closures8922026/10/07 06:22:33 INFO Vacuumed table table=pending_objects8932026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads8942026/10/07 06:22:33 INFO Vacuumed table table=closures8952026/10/07 06:22:33 INFO Vacuumed table table=objects896--- PASS: TestGetExistingObjectsLocksRows (0.51s)897=== CONT TestTombstonedObjectOfferedWithoutWaiting898--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.51s)899=== CONT TestNARDeduplicationMetadataUploadBug900--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.52s)901=== CONT TestReadRedirectUsesPublicS3URL9022026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes9032026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete9042026/10/07 06:22:33 INFO Completed push id=1 objects=4 duration=13.537459ms9052026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes906--- PASS: TestPresentRefreshesOnlyStaleClosures (0.57s)907=== CONT TestGCSweepSkipsPendingObjects908=== RUN TestPush_RejectsBadRequests/root_not_in_objects909=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects910=== RUN TestPush_RejectsBadRequests/no_roots911=== PAUSE TestPush_RejectsBadRequests/no_roots912=== RUN TestPush_RejectsBadRequests/no_objects913=== PAUSE TestPush_RejectsBadRequests/no_objects914=== RUN TestPush_RejectsBadRequests/bad_root915=== PAUSE TestPush_RejectsBadRequests/bad_root916=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9172026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=09182026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period9192026/10/07 06:22:33 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=09202026/10/07 06:22:33 INFO Vacuumed table table=pending_closures9212026/10/07 06:22:33 INFO Vacuumed table table=pending_objects9222026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads9232026/10/07 06:22:33 INFO Vacuumed table table=closures9242026/10/07 06:22:33 INFO Vacuumed table table=objects9252026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes9262026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=09272026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period9282026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9292026/10/07 06:22:33 INFO Signed narinfos id=1 count=19302026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9312026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9322026/10/07 06:22:33 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9332026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9342026/10/07 06:22:33 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9352026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9362026/10/07 06:22:33 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19372026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9382026/10/07 06:22:33 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo939--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.63s)940=== CONT TestReadProxyRangeRequest9412026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=09422026/10/07 06:22:33 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=09432026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/07 06:22:33 INFO Vacuumed table table=pending_closures9452026/10/07 06:22:33 INFO Vacuumed table table=pending_objects9462026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads9472026/10/07 06:22:33 INFO Vacuumed table table=closures9482026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period9492026/10/07 06:22:33 INFO Vacuumed table table=objects950--- PASS: TestSweepSkipsRowsLockedByPush (0.64s)951=== CONT TestDeduplicatedObjectsRecordedAsPending9522026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/07 06:22:33 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=09542026/10/07 06:22:33 INFO Vacuumed table table=pending_closures9552026/10/07 06:22:33 INFO Vacuumed table table=pending_objects9562026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads9572026/10/07 06:22:33 INFO Vacuumed table table=closures9582026/10/07 06:22:33 INFO Vacuumed table table=objects9592026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/2/complete960--- PASS: TestPresentReportsOnlyClosureRoots (0.66s)961=== CONT TestCreatePendingClosureRejectsOversizedNAR9622026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures963--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)964=== CONT TestReadRedirectKeepsNarinfoProxied9652026/10/07 06:22:33 INFO Completed push id=2 objects=4 duration=3.139647ms966--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.66s)967=== CONT TestPushDedupSurvivesConcurrentGC9682026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes9692026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures9702026-10-07 06:22:33.641 UTC [552] ERROR: could not obtain lock on row in relation "closures"9712026-10-07 06:22:33.641 UTC [552] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9722026-10-07 06:22:33.641 UTC [552] ERROR: could not obtain lock on row in relation "closures"9732026-10-07 06:22:33.641 UTC [552] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9742026-10-07 06:22:33.641 UTC [552] ERROR: could not obtain lock on row in relation "closures"9752026-10-07 06:22:33.641 UTC [552] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9762026-10-07 06:22:33.642 UTC [552] ERROR: could not obtain lock on row in relation "closures"9772026-10-07 06:22:33.642 UTC [552] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9782026-10-07 06:22:33.642 UTC [552] ERROR: could not obtain lock on row in relation "closures"9792026-10-07 06:22:33.642 UTC [552] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT980--- PASS: TestPush_RootsAreLockedInByteOrder (0.47s)981=== CONT TestCacheConfigHandlerMaxNarSize982--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)983=== CONT TestReadRedirectNar9842026/10/07 06:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9852026/10/07 06:22:33 WARN Refused reserved pin name=worker-x86_64-linux9862026/10/07 06:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9872026/10/07 06:22:33 INFO Received create pin request method=POST path=/api/pins/my-app9882026/10/07 06:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux989--- PASS: TestCreatePin_ReservedPins (0.67s)990=== CONT TestGenerateLandingPage991--- PASS: TestGenerateLandingPage (0.00s)992=== CONT TestReadProxyDisabled9932026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes9942026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=09952026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes9962026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period9972026/10/07 06:22:33 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9982026/10/07 06:22:33 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."999--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)1000=== CONT TestGCMetrics10012026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10022026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes10032026/10/07 06:22:33 INFO Completed push id=1 objects=4 duration=9.11478ms1004--- PASS: TestPush_RepeatedRootCommitsOnce (0.44s)1005=== CONT TestReadProxyRootRedirectsToIndexHTML10062026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10072026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/07 06:22:33 INFO Completed push id=1 objects=4 duration=9.668505ms10092026/10/07 06:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10102026/10/07 06:22:33 INFO Completed upload id=2 objects=2 duration=1.629554ms10112026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes1012--- PASS: TestMetricsCommit (0.47s)1013=== CONT TestService_readinessHandler10142026/10/07 06:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10152026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10162026/10/07 06:22:33 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LmJkYzk4OTYwLTQzMzMtNGM0OS05NTcwLTgxMTc5ZmY3ZDBjZXgxNzkxMzU0MTUzNDE5NjAzNzE3 parts=1210172026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/07 06:22:33 INFO Completed push id=1 objects=6 duration=9.117941ms1019--- PASS: TestPush_CompleteCommitsEveryRoot (0.44s)1020=== CONT TestReadProxyConditionalGet1021--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.87s)1022=== CONT TestGCBugBareHashReferences1023--- PASS: TestMetricsInventory (0.41s)1024=== CONT TestReadProxyOutlastsServerWriteTimeout10252026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=010262026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period10272026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures10282026/10/07 06:22:33 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=010292026/10/07 06:22:33 INFO Vacuumed table table=pending_closures10302026/10/07 06:22:33 INFO Vacuumed table table=pending_objects10312026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads10322026/10/07 06:22:33 INFO Vacuumed table table=closures1033--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1034=== CONT TestGCAdvisoryLockBlocksConcurrentRun10352026/10/07 06:22:33 INFO Vacuumed table table=objects1036--- PASS: TestPushWaitsForSweepHoldingRow (0.94s)1037=== CONT TestReadProxyHead1038--- PASS: TestGCSweepDeliversEachKeyOnce (0.48s)1039=== CONT TestReadProxyInvalidPath1040=== NAME TestNARDeduplicationMetadataUploadBug1041 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3626379068/001/store/nj8hgh6zy4izqfmn62c8z8r3b3bxcv2v-file1.txt1042--- PASS: TestReadRedirectUsesPublicS3URL (0.45s)1043=== CONT TestLeadEndsOnShutdown10442026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures10452026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes10462026/10/07 06:22:33 INFO Aborted multipart uploads count=0 kept=010472026/10/07 06:22:33 WARN Force mode enabled - objects will be deleted immediately without grace period10482026/10/07 06:22:33 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=01049--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.43s)10502026/10/07 06:22:33 INFO Vacuumed table table=pending_closures1051=== CONT TestReadProxy40410522026/10/07 06:22:33 INFO Vacuumed table table=pending_objects10532026/10/07 06:22:33 INFO Vacuumed table table=multipart_uploads10542026/10/07 06:22:33 INFO Received push request method=POST path=/api/pushes10552026/10/07 06:22:33 INFO Vacuumed table table=closures10562026/10/07 06:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10572026/10/07 06:22:33 INFO Vacuumed table table=objects10582026/10/07 06:22:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10592026/10/07 06:22:33 INFO Uploading nj8hgh6zy4izqfmn62c8z8r3b3bxcv2v-file1.txt (160B)1060--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.64s)1061=== CONT TestService_cleanupPendingClosuresHandler1062--- PASS: TestReadProxyRangeRequest (0.41s)1063=== CONT TestLeadIncumbentAnnouncesAtOnce1064--- PASS: TestGCSweepSkipsPendingObjects (0.47s)1065=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10662026/10/07 06:22:33 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10672026/10/07 06:22:33 WARN Failed to register uploaded object key=nj8hgh6zy4izqfmn62c8z8r3b3bxcv2v.ls error="server returned 404: 404 page not found\n"10682026/10/07 06:22:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10692026/10/07 06:22:33 INFO Signed narinfos id=1 count=110702026/10/07 06:22:33 INFO Uploading 1 narinfos10712026/10/07 06:22:33 INFO Received complete push request method=POST path=/api/pushes/1/complete10722026/10/07 06:22:33 WARN Failed to register uploaded object key=nj8hgh6zy4izqfmn62c8z8r3b3bxcv2v.narinfo error="server returned 404: 404 page not found\n"10732026/10/07 06:22:33 INFO Completed push id=1 objects=3 duration=6.043953ms10742026/10/07 06:22:33 INFO Upload complete. (58ms)1075=== NAME TestNARDeduplicationMetadataUploadBug1076 metadata_upload_test.go:54: Retrieved narinfo from S3:1077 StorePath: /build/TestNARDeduplicationMetadataUploadBug3626379068/001/store/nj8hgh6zy4izqfmn62c8z8r3b3bxcv2v-file1.txt1078 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1079 Compression: zstd1080 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1081 NarSize: 1601082 References: 1083 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10842026/10/07 06:22:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjYwZjg0YjY1LThmYjYtNDdkNi05ZjQyLWRmMjM2MGY2ZDM1MHgxNzkxMzU0MTUzNTc1MTg5MDI5 parts=1210852026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures1087 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1088 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1089 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10902026/10/07 06:22:33 INFO Received uploads request method=POST path=/api/pending_closures1091--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.42s)1092=== CONT TestIsValidUploadKey1093=== RUN TestIsValidUploadKey/narinfo1094=== PAUSE TestIsValidUploadKey/narinfo1095=== RUN TestIsValidUploadKey/nar_zst1096=== PAUSE TestIsValidUploadKey/nar_zst1097=== RUN TestIsValidUploadKey/nar_xz1098=== PAUSE TestIsValidUploadKey/nar_xz1099=== RUN TestIsValidUploadKey/nar_plain1100=== PAUSE TestIsValidUploadKey/nar_plain1101=== RUN TestIsValidUploadKey/listing1102=== PAUSE TestIsValidUploadKey/listing1103=== RUN TestIsValidUploadKey/build_log1104=== PAUSE TestIsValidUploadKey/build_log1105=== RUN TestIsValidUploadKey/build_log_home-manager_file1106=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1107=== RUN TestIsValidUploadKey/build_log_plus_in_name1108=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1109=== RUN TestIsValidUploadKey/build_log_question_mark1110=== PAUSE TestIsValidUploadKey/build_log_question_mark1111=== RUN TestIsValidUploadKey/build_log_equals1112=== PAUSE TestIsValidUploadKey/build_log_equals1113=== RUN TestIsValidUploadKey/realisation1114=== PAUSE TestIsValidUploadKey/realisation1115=== RUN TestIsValidUploadKey/realisation_plus_in_output1116=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1117=== RUN TestIsValidUploadKey/nix-cache-info1118=== PAUSE TestIsValidUploadKey/nix-cache-info1119=== RUN TestIsValidUploadKey/index.html1120=== PAUSE TestIsValidUploadKey/index.html1121=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1122=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1123=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1124=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1125=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1126=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1127=== RUN TestIsValidUploadKey/traversal1128=== PAUSE TestIsValidUploadKey/traversal1129=== RUN TestIsValidUploadKey/traversal_nar1130=== PAUSE TestIsValidUploadKey/traversal_nar1131=== RUN TestIsValidUploadKey/absolute1132=== PAUSE TestIsValidUploadKey/absolute1133=== RUN TestIsValidUploadKey/empty_key1134=== PAUSE TestIsValidUploadKey/empty_key1135=== RUN TestIsValidUploadKey/unknown_type1136=== PAUSE TestIsValidUploadKey/unknown_type1137=== CONT TestLeadElectsOneAndHandsOver11382026-10-07 06:22:34.011 UTC [565] ERROR: Push does not exist: id=111392026-10-07 06:22:34.011 UTC [565] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11402026-10-07 06:22:34.011 UTC [565] STATEMENT: SELECT commit_push($1)1141--- PASS: TestReadRedirectKeepsNarinfoProxied (0.42s)1142=== CONT TestCompleteMultipartUnregistered1143--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.73s)1144=== CONT TestConnectWaitsForAPeerMigration1145=== NAME TestNARDeduplicationMetadataUploadBug1146 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3626379068/001/store/89b1736jsphn8bcd5wq7650fsdlz50aw-file2.txt11472026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures1148--- PASS: TestReadRedirectNar (0.41s)1149=== CONT TestService_verifyS3Integrity1150--- PASS: TestReadProxyDisabled (0.39s)1151=== CONT TestResolveDBConnectionString1152=== RUN TestResolveDBConnectionString/flag_wins1153=== PAUSE TestResolveDBConnectionString/flag_wins1154=== RUN TestResolveDBConnectionString/file_when_flag_empty1155=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1156=== RUN TestResolveDBConnectionString/missing_file_is_an_error1157=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1158=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1159=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1160=== RUN TestResolveDBConnectionString/nothing_configured1161=== PAUSE TestResolveDBConnectionString/nothing_configured1162=== CONT TestService_createPendingClosureHandler11632026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes11642026/10/07 06:22:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11652026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11662026/10/07 06:22:34 WARN Failed to register uploaded object key=89b1736jsphn8bcd5wq7650fsdlz50aw.ls error="server returned 404: 404 page not found\n"11672026/10/07 06:22:34 INFO Signed narinfos id=2 count=111682026/10/07 06:22:34 INFO Uploading 1 narinfos11692026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=011702026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/2/complete11712026/10/07 06:22:34 WARN Failed to register uploaded object key=89b1736jsphn8bcd5wq7650fsdlz50aw.narinfo error="server returned 404: 404 page not found\n"11722026/10/07 06:22:34 INFO Completed push id=2 objects=3 duration=2.682124ms11732026/10/07 06:22:34 INFO Upload complete. (53ms)1174=== NAME TestNARDeduplicationMetadataUploadBug1175 metadata_upload_test.go:76: Retrieved narinfo from S3:1176 StorePath: /build/TestNARDeduplicationMetadataUploadBug3626379068/001/store/89b1736jsphn8bcd5wq7650fsdlz50aw-file2.txt1177 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1178 Compression: zstd1179 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1180 NarSize: 1601181 References: 1182 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1183 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1184 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1185 {"version":1,"root":{"type":"regular","size":44}}11862026/10/07 06:22:34 WARN Force mode enabled - objects will be deleted immediately without grace period1187--- PASS: TestNARDeduplicationMetadataUploadBug (0.67s)1188=== CONT TestUploadHandlersRejectOversizedBody11892026/10/07 06:22:34 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=011902026/10/07 06:22:34 INFO Vacuumed table table=pending_closures11912026/10/07 06:22:34 INFO Vacuumed table table=pending_objects11922026/10/07 06:22:34 INFO Vacuumed table table=multipart_uploads11932026/10/07 06:22:34 INFO Vacuumed table table=closures11942026/10/07 06:22:34 INFO Vacuumed table table=objects1195--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.39s)1196=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11972026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=01198--- PASS: TestGCMetrics (0.40s)1199=== CONT TestService_NativeMTLS12002026/10/07 06:22:34 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=012012026/10/07 06:22:34 WARN readiness check failed error="closed pool"1202--- PASS: TestService_readinessHandler (0.37s)1203=== CONT TestPendingClosureWriteTimeout1204=== RUN TestPendingClosureWriteTimeout/empty1205=== PAUSE TestPendingClosureWriteTimeout/empty1206=== RUN TestPendingClosureWriteTimeout/400_objects1207=== PAUSE TestPendingClosureWriteTimeout/400_objects1208=== RUN TestPendingClosureWriteTimeout/670k_objects1209=== PAUSE TestPendingClosureWriteTimeout/670k_objects12102026/10/07 06:22:34 INFO Vacuumed table table=pending_closures1211=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1212=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1213=== CONT TestUploadHandlersRejectInvalidKeys1214=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1215=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1216=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1217=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1218=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1219=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1220=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1221=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1222=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12232026/10/07 06:22:34 INFO Vacuumed table table=pending_objects12242026/10/07 06:22:34 INFO Vacuumed table table=multipart_uploads12252026/10/07 06:22:34 INFO Vacuumed table table=closures12262026/10/07 06:22:34 INFO Vacuumed table table=objects12272026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=012282026/10/07 06:22:34 WARN Force mode enabled - objects will be deleted immediately without grace period12292026/10/07 06:22:34 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=012302026/10/07 06:22:34 INFO Vacuumed table table=pending_closures12312026/10/07 06:22:34 INFO Vacuumed table table=pending_objects12322026/10/07 06:22:34 INFO Vacuumed table table=multipart_uploads12332026/10/07 06:22:34 INFO Vacuumed table table=closures12342026/10/07 06:22:34 INFO Vacuumed table table=objects1235--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1236=== CONT TestMultipartCleanup1237--- PASS: TestReadProxyConditionalGet (0.37s)1238=== CONT TestClientCADerivations1239=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1240=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1241=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1242=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1243=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1244=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1245=== CONT TestServerTLSConfig1246=== RUN TestServerTLSConfig/no_client_CA1247=== PAUSE TestServerTLSConfig/no_client_CA1248=== RUN TestServerTLSConfig/missing_CA_file1249=== PAUSE TestServerTLSConfig/missing_CA_file1250=== RUN TestServerTLSConfig/not_a_PEM_file1251=== PAUSE TestServerTLSConfig/not_a_PEM_file1252=== CONT TestClientFallsBackToClosures12532026/10/07 06:22:34 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"1254--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.43s)1255=== CONT TestObjectStatsLargeCommit1256--- PASS: TestReadProxyInvalidPath (0.44s)1257=== CONT TestClientPushesUseOnePush1258--- PASS: TestReadProxyHead (0.47s)1259=== CONT TestClientWithDependencies12602026/10/07 06:22:34 INFO lead: acquired remote=192.0.2.1:123412612026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures12622026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=012632026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures12652026/10/07 06:22:34 INFO Aborted multipart uploads count=1 kept=01266--- PASS: TestReadProxy404 (0.45s)1267=== CONT TestOrphanedObjectsGC12682026/10/07 06:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12692026-10-07 06:22:34.412 UTC [711] ERROR: Closure does not exist: id=112702026-10-07 06:22:34.412 UTC [711] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12712026-10-07 06:22:34.412 UTC [711] STATEMENT: -- name: CommitPendingClosure :one1272 SELECT commit_pending_closure($1::bigint)::bigint1273 1274--- PASS: TestService_cleanupPendingClosuresHandler (0.45s)1275=== CONT TestClientMultipleUploads12762026/10/07 06:22:34 INFO lead: acquired remote=192.0.2.1:123412772026/10/07 06:22:34 INFO lead: released remote=192.0.2.1:12341278--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.45s)1279=== CONT TestPinProtectsFromGC12802026/10/07 06:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12812026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures12822026/10/07 06:22:34 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjNlYmMxMWQ4LTY0MGUtNGZhNy05MDk1LTg5NzI3YzljMTU0NHgxNzkxMzU0MTUzOTk1MTIzMzUy error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12832026/10/07 06:22:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjNmZjA4ODQwLTQ4ZGEtNDAzNC05Yjk4LWI1MmYxYzhjYTI5OXgxNzkxMzU0MTUzOTg3OTU3MDQ4 parts=1212842026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures12852026/10/07 06:22:34 INFO Aborted multipart uploads count=1 kept=01286--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.47s)1287=== CONT TestClientSharedPathCommittedMidPush1288--- PASS: TestRedundantMultipartUpload (1.51s)1289=== CONT TestClientIntegration12902026/10/07 06:22:34 INFO lead: acquired remote=192.0.2.1:123412912026/10/07 06:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12922026/10/07 06:22:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1293--- PASS: TestCompleteMultipartUnregistered (0.46s)1294=== CONT TestClientErrorHandling1295=== RUN TestClientErrorHandling/InvalidStorePath1296=== PAUSE TestClientErrorHandling/InvalidStorePath1297=== RUN TestClientErrorHandling/InvalidAuthToken1298=== PAUSE TestClientErrorHandling/InvalidAuthToken1299=== RUN TestClientErrorHandling/ServerNotAvailable1300=== PAUSE TestClientErrorHandling/ServerNotAvailable1301=== CONT TestObjectStatsTrigger13022026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures1303--- PASS: TestGCBugBareHashReferences (0.70s)1304=== CONT TestDeleteClosuresRacingPins13052026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13092026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures1310--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.47s)1311=== CONT TestService_RequireScope_OIDC13122026/10/07 06:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13132026/10/07 06:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1314--- PASS: TestService_NativeMTLS (0.49s)1315=== CONT TestService_ReadAuthMiddleware1316=== NAME TestClientCADerivations1317 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4191807560/001/store/08rl4kylrif23c2iqpss65yih6v8hvh2-ca-test1318 client_ca_test.go:139: Found 1 dependencies (including self)13192026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures13202026/10/07 06:22:34 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket69/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13212026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=113222026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures13232026/10/07 06:22:34 INFO Aborted multipart uploads count=1 kept=01324--- PASS: TestMultipartCleanup (0.54s)1325=== CONT TestCacheConfigHandler1326=== RUN TestCacheConfigHandler/full_config,_no_issuer1327=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1328=== RUN TestCacheConfigHandler/no_cache_url_configured1329=== PAUSE TestCacheConfigHandler/no_cache_url_configured1330=== RUN TestCacheConfigHandler/no_signing_keys1331=== PAUSE TestCacheConfigHandler/no_signing_keys1332=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1333=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1334=== CONT TestPendingCleanupUsesOneCutoff13352026/10/07 06:22:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40685/oidc13362026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes13372026/10/07 06:22:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13382026/10/07 06:22:34 INFO Uploading 08rl4kylrif23c2iqpss65yih6v8hvh2-ca-test (144B)1339=== NAME TestClientWithDependencies1340 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2577082534/001/store/0pnir7s32n41mnkam6l124kza1f1ngji-test-script13412026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13422026/10/07 06:22:34 WARN Failed to register uploaded object key=08rl4kylrif23c2iqpss65yih6v8hvh2.ls error="server returned 404: 404 page not found\n"13432026/10/07 06:22:34 WARN Failed to register uploaded object key=log/rsq6p4yjbkh561v2vcbri09ad7z836lg-ca-test.drv error="server returned 404: 404 page not found\n"13442026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13452026/10/07 06:22:34 INFO Signed narinfos id=1 count=113462026/10/07 06:22:34 INFO Uploading 1 narinfos13472026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete13482026/10/07 06:22:34 WARN Failed to register uploaded object key=08rl4kylrif23c2iqpss65yih6v8hvh2.narinfo error="server returned 404: 404 page not found\n"13492026/10/07 06:22:34 INFO Completed push id=1 objects=4 duration=6.622239ms13502026/10/07 06:22:34 INFO Upload complete. (106ms)1351=== NAME TestClientCADerivations1352 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4191807560/001/store/08rl4kylrif23c2iqpss65yih6v8hvh2-ca-test1353 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1354 Compression: zstd1355 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1356 NarSize: 1441357 References: 1358 Deriver: /build/TestClientCADerivations4191807560/001/store/rsq6p4yjbkh561v2vcbri09ad7z836lg-ca-test.drv1359 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1360 client_ca_test.go:185: Checking for realisation files in S3...1361 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1362 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13632026/10/07 06:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1364=== NAME TestClientWithDependencies1365 client_integration_test.go:615: Found 1 dependencies (including self)1366=== NAME TestPinProtectsFromGC1367 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC3476732421/001/store/pc7jqd1j4plk5d37lmxvib573sb320x7-pinned-file.txt1368 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC3476732421/001/store/7mspw6qx00lfi7g96rw682hr87f1lvzy-unpinned-file.txt1369=== NAME TestClientMultipleUploads1370 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1786932685/001/store/n7fdsvj6lxi3gx8dgkkj164hyffgwgs4-test-file-0.txt1371--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)1372=== CONT TestService_AuthMiddleware_OIDC13732026/10/07 06:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13742026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13752026/10/07 06:22:34 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LmNkODIzZTRkLTk1ZmEtNGYzYi1hOWZiLWVjNjFmZTFmNzMzMXgxNzkxMzU0MTU0NDk4MzE4OTA5 parts=1013762026/10/07 06:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1377=== NAME TestClientIntegration1378 client_integration_test.go:286: Created store path: /build/TestClientIntegration1130264764/002/store/c7qqh9664nv7mldsy2ggaplhhm136vwb-test-file.txt13792026/10/07 06:22:34 INFO Completed upload id=1 objects=2 duration=3.989176ms13802026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13812026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13822026/10/07 06:22:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13832026/10/07 06:22:34 INFO Uploading hb2s27sxisn998z132hay6lsszp2qija-shared-dep (136B)13842026/10/07 06:22:34 INFO Uploading 4i5fyviq62333q5cfhv93kb1zfzgxah3-a (216B)13852026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures13862026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/0zw44vy1kgi2xa4ahyp6lbfs3mbcgnpvz181hk67hi6d5g04l1qa.nar.zst error="server returned 404: 404 page not found\n"13872026/10/07 06:22:34 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13882026/10/07 06:22:34 WARN Found objects in DB but missing from S3, will re-upload count=113892026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13902026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13912026/10/07 06:22:34 WARN Failed to register uploaded object key=4i5fyviq62333q5cfhv93kb1zfzgxah3.ls error="server returned 404: 404 page not found\n"13922026/10/07 06:22:34 WARN Failed to register uploaded object key=gj66zx102c38b7yyrwrra6xvhs532zd9.ls error="server returned 404: 404 page not found\n"1393--- PASS: TestService_verifyS3Integrity (0.78s)1394=== CONT TestProxyWriteTimeout1395=== RUN TestProxyWriteTimeout/narinfo13962026/10/07 06:22:34 WARN Failed to register uploaded object key=hb2s27sxisn998z132hay6lsszp2qija.ls error="server returned 404: 404 page not found\n"1397=== PAUSE TestProxyWriteTimeout/narinfo1398=== RUN TestProxyWriteTimeout/1_GiB_nar1399=== PAUSE TestProxyWriteTimeout/1_GiB_nar1400=== RUN TestProxyWriteTimeout/10_GiB_nar1401=== PAUSE TestProxyWriteTimeout/10_GiB_nar1402=== RUN TestProxyWriteTimeout/unknown_size1403=== PAUSE TestProxyWriteTimeout/unknown_size1404=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14052026/10/07 06:22:34 INFO Signed narinfos id=1 count=214062026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14072026/10/07 06:22:34 INFO Signed narinfos id=2 count=214082026/10/07 06:22:34 INFO Uploading 4 narinfos14092026/10/07 06:22:34 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTA4OGQ2YjItMTkxNy00ZjJkLTk5N2ItODE5MGM1NTk0NmQ5LjYwYTM4ODY3LTBiNTAtNGY4YS1iNTdiLWU5ZDI0MjBkOWI0ZngxNzkxMzU0MTU0NTE4OTcyNzcx parts=1014102026/10/07 06:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14112026/10/07 06:22:34 INFO Completed upload id=1 objects=2 duration=2.897546ms14122026/10/07 06:22:34 WARN Failed to register uploaded object key=hb2s27sxisn998z132hay6lsszp2qija.narinfo error="server returned 404: 404 page not found\n"14132026/10/07 06:22:34 WARN Failed to register uploaded object key=gj66zx102c38b7yyrwrra6xvhs532zd9.narinfo error="server returned 404: 404 page not found\n"14142026/10/07 06:22:34 WARN Failed to register uploaded object key=4i5fyviq62333q5cfhv93kb1zfzgxah3.narinfo error="server returned 404: 404 page not found\n"14152026/10/07 06:22:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001416=== NAME TestClientMultipleUploads1417 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1786932685/001/store/072gx8fmbinsh58la9qwccvc5f9mwq17-test-file-1.txt14182026/10/07 06:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14192026/10/07 06:22:34 WARN Failed to register uploaded object key=hb2s27sxisn998z132hay6lsszp2qija.narinfo error="server returned 404: 404 page not found\n"14202026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures1421--- PASS: TestObjectStatsTrigger (0.37s)1422=== CONT TestCacheStatsHandler14232026/10/07 06:22:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures14242026/10/07 06:22:34 INFO Completed upload id=1 objects=6 duration=4.223977ms14252026/10/07 06:22:34 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14262026/10/07 06:22:34 INFO Completed upload id=2 objects=6 duration=1.800316ms14272026/10/07 06:22:34 INFO Upload complete. (66ms)1428=== NAME TestClientFallsBackToClosures1429 client_pushes_test.go:112: Retrieved narinfo from S3:1430 StorePath: /build/TestClientFallsBackToClosures554628086/001/store/hb2s27sxisn998z132hay6lsszp2qija-shared-dep1431 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1432 Compression: zstd1433 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821434 NarSize: 1361435 References: 1436 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1437 client_pushes_test.go:112: Retrieved narinfo from S3:1438 StorePath: /build/TestClientFallsBackToClosures554628086/001/store/4i5fyviq62333q5cfhv93kb1zfzgxah3-a1439 URL: nar/0zw44vy1kgi2xa4ahyp6lbfs3mbcgnpvz181hk67hi6d5g04l1qa.nar.zst1440 Compression: zstd1441 NarHash: sha256:0zw44vy1kgi2xa4ahyp6lbfs3mbcgnpvz181hk67hi6d5g04l1qa1442 NarSize: 2161443 References: /build/TestClientFallsBackToClosures554628086/001/store/hb2s27sxisn998z132hay6lsszp2qija-shared-dep1444 CA: text:sha256:17ckns6m4n80008kszir603m8jrza3r4qrk6yphzyv671g6580fl14452026/10/07 06:22:34 INFO Aborted multipart uploads count=0 kept=014462026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes1447 client_pushes_test.go:112: Retrieved narinfo from S3:1448 StorePath: /build/TestClientFallsBackToClosures554628086/001/store/gj66zx102c38b7yyrwrra6xvhs532zd9-b1449 URL: nar/0zw44vy1kgi2xa4ahyp6lbfs3mbcgnpvz181hk67hi6d5g04l1qa.nar.zst1450 Compression: zstd1451 NarHash: sha256:0zw44vy1kgi2xa4ahyp6lbfs3mbcgnpvz181hk67hi6d5g04l1qa1452 NarSize: 2161453 References: /build/TestClientFallsBackToClosures554628086/001/store/hb2s27sxisn998z132hay6lsszp2qija-shared-dep1454 CA: text:sha256:17ckns6m4n80008kszir603m8jrza3r4qrk6yphzyv671g6580fl14552026/10/07 06:22:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14562026/10/07 06:22:34 INFO Uploading djvjdcn1hivh8vapzs46a708cfdy7n0n-b (216B)14572026/10/07 06:22:34 INFO Uploading j7v2wsydbg0hav84yaxm9lh67nwkxbcl-shared-dep (136B)1458--- PASS: TestClientFallsBackToClosures (0.58s)1459=== CONT TestService_AuthMiddleware_MTLSProxyHeader14602026/10/07 06:22:34 WARN Failed to register uploaded object key=dcyr6n8jc1bj18zz5kinlrcvf24wh0xv.ls error="server returned 404: 404 page not found\n"14612026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/0vjc41y1sbljx6000k9n4mvwfcxs53i26hyr5rsz02m9p8cakjnl.nar.zst error="server returned 404: 404 page not found\n"14622026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14632026/10/07 06:22:34 WARN Failed to register uploaded object key=djvjdcn1hivh8vapzs46a708cfdy7n0n.ls error="server returned 404: 404 page not found\n"14642026/10/07 06:22:34 WARN Failed to register uploaded object key=j7v2wsydbg0hav84yaxm9lh67nwkxbcl.ls error="server returned 404: 404 page not found\n"14652026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14662026/10/07 06:22:34 INFO Signed narinfos id=1 count=314672026/10/07 06:22:34 INFO Uploading 3 narinfos14682026/10/07 06:22:34 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=01469--- PASS: TestService_ReadAuthMiddleware (0.26s)1470=== CONT TestService_ReadScope_PublicByDefault14712026/10/07 06:22:34 WARN Failed to register uploaded object key=j7v2wsydbg0hav84yaxm9lh67nwkxbcl.narinfo error="server returned 404: 404 page not found\n"14722026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete14732026/10/07 06:22:34 WARN Failed to register uploaded object key=djvjdcn1hivh8vapzs46a708cfdy7n0n.narinfo error="server returned 404: 404 page not found\n"14742026/10/07 06:22:34 INFO Vacuumed table table=pending_closures14752026/10/07 06:22:34 WARN Failed to register uploaded object key=dcyr6n8jc1bj18zz5kinlrcvf24wh0xv.narinfo error="server returned 404: 404 page not found\n"14762026/10/07 06:22:34 INFO Vacuumed table table=pending_objects14772026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes1478=== NAME TestClientMultipleUploads1479 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1786932685/001/store/s0n0scmh4kj4bvh3czsdx04zxfg964rg-test-file-2.txt14802026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes14812026/10/07 06:22:34 INFO Vacuumed table table=multipart_uploads14822026/10/07 06:22:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14832026/10/07 06:22:34 INFO Uploading pc7jqd1j4plk5d37lmxvib573sb320x7-pinned-file.txt (128B)14842026/10/07 06:22:34 INFO Completed push id=1 objects=8 duration=7.565866ms14852026/10/07 06:22:34 INFO Upload complete. (59ms)14862026/10/07 06:22:34 INFO Vacuumed table table=closures1487=== NAME TestClientPushesUseOnePush1488 client_pushes_test.go:97: Retrieved narinfo from S3:1489 StorePath: /build/TestClientPushesUseOnePush2537418667/001/store/j7v2wsydbg0hav84yaxm9lh67nwkxbcl-shared-dep1490 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1491 Compression: zstd1492 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821493 NarSize: 1361494 References: 1495 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14962026/10/07 06:22:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14972026/10/07 06:22:34 INFO Uploading 0pnir7s32n41mnkam6l124kza1f1ngji-test-script (136B)14982026/10/07 06:22:34 INFO Vacuumed table table=objects1499 client_pushes_test.go:97: Retrieved narinfo from S3:1500 StorePath: /build/TestClientPushesUseOnePush2537418667/001/store/dcyr6n8jc1bj18zz5kinlrcvf24wh0xv-a1501 URL: nar/0vjc41y1sbljx6000k9n4mvwfcxs53i26hyr5rsz02m9p8cakjnl.nar.zst1502 Compression: zstd1503 NarHash: sha256:0vjc41y1sbljx6000k9n4mvwfcxs53i26hyr5rsz02m9p8cakjnl1504 NarSize: 2161505 References: /build/TestClientPushesUseOnePush2537418667/001/store/j7v2wsydbg0hav84yaxm9lh67nwkxbcl-shared-dep1506 CA: text:sha256:066idxqgn1qad9yxz8nazisv65724fydv8y8hanfrcqn0k69431315072026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15082026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15092026/10/07 06:22:34 WARN Failed to register uploaded object key=pc7jqd1j4plk5d37lmxvib573sb320x7.ls error="server returned 404: 404 page not found\n"15102026/10/07 06:22:34 INFO Signed narinfos id=1 count=115112026/10/07 06:22:34 INFO Uploading 1 narinfos15122026/10/07 06:22:34 WARN Failed to register uploaded object key=0pnir7s32n41mnkam6l124kza1f1ngji.ls error="server returned 404: 404 page not found\n"15132026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1514 client_pushes_test.go:97: Retrieved narinfo from S3:1515 StorePath: /build/TestClientPushesUseOnePush2537418667/001/store/djvjdcn1hivh8vapzs46a708cfdy7n0n-b1516 URL: nar/0vjc41y1sbljx6000k9n4mvwfcxs53i26hyr5rsz02m9p8cakjnl.nar.zst1517 Compression: zstd1518 NarHash: sha256:0vjc41y1sbljx6000k9n4mvwfcxs53i26hyr5rsz02m9p8cakjnl1519 NarSize: 2161520 References: /build/TestClientPushesUseOnePush2537418667/001/store/j7v2wsydbg0hav84yaxm9lh67nwkxbcl-shared-dep1521 CA: text:sha256:066idxqgn1qad9yxz8nazisv65724fydv8y8hanfrcqn0k69431315222026/10/07 06:22:34 WARN Failed to register uploaded object key=log/ir0pv6q6z9mw52h0qrfb57n340czzzak-test-script.drv error="server returned 404: 404 page not found\n"15232026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15242026/10/07 06:22:34 INFO Signed narinfos id=1 count=115252026/10/07 06:22:34 INFO Uploading 1 narinfos15262026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15272026/10/07 06:22:34 WARN Failed to register uploaded object key=pc7jqd1j4plk5d37lmxvib573sb320x7.narinfo error="server returned 404: 404 page not found\n"15282026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes1529--- PASS: TestClientPushesUseOnePush (0.57s)1530=== CONT TestIsValidCachePath/narinfo1531=== CONT TestIsValidCachePath/traversal_in_middle1532=== CONT TestIsValidCachePath/leading_slash1533=== CONT TestGCEndsOnShutdown/before_the_run15342026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures15352026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15362026/10/07 06:22:34 WARN Failed to register uploaded object key=0pnir7s32n41mnkam6l124kza1f1ngji.narinfo error="server returned 404: 404 page not found\n"15372026/10/07 06:22:34 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001538=== NAME TestClientCADerivations1539 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1540 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1541 error: binary cache 's3://bucket67?endpoint=http://localhost:35295®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4191807560/001/store'1542 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115432026/10/07 06:22:34 INFO Completed push id=1 objects=3 duration=8.405634ms15442026/10/07 06:22:34 INFO Upload complete. (54ms)1545--- PASS: TestService_createPendingClosureHandler (0.82s)1546=== CONT TestIsValidCachePath/invalid_char_u1547=== CONT TestIsValidCachePath/empty1548=== CONT TestIsValidCachePath/random_path1549=== CONT TestIsValidCachePath/ls1550=== CONT TestIsValidCachePath/traversal_parent1551=== CONT TestIsValidCachePath/index.html1552=== CONT TestIsValidCachePath/nix-cache-info1553=== CONT TestIsValidCachePath/realisation1554=== CONT TestIsValidCachePath/log1555=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15562026/10/07 06:22:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15572026/10/07 06:22:34 INFO Uploading c7qqh9664nv7mldsy2ggaplhhm136vwb-test-file.txt (152B)1558--- PASS: TestClientCADerivations (0.73s)1559=== CONT TestIsValidCachePath/nar_xz1560=== CONT TestIsValidCachePath/nar_uncompressed1561=== CONT TestIsValidCachePath/nar_bz21562=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15632026/10/07 06:22:34 INFO Completed push id=1 objects=4 duration=9.896087ms15642026/10/07 06:22:34 INFO Upload complete. (60ms)15652026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15662026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15672026/10/07 06:22:34 WARN Failed to register uploaded object key=c7qqh9664nv7mldsy2ggaplhhm136vwb.ls error="server returned 404: 404 page not found\n"15682026/10/07 06:22:34 INFO Signed narinfos id=1 count=115692026/10/07 06:22:34 INFO Uploading 1 narinfos1570=== NAME TestClientWithDependencies1571 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2577082534/001/store) requires matching store prefix15722026/10/07 06:22:34 INFO Received uploads request method=POST path=/api/pending_closures1573--- PASS: TestClientWithDependencies (0.55s)1574=== CONT TestIsValidCachePath/short_hash1575=== CONT TestIsValidCachePath/nar_zst1576=== CONT TestIsValidCachePath/invalid_char_e1577=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1578=== CONT TestIsValidCachePath/wrong_extension1579--- PASS: TestIsValidCachePath (0.00s)1580 --- PASS: TestIsValidCachePath/narinfo (0.00s)1581 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1582 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1583 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1584 --- PASS: TestIsValidCachePath/empty (0.00s)1585 --- PASS: TestIsValidCachePath/random_path (0.00s)1586 --- PASS: TestIsValidCachePath/ls (0.00s)1587 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1588 --- PASS: TestIsValidCachePath/index.html (0.00s)1589 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1590 --- PASS: TestIsValidCachePath/realisation (0.00s)1591 --- PASS: TestIsValidCachePath/log (0.00s)1592 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1593 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1594 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1595 --- PASS: TestIsValidCachePath/short_hash (0.00s)1596 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1597 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1598 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1599 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1600=== CONT TestParseSingleRange/none1601=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16022026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete16032026/10/07 06:22:34 WARN Failed to register uploaded object key=c7qqh9664nv7mldsy2ggaplhhm136vwb.narinfo error="server returned 404: 404 page not found\n"16042026/10/07 06:22:34 INFO Completed push id=1 objects=3 duration=6.496277ms16052026/10/07 06:22:34 INFO Upload complete. (60ms)16062026/10/07 06:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures1607=== RUN TestService_RequireScope_OIDC/builder_may_write1608=== PAUSE TestService_RequireScope_OIDC/builder_may_write1609=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1610=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1611=== RUN TestService_RequireScope_OIDC/ops_may_admin1612=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1613=== RUN TestService_RequireScope_OIDC/ops_may_not_write1614=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1615=== RUN TestService_RequireScope_OIDC/reader_may_not_write1616=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1617=== RUN TestService_RequireScope_OIDC/static_token_may_admin1618=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1619=== RUN TestService_RequireScope_OIDC/static_token_may_write1620=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1621=== RUN TestService_RequireScope_OIDC/reader_may_read1622=== PAUSE TestService_RequireScope_OIDC/reader_may_read1623=== RUN TestService_RequireScope_OIDC/writer_implies_read1624=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1625=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1626=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1627=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1628=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1629=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1630=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1631=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1632=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1633=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1634=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1635=== CONT TestParseSingleRange/closed1636=== CONT TestParseSingleRange/malformed_end_before_start1637=== CONT TestParseSingleRange/malformed_both_empty1638=== CONT TestParseSingleRange/malformed_no_dash1639=== CONT TestParseSingleRange/multi-range_ignored1640=== CONT TestParseSingleRange/unknown_unit1641=== CONT TestParseSingleRange/open-ended1642=== CONT TestParseSingleRange/single_byte1643=== CONT TestParseSingleRange/start_far_past_EOF1644=== CONT TestParseSingleRange/start_past_EOF1645=== CONT TestParseSingleRange/suffix1646=== CONT TestParseSingleRange/suffix_exceeds_size1647=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16482026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes16492026/10/07 06:22:34 INFO All 1 paths already cached1650=== NAME TestClientIntegration1651 client_integration_test.go:312: Retrieved narinfo from S3:1652 StorePath: /build/TestClientIntegration1130264764/002/store/c7qqh9664nv7mldsy2ggaplhhm136vwb-test-file.txt1653 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1654 Compression: zstd1655 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11656 NarSize: 1521657 References: 1658 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116592026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes16602026/10/07 06:22:34 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16612026/10/07 06:22:34 INFO Uploading zz34rpfs47sn9hxwq3ss5n7y05rbx7ls-top (224B)16622026/10/07 06:22:34 INFO Uploading dwqqj6z357hqp88sh02ijy59qck3v112-shared-dep (136B)1663 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1664 client_integration_test.go:313: Decompressed .ls content (64 bytes):1665 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1666 client_integration_test.go:316: Testing garbage collection...16672026/10/07 06:22:34 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16682026/10/07 06:22:34 INFO Uploading s0n0scmh4kj4bvh3czsdx04zxfg964rg-test-file-2.txt (160B)16692026/10/07 06:22:34 INFO Uploading 072gx8fmbinsh58la9qwccvc5f9mwq17-test-file-1.txt (160B)16702026/10/07 06:22:34 INFO Uploading n7fdsvj6lxi3gx8dgkkj164hyffgwgs4-test-file-0.txt (160B)16712026/10/07 06:22:34 WARN Failed to register uploaded object key=zz34rpfs47sn9hxwq3ss5n7y05rbx7ls.ls error="server returned 404: 404 page not found\n"16722026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16732026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/144lf1ns7cxlghi1vsb4fhzkmqwfpy1xhhqh2yn39vc686nhagmw.nar.zst error="server returned 404: 404 page not found\n"16742026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16752026/10/07 06:22:34 WARN Failed to register uploaded object key=dwqqj6z357hqp88sh02ijy59qck3v112.ls error="server returned 404: 404 page not found\n"16762026/10/07 06:22:34 INFO Signed narinfos id=1 count=216772026/10/07 06:22:34 INFO Uploading 2 narinfos16782026/10/07 06:22:34 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32933/oidc16792026/10/07 06:22:34 WARN Failed to register uploaded object key=072gx8fmbinsh58la9qwccvc5f9mwq17.ls error="server returned 404: 404 page not found\n"16802026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16812026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16822026/10/07 06:22:34 WARN Failed to register uploaded object key=n7fdsvj6lxi3gx8dgkkj164hyffgwgs4.ls error="server returned 404: 404 page not found\n"16832026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16842026/10/07 06:22:34 WARN Failed to register uploaded object key=s0n0scmh4kj4bvh3czsdx04zxfg964rg.ls error="server returned 404: 404 page not found\n"16852026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16862026/10/07 06:22:34 WARN Failed to register uploaded object key=dwqqj6z357hqp88sh02ijy59qck3v112.narinfo error="server returned 404: 404 page not found\n"16872026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete16882026/10/07 06:22:34 INFO Signed narinfos id=1 count=316892026/10/07 06:22:34 WARN Failed to register uploaded object key=zz34rpfs47sn9hxwq3ss5n7y05rbx7ls.narinfo error="server returned 404: 404 page not found\n"16902026/10/07 06:22:34 INFO Received push request method=POST path=/api/pushes16912026/10/07 06:22:34 INFO Uploading 3 narinfos16922026/10/07 06:22:34 WARN Failed to register uploaded object key=s0n0scmh4kj4bvh3czsdx04zxfg964rg.narinfo error="server returned 404: 404 page not found\n"16932026/10/07 06:22:34 WARN Failed to register uploaded object key=n7fdsvj6lxi3gx8dgkkj164hyffgwgs4.narinfo error="server returned 404: 404 page not found\n"16942026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete16952026/10/07 06:22:34 WARN Failed to register uploaded object key=072gx8fmbinsh58la9qwccvc5f9mwq17.narinfo error="server returned 404: 404 page not found\n"16962026/10/07 06:22:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16972026/10/07 06:22:34 INFO Uploading 7mspw6qx00lfi7g96rw682hr87f1lvzy-unpinned-file.txt (128B)16982026/10/07 06:22:34 INFO Completed push id=1 objects=6 duration=8.037571ms16992026/10/07 06:22:34 INFO Upload complete. (64ms)1700=== NAME TestClientSharedPathCommittedMidPush1701 client_integration_test.go:680: Retrieved narinfo from S3:1702 StorePath: /build/TestClientSharedPathCommittedMidPush951518114/001/store/dwqqj6z357hqp88sh02ijy59qck3v112-shared-dep1703 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1704 Compression: zstd1705 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821706 NarSize: 1361707 References: 1708 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17092026/10/07 06:22:34 WARN Failed to register uploaded object key=7mspw6qx00lfi7g96rw682hr87f1lvzy.ls error="server returned 404: 404 page not found\n"17102026/10/07 06:22:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17112026/10/07 06:22:34 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17122026/10/07 06:22:34 INFO Signed narinfos id=2 count=117132026/10/07 06:22:34 INFO Uploading 1 narinfos1714 client_integration_test.go:680: Retrieved narinfo from S3:1715 StorePath: /build/TestClientSharedPathCommittedMidPush951518114/001/store/zz34rpfs47sn9hxwq3ss5n7y05rbx7ls-top1716 URL: nar/144lf1ns7cxlghi1vsb4fhzkmqwfpy1xhhqh2yn39vc686nhagmw.nar.zst1717 Compression: zstd1718 NarHash: sha256:144lf1ns7cxlghi1vsb4fhzkmqwfpy1xhhqh2yn39vc686nhagmw1719 NarSize: 2241720 References: /build/TestClientSharedPathCommittedMidPush951518114/001/store/dwqqj6z357hqp88sh02ijy59qck3v112-shared-dep1721 CA: text:sha256:1xcg56ynyj86mckkdyk6zmrpbab2qa2c9nsbk156yd4s954ak64n17222026/10/07 06:22:34 INFO Completed push id=1 objects=9 duration=9.295742ms17232026/10/07 06:22:34 INFO Upload complete. (69ms)1724=== NAME TestClientMultipleUploads1725 client_integration_test.go:369: Uploaded 3 paths in 103.875696ms17262026/10/07 06:22:34 INFO Received complete push request method=POST path=/api/pushes/2/complete17272026/10/07 06:22:34 WARN Failed to register uploaded object key=7mspw6qx00lfi7g96rw682hr87f1lvzy.narinfo error="server returned 404: 404 page not found\n"1728--- PASS: TestClientSharedPathCommittedMidPush (0.54s)1729=== CONT TestParseSingleRange/end_clamped_to_size1730--- PASS: TestParseSingleRange (0.01s)1731 --- PASS: TestParseSingleRange/none (0.00s)1732 --- PASS: TestParseSingleRange/closed (0.00s)1733 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1734 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1735 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1736 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1737 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1738 --- PASS: TestParseSingleRange/open-ended (0.00s)1739 --- PASS: TestParseSingleRange/single_byte (0.00s)1740 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1741 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1742 --- PASS: TestParseSingleRange/suffix (0.00s)1743 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1744 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1745=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17462026/10/07 06:22:34 INFO Completed push id=2 objects=3 duration=2.731184ms17472026/10/07 06:22:34 INFO Upload complete. (53ms)1748--- PASS: TestClientMultipleUploads (0.57s)1749=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17502026/10/07 06:22:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures17512026/10/07 06:22:34 INFO Garbage collection started17522026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=017532026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period17542026/10/07 06:22:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17552026/10/07 06:22:35 WARN mTLS auth: bound subjects configured but subject DN unavailable17562026/10/07 06:22:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1757--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.19s)1758=== CONT TestPush_RejectsBadRequests/root_not_in_objects17592026/10/07 06:22:35 INFO Received push request method=POST path=/api/pushes1760=== CONT TestPush_RejectsBadRequests/bad_root17612026/10/07 06:22:35 INFO Received push request method=POST path=/api/pushes1762=== CONT TestPush_RejectsBadRequests/no_objects17632026/10/07 06:22:35 INFO Received push request method=POST path=/api/pushes1764=== CONT TestPush_RejectsBadRequests/no_roots17652026/10/07 06:22:35 INFO Received push request method=POST path=/api/pushes1766=== CONT TestIsValidUploadKey/narinfo17672026/10/07 06:22:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures1768--- PASS: TestPush_RejectsBadRequests (0.59s)1769 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1770 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1771 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1772 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1773=== CONT TestIsValidUploadKey/realisation_plus_in_output1774=== CONT TestIsValidUploadKey/unknown_type1775=== CONT TestIsValidUploadKey/empty_key1776=== CONT TestIsValidUploadKey/absolute1777=== CONT TestIsValidUploadKey/traversal_nar1778=== CONT TestIsValidUploadKey/traversal1779=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1780=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1781=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1782=== CONT TestIsValidUploadKey/index.html17832026/10/07 06:22:35 INFO Garbage collection started1784=== CONT TestIsValidUploadKey/nix-cache-info1785=== CONT TestIsValidUploadKey/build_log_home-manager_file1786=== CONT TestIsValidUploadKey/realisation1787=== CONT TestIsValidUploadKey/build_log_equals1788=== CONT TestIsValidUploadKey/build_log_question_mark1789=== CONT TestIsValidUploadKey/build_log_plus_in_name1790=== CONT TestIsValidUploadKey/nar_plain1791=== CONT TestIsValidUploadKey/build_log1792=== CONT TestIsValidUploadKey/listing1793=== CONT TestIsValidUploadKey/nar_xz1794=== CONT TestIsValidUploadKey/nar_zst1795--- PASS: TestIsValidUploadKey (0.00s)1796 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1797 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1798 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1799 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1800 --- PASS: TestIsValidUploadKey/absolute (0.00s)1801 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1802 --- PASS: TestIsValidUploadKey/traversal (0.00s)1803 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1804 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1805 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1806 --- PASS: TestIsValidUploadKey/index.html (0.00s)1807 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1808 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1809 --- PASS: TestIsValidUploadKey/realisation (0.00s)1810 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1811 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1813 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1814 --- PASS: TestIsValidUploadKey/build_log (0.00s)1815 --- PASS: TestIsValidUploadKey/listing (0.00s)1816 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1817 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1818=== CONT TestResolveDBConnectionString/flag_wins1819=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1820=== CONT TestResolveDBConnectionString/missing_file_is_an_error1821=== CONT TestResolveDBConnectionString/file_when_flag_empty1822=== CONT TestResolveDBConnectionString/nothing_configured1823=== CONT TestPendingClosureWriteTimeout/empty1824=== CONT TestPendingClosureWriteTimeout/670k_objects1825=== CONT TestPendingClosureWriteTimeout/400_objects1826=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1827--- PASS: TestResolveDBConnectionString (0.00s)1828 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1829 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1830 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1831 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1832 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)18332026/10/07 06:22:35 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=018342026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=018352026/10/07 06:22:35 INFO Vacuumed table table=pending_closures1836=== NAME TestOrphanedObjectsGC1837 orphaned_objects_gc_test.go:287: GC Test Summary:1838 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1839 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1840 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1841 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1842 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1843--- PASS: TestOrphanedObjectsGC (0.63s)1844=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18452026/10/07 06:22:35 INFO Received uploads request method=POST path=/1846=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18472026/10/07 06:22:35 INFO Received complete multipart upload request method=POST path=/1848=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18492026/10/07 06:22:35 INFO Received uploads request method=POST path=/1850=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18512026/10/07 06:22:35 INFO Received request for more parts method=POST path=/1852--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1853 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1854 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1855 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1856 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)18572026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period1858=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18592026/10/07 06:22:35 INFO Received complete multipart upload request method=POST path=/18602026/10/07 06:22:35 INFO Vacuumed table table=pending_objects18612026/10/07 06:22:35 INFO Vacuumed table table=multipart_uploads18622026/10/07 06:22:35 INFO Vacuumed table table=closures18632026/10/07 06:22:35 INFO Vacuumed table table=objects18642026/10/07 06:22:35 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=01865--- PASS: TestCacheStatsHandler (0.21s)1866=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18672026/10/07 06:22:35 INFO Received uploads request method=POST path=/18682026/10/07 06:22:35 INFO Vacuumed table table=pending_closures18692026/10/07 06:22:35 INFO Vacuumed table table=pending_objects18702026/10/07 06:22:35 INFO Vacuumed table table=multipart_uploads18712026/10/07 06:22:35 INFO Vacuumed table table=closures1872--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.21s)1873=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18742026/10/07 06:22:35 INFO Received request for more parts method=POST path=/18752026/10/07 06:22:35 INFO Vacuumed table table=objects18762026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=018772026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period1878=== CONT TestServerTLSConfig/no_client_CA1879=== CONT TestServerTLSConfig/not_a_PEM_file1880=== CONT TestServerTLSConfig/missing_CA_file1881--- PASS: TestServerTLSConfig (0.00s)1882 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1883 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1884 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1885=== CONT TestClientErrorHandling/InvalidStorePath1886=== CONT TestClientErrorHandling/InvalidAuthToken18872026/10/07 06:22:35 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:35295/bucket89/?delete=\": context canceled"1888=== CONT TestClientErrorHandling/ServerNotAvailable1889--- PASS: TestService_ReadScope_PublicByDefault (0.26s)1890=== CONT TestCacheConfigHandler/full_config,_no_issuer1891=== CONT TestCacheConfigHandler/no_signing_keys1892=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1893=== CONT TestCacheConfigHandler/no_cache_url_configured1894--- PASS: TestCacheConfigHandler (0.00s)1895 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1896 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1897 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1898 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1899=== CONT TestProxyWriteTimeout/narinfo1900=== CONT TestProxyWriteTimeout/unknown_size1901=== CONT TestProxyWriteTimeout/10_GiB_nar1902=== CONT TestProxyWriteTimeout/1_GiB_nar1903--- PASS: TestProxyWriteTimeout (0.00s)1904 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1905 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1906 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1907 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1908=== CONT TestService_RequireScope_OIDC/builder_may_write1909=== CONT TestService_RequireScope_OIDC/reader_may_read1910=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1911=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19122026/10/07 06:22:35 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]1913=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1914=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1915=== CONT TestService_RequireScope_OIDC/writer_implies_read1916=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1917=== CONT TestService_RequireScope_OIDC/reader_may_not_write1918=== CONT TestService_RequireScope_OIDC/static_token_may_write1919=== CONT TestService_RequireScope_OIDC/static_token_may_admin1920=== CONT TestService_RequireScope_OIDC/ops_may_admin1921=== CONT TestService_RequireScope_OIDC/ops_may_not_write1922=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1923--- PASS: TestService_RequireScope_OIDC (0.32s)1924 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)19382026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=019392026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period19402026/10/07 06:22:35 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/present1941=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1942=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1943=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1944=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1945=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1946=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1947=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1948=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1949=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1950=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1951=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19522026/10/07 06:22:35 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]1953=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19542026/10/07 06:22:35 WARN Authentication failed token_preview=eyJhbGciOi...hzwAppoCpg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1955--- PASS: TestService_AuthMiddleware_OIDC (0.39s)1956 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1957 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1958 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1959 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1960--- PASS: TestGCEndsOnShutdown (0.00s)1961 --- PASS: TestGCEndsOnShutdown/before_the_run (0.23s)1962 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)1963 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)1964=== NAME TestOrphanedObjectsGCStressTest1965 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19662026/10/07 06:22:35 INFO Received uploads request method=POST path=/api/pending_closures1967 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion19682026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=019692026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period19702026/10/07 06:22:35 INFO Received uploads request method=POST path=/api/pending_closures19712026/10/07 06:22:35 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=019722026/10/07 06:22:35 INFO Vacuumed table table=pending_closures19732026/10/07 06:22:35 INFO Vacuumed table table=pending_objects19742026/10/07 06:22:35 INFO Vacuumed table table=multipart_uploads19752026/10/07 06:22:35 INFO Vacuumed table table=closures19762026/10/07 06:22:35 INFO Vacuumed table table=objects19772026/10/07 06:22:35 INFO Aborted multipart uploads count=0 kept=019782026/10/07 06:22:35 INFO Received uploads request method=POST path=/api/pending_closures19792026/10/07 06:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period19802026/10/07 06:22:35 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019812026/10/07 06:22:35 INFO Vacuumed table table=pending_closures19822026/10/07 06:22:35 INFO Vacuumed table table=pending_objects19832026/10/07 06:22:35 INFO Vacuumed table table=multipart_uploads19842026/10/07 06:22:35 INFO Vacuumed table table=closures19852026/10/07 06:22:35 INFO Vacuumed table table=objects1986--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1987 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.27s)1988 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)19892026/10/07 06:22:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=216.030682ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19902026/10/07 06:22:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19912026/10/07 06:22:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19922026/10/07 06:22:35 INFO lead: released remote=192.0.2.1:12341993--- PASS: TestLeadEndsOnShutdown (1.50s)1994=== NAME TestOrphanedObjectsGCStressTest1995 orphaned_objects_gc_test.go:503: Stress test completed successfully:1996 orphaned_objects_gc_test.go:504: - Active objects preserved: 201997 orphaned_objects_gc_test.go:505: - Objects deleted: 2101998 orphaned_objects_gc_test.go:506: - Total GC'd: 2101999--- PASS: TestOrphanedObjectsGCStressTest (2.20s)20002026/10/07 06:22:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.283924ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2001--- PASS: TestObjectStatsLargeCommit (1.35s)2002--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2003 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.75s)2004 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.75s)20052026/10/07 06:22:35 INFO lead: released remote=192.0.2.1:123420062026/10/07 06:22:35 INFO lead: acquired remote=192.0.2.1:123420072026/10/07 06:22:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.220189ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2008--- PASS: TestPendingClosureWriteTimeout (0.00s)2009 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2010 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2011 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2012 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)2013--- PASS: TestDeleteClosuresRacingPins (1.58s)2014--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2015 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2016 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2017 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.04s)20182026/10/07 06:22:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.575236904s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20192026/10/07 06:22:36 INFO lead: released remote=192.0.2.1:12342020--- PASS: TestLeadElectsOneAndHandsOver (2.81s)20212026/10/07 06:22:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02022=== NAME TestClientIntegration2023 client_integration_test.go:323: Objects in database after GC:2024 client_integration_test.go:323: Successfully deleted all objects with GC --force2025--- PASS: TestClientIntegration (2.55s)20262026/10/07 06:22:37 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020272026/10/07 06:22:37 INFO Received create pin request method=POST path=/api/pins/myapp20282026/10/07 06:22:37 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3476732421/001/store/pc7jqd1j4plk5d37lmxvib573sb320x7-pinned-file.txt narinfo_key=pc7jqd1j4plk5d37lmxvib573sb320x7.narinfo20292026/10/07 06:22:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures20302026/10/07 06:22:37 INFO Garbage collection started20312026/10/07 06:22:37 INFO Aborted multipart uploads count=0 kept=020322026/10/07 06:22:37 WARN Force mode enabled - objects will be deleted immediately without grace period20332026/10/07 06:22:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020342026/10/07 06:22:37 INFO Vacuumed table table=pending_closures20352026/10/07 06:22:37 INFO Vacuumed table table=pending_objects20362026/10/07 06:22:37 INFO Vacuumed table table=multipart_uploads20372026/10/07 06:22:37 INFO Vacuumed table table=closures20382026/10/07 06:22:37 INFO Vacuumed table table=objects20392026/10/07 06:22:38 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-config2040--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.58s)20412026/10/07 06:22:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.678734ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/07 06:22:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=398.248915ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2043=== NAME TestPinProtectsFromGC2044 client_integration_test.go:840: Pin successfully protected closure from garbage collection2045--- PASS: TestPinProtectsFromGC (4.62s)20462026/10/07 06:22:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=736.054857ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2047--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20482026/10/07 06:22:39 WARN Rate limiter enabled after throttle name=s3-test rate=520492026/10/07 06:22:39 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2050=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2051 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102052 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002053--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.36s)20542026/10/07 06:22:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.533191311s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/07 06:22:40 INFO Aborted multipart uploads count=1 kept=020562026/10/07 06:22:40 INFO Received cleanup request method=DELETE path=/api/pending_closures20572026/10/07 06:22:40 INFO Aborted multipart uploads count=1 kept=02058--- PASS: TestPendingCleanupUsesOneCutoff (6.23s)20592026/10/07 06:22:41 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"20602026/10/07 06:22:41 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-config20612026/10/07 06:22:41 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.873776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/10/07 06:22:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.711744ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20632026/10/07 06:22:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=774.804331ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20642026/10/07 06:22:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.509172532s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20652026/10/07 06:22:44 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_closures20662026/10/07 06:22:44 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.538673ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20672026/10/07 06:22:44 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.949389ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20682026/10/07 06:22:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=758.135163ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20692026/10/07 06:22:45 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.444141111s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2070--- PASS: TestClientErrorHandling (0.00s)2071 --- PASS: TestClientErrorHandling/InvalidStorePath (0.18s)2072 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.26s)2073 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.11s)2074PASS20752026-10-07 06:22:47.486 UTC [128] LOG: received smart shutdown request20762026-10-07 06:22:47.491 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 120772026-10-07 06:22:47.504 UTC [133] LOG: shutting down20782026-10-07 06:22:47.504 UTC [133] LOG: checkpoint starting: shutdown immediate20792026-10-07 06:22:48.282 UTC [133] LOG: checkpoint complete: wrote 10614 buffers (64.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.163 s, sync=0.583 s, total=0.779 s; sync files=34045, longest=0.007 s, average=0.001 s; distance=531623 kB, estimate=531623 kB; lsn=0/21E8FB80, redo lsn=0/21E8FB8020802026-10-07 06:22:48.362 UTC [128] LOG: database system is shut down2081Running OIDC tests...2082=== RUN TestAudienceForIssuer2083=== PAUSE TestAudienceForIssuer2084=== RUN TestGlobMatch2085=== PAUSE TestGlobMatch2086=== RUN TestValidateToken_ValidToken2087=== PAUSE TestValidateToken_ValidToken2088=== RUN TestValidateToken_WrongAudience2089=== PAUSE TestValidateToken_WrongAudience2090=== RUN TestValidateToken_Expired2091=== PAUSE TestValidateToken_Expired2092=== RUN TestValidateToken_BoundClaimsMismatch2093=== PAUSE TestValidateToken_BoundClaimsMismatch2094=== RUN TestValidateToken_BoundSubjectMismatch2095=== PAUSE TestValidateToken_BoundSubjectMismatch2096=== RUN TestValidateToken_MultipleProviders2097=== PAUSE TestValidateToken_MultipleProviders2098=== RUN TestValidateToken_NoMatchingProvider2099=== PAUSE TestValidateToken_NoMatchingProvider2100=== RUN TestValidateToken_KubernetesServiceAccount2101=== PAUSE TestValidateToken_KubernetesServiceAccount2102=== RUN TestNewValidator_KubernetesRequiresCA2103=== PAUSE TestNewValidator_KubernetesRequiresCA2104=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2105=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2106=== RUN TestPins_ReservedForMatchingRule2107=== PAUSE TestPins_ReservedForMatchingRule2108=== RUN TestPins_TopLevelShorthand2109=== PAUSE TestPins_TopLevelShorthand2110=== RUN TestPins_ConfigValidation2111=== PAUSE TestPins_ConfigValidation2112=== RUN TestScopes_LegacyProviderDefaultsToWrite2113=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2114=== RUN TestScopes_Rules2115=== PAUSE TestScopes_Rules2116=== RUN TestScopes_ConfigValidation2117=== PAUSE TestScopes_ConfigValidation2118=== CONT TestAudienceForIssuer2119=== CONT TestValidateToken_KubernetesServiceAccount2120=== CONT TestPins_ConfigValidation2121--- PASS: TestAudienceForIssuer (0.00s)2122=== CONT TestValidateToken_NoMatchingProvider2123=== CONT TestValidateToken_MultipleProviders2124=== CONT TestValidateToken_BoundSubjectMismatch2125=== CONT TestValidateToken_BoundClaimsMismatch2126=== CONT TestValidateToken_Expired2127=== CONT TestValidateToken_WrongAudience2128=== CONT TestValidateToken_ValidToken2129=== CONT TestGlobMatch2130=== RUN TestGlobMatch/foo_foo2131=== PAUSE TestGlobMatch/foo_foo2132=== RUN TestGlobMatch/foo_bar2133=== PAUSE TestGlobMatch/foo_bar2134=== RUN TestGlobMatch/*_2135=== PAUSE TestGlobMatch/*_2136=== RUN TestGlobMatch/*_anything2137=== PAUSE TestGlobMatch/*_anything2138=== RUN TestGlobMatch/foo*_foo2139=== PAUSE TestGlobMatch/foo*_foo2140=== RUN TestGlobMatch/foo*_foobar2141=== PAUSE TestGlobMatch/foo*_foobar2142=== RUN TestGlobMatch/foo*_bar2143=== PAUSE TestGlobMatch/foo*_bar2144=== RUN TestGlobMatch/*bar_bar2145=== PAUSE TestGlobMatch/*bar_bar2146=== RUN TestGlobMatch/*bar_foobar2147=== PAUSE TestGlobMatch/*bar_foobar2148=== RUN TestGlobMatch/*bar_foo2149=== PAUSE TestGlobMatch/*bar_foo2150=== RUN TestGlobMatch/foo*bar_foobar2151=== PAUSE TestGlobMatch/foo*bar_foobar2152=== CONT TestScopes_LegacyProviderDefaultsToWrite2153=== CONT TestScopes_ConfigValidation2154=== CONT TestPins_ReservedForMatchingRule2155=== CONT TestPins_TopLevelShorthand2156=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2157=== CONT TestNewValidator_KubernetesRequiresCA2158=== CONT TestScopes_Rules2159--- PASS: TestPins_ConfigValidation (0.00s)2160=== RUN TestGlobMatch/foo*bar_foo123bar2161=== PAUSE TestGlobMatch/foo*bar_foo123bar2162=== RUN TestGlobMatch/foo*bar_foobarbaz2163=== PAUSE TestGlobMatch/foo*bar_foobarbaz2164=== RUN TestGlobMatch/*/*_foo/bar2165=== PAUSE TestGlobMatch/*/*_foo/bar2166=== RUN TestGlobMatch/*/*_foo2167=== PAUSE TestGlobMatch/*/*_foo2168=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2169=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2170=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02171=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02172=== RUN TestGlobMatch/refs/*/main_refs/heads/main2173=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2174=== RUN TestGlobMatch/fo?_foo2175=== PAUSE TestGlobMatch/fo?_foo2176=== RUN TestGlobMatch/fo?_fo2177=== PAUSE TestGlobMatch/fo?_fo2178=== RUN TestGlobMatch/fo?_fooo2179=== PAUSE TestGlobMatch/fo?_fooo2180=== RUN TestGlobMatch/?oo_foo2181=== PAUSE TestGlobMatch/?oo_foo2182=== RUN TestGlobMatch/?oo_boo2183=== PAUSE TestGlobMatch/?oo_boo2184=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2185=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2186=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2187=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2188=== CONT TestGlobMatch/foo_foo2189=== CONT TestGlobMatch/*/*_foo2190=== CONT TestGlobMatch/*bar_bar2191=== CONT TestGlobMatch/*/*_foo/bar2192=== CONT TestGlobMatch/foo*bar_foobarbaz2193=== CONT TestGlobMatch/foo*bar_foo123bar2194=== CONT TestGlobMatch/foo*bar_foobar2195=== CONT TestGlobMatch/*bar_foo2196=== CONT TestGlobMatch/*bar_foobar2197=== CONT TestGlobMatch/fo?_fooo2198=== CONT TestGlobMatch/foo*_foo2199=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2200=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2201=== CONT TestGlobMatch/refs/*/main_refs/heads/main2202=== CONT TestGlobMatch/fo?_fo2203=== CONT TestGlobMatch/fo?_foo2204=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02205=== CONT TestGlobMatch/*_2206=== CONT TestGlobMatch/*_anything2207=== CONT TestGlobMatch/foo*_bar2208=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2209=== CONT TestGlobMatch/foo_bar2210=== CONT TestGlobMatch/?oo_boo2211=== CONT TestGlobMatch/foo*_foobar2212=== CONT TestGlobMatch/?oo_foo2213--- PASS: TestScopes_ConfigValidation (0.00s)2214--- PASS: TestGlobMatch (0.00s)2215 --- PASS: TestGlobMatch/foo_foo (0.00s)2216 --- PASS: TestGlobMatch/*/*_foo (0.00s)2217 --- PASS: TestGlobMatch/*bar_bar (0.00s)2218 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2219 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2220 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2221 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2222 --- PASS: TestGlobMatch/*bar_foo (0.00s)2223 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2224 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2225 --- PASS: TestGlobMatch/foo*_foo (0.00s)2226 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2227 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2228 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2229 --- PASS: TestGlobMatch/fo?_fo (0.00s)2230 --- PASS: TestGlobMatch/fo?_foo (0.00s)2231 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2232 --- PASS: TestGlobMatch/*_ (0.00s)2233 --- PASS: TestGlobMatch/*_anything (0.00s)2234 --- PASS: TestGlobMatch/foo*_bar (0.00s)2235 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2236 --- PASS: TestGlobMatch/foo_bar (0.00s)2237 --- PASS: TestGlobMatch/?oo_boo (0.00s)2238 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2239 --- PASS: TestGlobMatch/?oo_foo (0.00s)22402026/10/07 06:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46291/oidc2241--- PASS: TestValidateToken_Expired (0.03s)22422026/10/07 06:22:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46485/oidc2243--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)22442026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41829/oidc2245--- PASS: TestValidateToken_ValidToken (0.07s)22462026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41625/oidc2247--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)22482026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33749/oidc22492026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46401/oidc2250--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)2251--- PASS: TestScopes_Rules (0.12s)22522026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37031/oidc22532026/10/07 06:22:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43189/oidc2254--- PASS: TestPins_TopLevelShorthand (0.18s)22552026/10/07 06:22:50 http: TLS handshake error from 127.0.0.1:40970: remote error: tls: bad certificate2256--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)2257--- PASS: TestValidateToken_NoMatchingProvider (0.19s)22582026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33949/oidc2259--- PASS: TestPins_ReservedForMatchingRule (0.21s)22602026/10/07 06:22:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41405/oidc22612026/10/07 06:22:50 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38663/oidc2262--- PASS: TestValidateToken_MultipleProviders (0.23s)22632026/10/07 06:22:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232264--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.26s)22652026/10/07 06:22:50 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:355432266--- PASS: TestValidateToken_KubernetesServiceAccount (0.33s)22672026/10/07 06:22:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37005/oidc2268--- PASS: TestValidateToken_WrongAudience (0.54s)2269PASS2270Running hook tests...2271=== RUN TestSendPathsEmpty2272=== PAUSE TestSendPathsEmpty2273=== RUN TestQueueEnqueueAndFetch2274=== PAUSE TestQueueEnqueueAndFetch2275=== RUN TestQueueDeduplication2276=== PAUSE TestQueueDeduplication2277=== RUN TestQueueRemove2278=== PAUSE TestQueueRemove2279=== RUN TestQueueFetchBatchLimit2280=== PAUSE TestQueueFetchBatchLimit2281=== RUN TestQueueRetryMovesToBack2282=== PAUSE TestQueueRetryMovesToBack2283=== RUN TestQueueFetchRemoveLifecycle2284=== PAUSE TestQueueFetchRemoveLifecycle2285=== RUN TestQueueConcurrentWriters2286=== PAUSE TestQueueConcurrentWriters2287=== RUN TestQueueRemoveLargeClosure2288=== PAUSE TestQueueRemoveLargeClosure2289=== RUN TestServerClientIntegration2290--- PASS: TestServerClientIntegration (0.00s)2291=== RUN TestServerQueueError22922026/10/07 06:22:50 ERROR Failed to queue paths error="permission denied" count=12293--- PASS: TestServerQueueError (0.00s)2294=== RUN TestGetListenerSocketActivation2295 server_test.go:219: === RUN TestGetListenerSocketActivation2296 --- PASS: TestGetListenerSocketActivation (0.00s)2297 PASS2298 2299--- PASS: TestGetListenerSocketActivation (0.01s)2300=== RUN TestDrainIsolatesPoisonPath2301=== PAUSE TestDrainIsolatesPoisonPath2302=== RUN TestRunNotBlockedByPoisonHead2303=== PAUSE TestRunNotBlockedByPoisonHead2304=== RUN TestDrainGivesUpWhenServerDown2305=== PAUSE TestDrainGivesUpWhenServerDown2306=== RUN TestFailedPathPrunedByLaterClosure2307=== PAUSE TestFailedPathPrunedByLaterClosure2308=== RUN TestWorkerUploadsAndRemoves2309=== PAUSE TestWorkerUploadsAndRemoves2310=== RUN TestWorkerSkipsGCdPaths2311=== PAUSE TestWorkerSkipsGCdPaths2312=== RUN TestWorkerPrunesClosureDeps2313=== PAUSE TestWorkerPrunesClosureDeps2314=== RUN TestDrainTimeout2315=== PAUSE TestDrainTimeout2316=== CONT TestSendPathsEmpty2317=== CONT TestWorkerSkipsGCdPaths2318--- PASS: TestSendPathsEmpty (0.00s)2319=== CONT TestDrainTimeout2320=== CONT TestWorkerPrunesClosureDeps2321=== CONT TestWorkerUploadsAndRemoves2322=== CONT TestQueueFetchRemoveLifecycle2323=== CONT TestQueueRetryMovesToBack2324=== CONT TestQueueFetchBatchLimit2325=== CONT TestQueueRemove2326=== CONT TestQueueConcurrentWriters2327=== CONT TestQueueDeduplication2328=== CONT TestFailedPathPrunedByLaterClosure2329=== CONT TestQueueEnqueueAndFetch2330=== CONT TestDrainGivesUpWhenServerDown2331=== CONT TestDrainIsolatesPoisonPath2332=== CONT TestQueueRemoveLargeClosure2333=== CONT TestRunNotBlockedByPoisonHead23342026/10/07 06:22:50 INFO Upload queue status pending=223352026/10/07 06:22:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths682095888/002/nonexistent23362026/10/07 06:22:50 INFO Uploading batch count=223372026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=223382026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/a2339--- PASS: TestQueueDeduplication (0.01s)23402026/10/07 06:22:50 INFO Upload queue status pending=323412026/10/07 06:22:50 INFO Upload queue status pending=223422026/10/07 06:22:50 INFO Uploading batch count=223432026/10/07 06:22:50 INFO Upload queue status pending=223442026/10/07 06:22:50 INFO Uploading batch count=123452026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=123462026/10/07 06:22:50 INFO Uploading batch count=223472026/10/07 06:22:50 INFO Uploading batch count=12348--- PASS: TestQueueEnqueueAndFetch (0.01s)23492026/10/07 06:22:50 INFO Uploading batch count=12350--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23512026/10/07 06:22:50 INFO Uploading batch count=423522026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=423532026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/b2354--- PASS: TestQueueRetryMovesToBack (0.01s)23552026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath422567295/002/bbb23562026/10/07 06:22:50 INFO Uploading batch count=123572026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=12358--- PASS: TestQueueRemove (0.01s)23592026/10/07 06:22:50 INFO Uploading batch count=223602026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=223612026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/c2362--- PASS: TestQueueFetchBatchLimit (0.01s)23632026/10/07 06:22:50 INFO Uploading batch count=123642026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/d23652026/10/07 06:22:50 INFO Uploading batch count=123662026/10/07 06:22:50 INFO Uploading batch count=123672026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=123682026/10/07 06:22:50 INFO Uploading batch count=223692026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=223702026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/e23712026/10/07 06:22:50 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown283842025/002/f23722026/10/07 06:22:50 INFO Uploading batch count=123732026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=123742026/10/07 06:22:50 ERROR Drain finished with paths left in queue remaining=1023752026/10/07 06:22:50 INFO Uploading batch count=123762026/10/07 06:22:50 ERROR Upload failed error="upload failed" count=12377--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23782026/10/07 06:22:50 ERROR Drain finished with paths left in queue remaining=12379--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2380--- PASS: TestDrainIsolatesPoisonPath (0.02s)2381--- PASS: TestWorkerPrunesClosureDeps (0.03s)2382--- PASS: TestWorkerSkipsGCdPaths (0.03s)2383--- PASS: TestWorkerUploadsAndRemoves (0.03s)2384--- PASS: TestQueueRemoveLargeClosure (0.10s)2385--- PASS: TestQueueConcurrentWriters (0.15s)23862026/10/07 06:22:50 ERROR Upload failed error="context deadline exceeded" count=223872026/10/07 06:22:50 ERROR Drain finished with paths left in queue remaining=42388--- PASS: TestDrainTimeout (0.21s)23892026/10/07 06:22:51 INFO Uploading batch count=123902026/10/07 06:22:51 INFO Uploading batch count=123912026/10/07 06:22:51 INFO Uploading batch count=123922026/10/07 06:22:51 ERROR Upload failed error="upload failed" count=123932026/10/07 06:22:51 INFO Uploading batch count=123942026/10/07 06:22:51 ERROR Upload failed error="upload failed" count=123952026/10/07 06:22:51 INFO Uploading batch count=123962026/10/07 06:22:51 ERROR Upload failed error="upload failed" count=123972026/10/07 06:22:51 INFO Uploading batch count=123982026/10/07 06:22:51 ERROR Upload failed error="upload failed" count=123992026/10/07 06:22:51 ERROR Drain finished with paths left in queue remaining=12400--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2401PASS2402Running signing tests...2403=== RUN TestExternalSigner2404=== PAUSE TestExternalSigner2405=== RUN TestExternalSignerWrongPublicKey2406=== PAUSE TestExternalSignerWrongPublicKey2407=== RUN TestExternalSignerErrors2408=== PAUSE TestExternalSignerErrors2409=== RUN TestExternalSignerRestartsAfterCrash2410=== PAUSE TestExternalSignerRestartsAfterCrash2411=== RUN TestExternalSignerProgramErrorKeepsProcess2412=== PAUSE TestExternalSignerProgramErrorKeepsProcess2413=== RUN TestExternalSignerClose2414=== PAUSE TestExternalSignerClose2415=== RUN TestExternalSignerRejectsInvalidPublicKey2416=== PAUSE TestExternalSignerRejectsInvalidPublicKey2417=== RUN TestExternalSignerCancellation2418=== PAUSE TestExternalSignerCancellation2419=== RUN TestGenerateFingerprint2420=== PAUSE TestGenerateFingerprint2421=== RUN TestParseSigningKey2422=== PAUSE TestParseSigningKey2423=== RUN TestSign2424=== PAUSE TestSign2425=== RUN TestSignBatch2426=== PAUSE TestSignBatch2427=== RUN TestNilKeyPublicKey2428=== PAUSE TestNilKeyPublicKey2429=== RUN TestSignErrors2430=== PAUSE TestSignErrors2431=== CONT TestExternalSigner2432=== CONT TestExternalSignerCancellation2433=== CONT TestSignBatch2434=== CONT TestGenerateFingerprint2435=== RUN TestGenerateFingerprint/basic_with_references2436=== CONT TestExternalSignerProgramErrorKeepsProcess2437=== CONT TestExternalSignerRejectsInvalidPublicKey2438=== RUN TestExternalSignerRejectsInvalidPublicKey/#002439=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002440=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2441=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2442=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2443=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2444=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2445=== CONT TestExternalSignerClose2446=== CONT TestSignErrors2447=== CONT TestExternalSignerErrors2448=== CONT TestExternalSignerRestartsAfterCrash2449=== CONT TestExternalSignerWrongPublicKey2450=== CONT TestSign2451=== CONT TestNilKeyPublicKey2452--- PASS: TestNilKeyPublicKey (0.00s)2453=== CONT TestParseSigningKey2454=== PAUSE TestGenerateFingerprint/basic_with_references2455=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2456=== RUN TestExternalSignerErrors/exit_at_startup2457=== PAUSE TestExternalSignerErrors/exit_at_startup2458=== RUN TestParseSigningKey/valid_32-byte_key2459=== RUN TestGenerateFingerprint/no_references2460=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2461=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2462=== RUN TestExternalSignerErrors/wrong_shape2463=== PAUSE TestExternalSignerErrors/wrong_shape2464=== RUN TestExternalSignerErrors/wrong_id2465=== PAUSE TestExternalSignerErrors/wrong_id2466=== RUN TestExternalSignerErrors/wrong_signature_name2467=== PAUSE TestExternalSignerErrors/wrong_signature_name2468=== RUN TestExternalSignerErrors/wrong_signature_length2469=== PAUSE TestExternalSignerErrors/wrong_signature_length2470=== RUN TestExternalSignerErrors/program_error2471=== PAUSE TestExternalSignerErrors/program_error2472=== PAUSE TestParseSigningKey/valid_32-byte_key2473=== PAUSE TestGenerateFingerprint/no_references2474=== CONT TestExternalSignerRejectsInvalidPublicKey/#002475=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2476=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2477=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2478=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2479=== RUN TestExternalSignerErrors/wrong_signatures_shape2480=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2481=== RUN TestExternalSignerErrors/invalid_signature_base642482=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2483=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2484=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2485=== PAUSE TestExternalSignerErrors/invalid_signature_base642486--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2487 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2488 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2489 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2490 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2491 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2492=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2493=== RUN TestParseSigningKey/no_colon2494=== PAUSE TestParseSigningKey/no_colon2495=== RUN TestParseSigningKey/empty_name2496=== PAUSE TestParseSigningKey/empty_name2497=== RUN TestParseSigningKey/invalid_base642498=== RUN TestExternalSignerErrors/invalid_JSON2499=== PAUSE TestExternalSignerErrors/invalid_JSON2500=== RUN TestExternalSignerErrors/missing_signatures2501=== PAUSE TestExternalSignerErrors/missing_signatures2502=== RUN TestExternalSignerErrors/unrequested_key2503=== PAUSE TestExternalSignerErrors/unrequested_key2504=== RUN TestExternalSignerErrors/missing_signature_name2505=== PAUSE TestExternalSignerErrors/missing_signature_name2506=== RUN TestExternalSignerErrors/exit_on_request2507=== PAUSE TestExternalSignerErrors/exit_on_request2508=== RUN TestExternalSignerErrors/null2509=== PAUSE TestExternalSignerErrors/null2510=== RUN TestExternalSignerErrors/null_signatures2511=== PAUSE TestExternalSignerErrors/null_signatures2512=== RUN TestExternalSignerErrors/too_few_signatures2513=== PAUSE TestExternalSignerErrors/too_few_signatures2514=== CONT TestExternalSignerErrors/exit_at_startup2515=== CONT TestExternalSignerErrors/exit_on_request2516=== RUN TestSignErrors/nil_key2517=== PAUSE TestSignErrors/nil_key2518=== RUN TestSignErrors/nil_narinfo2519=== CONT TestExternalSignerErrors/wrong_signatures_shape2520=== CONT TestExternalSignerErrors/invalid_signature_base642521=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2522=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2523=== RUN TestGenerateFingerprint/invalid_nar_hash_length2524=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2525--- PASS: TestSign (0.00s)2526=== CONT TestExternalSignerErrors/missing_signature_name2527=== PAUSE TestSignErrors/nil_narinfo2528=== RUN TestSignErrors/invalid_narinfo2529=== PAUSE TestSignErrors/invalid_narinfo2530=== RUN TestSignErrors/canceled2531=== PAUSE TestSignErrors/canceled2532=== PAUSE TestParseSigningKey/invalid_base642533=== RUN TestParseSigningKey/wrong_length2534=== CONT TestExternalSignerErrors/too_few_signatures2535=== RUN TestGenerateFingerprint/invalid_store_path_prefix2536=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2537=== CONT TestExternalSignerErrors/null_signatures2538=== CONT TestExternalSignerErrors/null2539=== CONT TestExternalSignerErrors/wrong_signature_name2540=== CONT TestExternalSignerErrors/program_error2541=== CONT TestExternalSignerErrors/wrong_signature_length2542=== CONT TestExternalSignerErrors/invalid_JSON2543=== CONT TestExternalSignerErrors/wrong_id2544=== CONT TestSignErrors/nil_key2545=== CONT TestSignErrors/invalid_narinfo2546=== CONT TestExternalSignerErrors/missing_signatures2547=== CONT TestExternalSignerErrors/unrequested_key2548=== CONT TestSignErrors/canceled2549=== RUN TestGenerateFingerprint/invalid_reference_prefix2550--- PASS: TestSignBatch (0.00s)2551=== CONT TestExternalSignerErrors/wrong_shape2552=== PAUSE TestParseSigningKey/wrong_length2553=== CONT TestParseSigningKey/valid_32-byte_key2554=== CONT TestParseSigningKey/invalid_base642555--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2556=== CONT TestSignErrors/nil_narinfo2557=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2558=== CONT TestParseSigningKey/wrong_length2559=== CONT TestGenerateFingerprint/invalid_reference_prefix2560=== CONT TestGenerateFingerprint/invalid_store_path_prefix2561=== CONT TestParseSigningKey/no_colon2562=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2563=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2564=== CONT TestParseSigningKey/empty_name2565=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2566--- PASS: TestExternalSignerWrongPublicKey (0.00s)2567--- PASS: TestExternalSignerClose (0.00s)2568=== CONT TestGenerateFingerprint/basic_with_references2569=== CONT TestGenerateFingerprint/invalid_nar_hash_length2570=== CONT TestGenerateFingerprint/no_references2571--- PASS: TestSignErrors (0.00s)2572 --- PASS: TestSignErrors/nil_key (0.00s)2573 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2574 --- PASS: TestSignErrors/canceled (0.00s)2575 --- PASS: TestSignErrors/nil_narinfo (0.00s)2576--- PASS: TestParseSigningKey (0.00s)2577 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2578 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2579 --- PASS: TestParseSigningKey/wrong_length (0.00s)2580 --- PASS: TestParseSigningKey/no_colon (0.00s)2581 --- PASS: TestParseSigningKey/empty_name (0.00s)2582 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2583--- PASS: TestGenerateFingerprint (0.01s)2584 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2585 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2586 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2587 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2588 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2589 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2590 --- PASS: TestGenerateFingerprint/no_references (0.00s)2591--- PASS: TestExternalSigner (0.01s)2592--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2593--- PASS: TestExternalSignerErrors (0.00s)2594 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2595 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2596 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2597 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2598 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2599 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2600 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2601 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2602 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2603 --- PASS: TestExternalSignerErrors/program_error (0.01s)2604 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2605 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2606 --- PASS: TestExternalSignerErrors/null (0.01s)2607 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2608 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2609 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2610--- PASS: TestExternalSignerCancellation (0.02s)2611PASS2612Running OpenBao signer tests...2613=== RUN TestSign2614=== PAUSE TestSign2615=== RUN TestSignErrors2616=== PAUSE TestSignErrors2617=== RUN TestServe2618=== PAUSE TestServe2619=== RUN TestServeRejectsGarbage2620=== PAUSE TestServeRejectsGarbage2621=== CONT TestSign2622=== CONT TestServeRejectsGarbage2623=== CONT TestServe2624=== CONT TestSignErrors2625--- PASS: TestServeRejectsGarbage (0.00s)2626=== RUN TestSignErrors/http_error2627=== PAUSE TestSignErrors/http_error2628=== RUN TestSignErrors/invalid_json2629=== PAUSE TestSignErrors/invalid_json2630=== RUN TestSignErrors/no_prefix2631=== PAUSE TestSignErrors/no_prefix2632=== RUN TestSignErrors/invalid_base642633=== PAUSE TestSignErrors/invalid_base642634=== CONT TestSignErrors/http_error2635=== CONT TestSignErrors/no_prefix2636=== CONT TestSignErrors/invalid_json2637--- PASS: TestServe (0.00s)2638=== CONT TestSignErrors/invalid_base642639--- PASS: TestSign (0.00s)2640--- PASS: TestSignErrors (0.00s)2641 --- PASS: TestSignErrors/invalid_base64 (0.00s)2642 --- PASS: TestSignErrors/invalid_json (0.00s)2643 --- PASS: TestSignErrors/no_prefix (0.00s)2644 --- PASS: TestSignErrors/http_error (0.00s)2645PASS