niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #397
· 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 TestStreamPushStopsWhenCanceled74=== PAUSE TestStreamPushStopsWhenCanceled75=== RUN TestSetClientTLS76=== PAUSE TestSetClientTLS77=== RUN TestSetClientTLSDoesNotMutateDefaultTransport78=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport79=== RUN TestSetClientTLSErrors80=== PAUSE TestSetClientTLSErrors81=== RUN TestStaticToken82=== PAUSE TestStaticToken83=== RUN TestFileTokenReadsAndCaches84=== PAUSE TestFileTokenReadsAndCaches85=== RUN TestFileTokenMissing86=== PAUSE TestFileTokenMissing87=== RUN TestFileTokenEmpty88=== PAUSE TestFileTokenEmpty89=== RUN TestScriptTokenNoExpiryRerunsEveryCall90=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall91=== RUN TestScriptTokenCachesUntilRefresh92=== PAUSE TestScriptTokenCachesUntilRefresh93=== RUN TestScriptTokenEmptyToken94=== PAUSE TestScriptTokenEmptyToken95=== RUN TestScriptTokenBadJSON96=== PAUSE TestScriptTokenBadJSON97=== RUN TestScriptTokenScriptFails98=== PAUSE TestScriptTokenScriptFails99=== RUN TestScriptTokenEmptyCommand100=== PAUSE TestScriptTokenEmptyCommand101=== CONT TestDoServerRequestAttachesToken102=== CONT TestScriptTokenBadJSON103=== CONT TestScriptTokenEmptyCommand104--- PASS: TestScriptTokenEmptyCommand (0.00s)105=== CONT TestStreamPushIsolatesFailures106=== CONT TestScriptTokenScriptFails107=== CONT TestStreamPushStopsWhenCanceled108--- PASS: TestStreamPushStopsWhenCanceled (0.00s)109=== CONT TestScriptTokenEmptyToken110=== CONT TestStreamPushBatchesUnderLoad111=== CONT TestScriptTokenCachesUntilRefresh1122026/10/08 12:57:14 ERROR Upload failed error="bad path" count=3113=== CONT TestScriptTokenNoExpiryRerunsEveryCall114=== CONT TestFileTokenEmpty115--- PASS: TestScriptTokenScriptFails (0.00s)116=== CONT TestFileTokenMissing117=== CONT TestFileTokenReadsAndCaches118=== CONT TestStaticToken119=== CONT TestSetClientTLSErrors120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121=== CONT TestResolveStorePath122=== CONT TestSetClientTLS123=== CONT TestClientSignaturesByStorePath124=== CONT TestUploadMultipart_PartsInParallel125=== CONT TestStreamPushReportsSignatures126=== CONT TestDumpPathSingleFile127=== CONT TestStreamPushRequestLine128=== CONT TestDumpPathMatchesNix129=== CONT TestStreamPushGivesUpOnDeadServer130=== CONT TestUploadMultipart_SupersededByPeer131=== CONT TestStreamPushReportsEveryPath132--- PASS: TestStaticToken (0.00s)133--- PASS: TestFileTokenMissing (0.00s)134--- PASS: TestFileTokenEmpty (0.00s)135=== CONT TestShellSplit136--- PASS: TestScriptTokenBadJSON (0.00s)137=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun138=== CONT TestDoWithRetry_BodyReplayedViaGetBody139--- PASS: TestShellSplit (0.00s)140=== CONT TestPartSizeForNAR141--- PASS: TestStreamPushIsolatesFailures (0.00s)142=== RUN TestPartSizeForNAR/zero_stays_at_minimum143=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum144=== RUN TestPartSizeForNAR/small_stays_at_minimum145=== CONT TestFilterOversizedClosures146=== RUN TestFilterOversizedClosures/no_limit_keeps_everything147--- PASS: TestClientSignaturesByStorePath (0.00s)148=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica149=== PAUSE TestPartSizeForNAR/small_stays_at_minimum150=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything151=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum152=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum153=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped154=== CONT TestCaseHackSuffix155=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts156--- PASS: TestFileTokenReadsAndCaches (0.00s)157--- PASS: TestScriptTokenEmptyToken (0.01s)158--- PASS: TestResolveStorePath (0.00s)159=== CONT TestShellSplitErrors160--- PASS: TestShellSplitErrors (0.00s)161=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1622026/10/08 12:57:14 ERROR Upload failed error=boom count=1163=== RUN TestFilterOversizedClosures/all_closures_skipped1642026/10/08 12:57:14 ERROR Upload failed error="connection refused" count=20165=== PAUSE TestFilterOversizedClosures/all_closures_skipped1662026/10/08 12:57:14 ERROR Server seems unavailable, giving up on batch untried=17167=== CONT TestParsePathInfoJSON168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts170=== CONT TestRateLimiterFeedback171=== RUN TestRateLimiterFeedback/429_enables_limiter1722026/10/08 12:57:14 ERROR Upload failed error=boom count=1173=== RUN TestUploadMultipart_SupersededByPeer/exists174=== CONT TestConvertHashToNix321752026/10/08 12:57:14 WARN Rate limiter enabled after throttle name=server-test rate=5176=== RUN TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestParsePathInfoJSON/Nix_format178=== RUN TestPartSizeForNAR/1_TiB179=== PAUSE TestPartSizeForNAR/1_TiB180--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)181--- PASS: TestStreamPushReportsSignatures (0.03s)182=== CONT TestPathInfoHashCompatibility183=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1842026/10/08 12:57:14 WARN Rate limiter enabled after throttle name=server-test rate=5185=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1862026/10/08 12:57:14 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37943187=== PAUSE TestRateLimiterFeedback/429_enables_limiter1882026/10/08 12:57:14 INFO Garbage collection started189=== CONT TestPathInfoCACompatibility1902026/10/08 12:57:14 INFO Garbage collection started191=== RUN TestPathInfoCACompatibility/null_ca_field1922026/10/08 12:57:14 WARN Rate limiter backed off name=server-test rate=5193=== PAUSE TestPathInfoCACompatibility/null_ca_field1942026/10/08 12:57:14 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37943195=== RUN TestPathInfoCACompatibility/old_string_format_-_text196=== PAUSE TestUploadMultipart_SupersededByPeer/exists197=== RUN TestUploadMultipart_SupersededByPeer/missing198=== CONT TestParsePathInfoJSONMultiplePaths199=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths200=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== CONT TestGetStorePathHash202=== RUN TestGetStorePathHash/valid_store_path203=== PAUSE TestGetStorePathHash/valid_store_path204=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32205=== RUN TestConvertHashToNix32/already_Nix32_format206=== PAUSE TestConvertHashToNix32/already_Nix32_format207=== RUN TestConvertHashToNix32/invalid_format208=== PAUSE TestConvertHashToNix32/invalid_format209=== PAUSE TestParsePathInfoJSON/Nix_format210=== RUN TestParsePathInfoJSON/Lix_format211=== PAUSE TestParsePathInfoJSON/Lix_format212=== RUN TestParsePathInfoJSON/empty_input213=== PAUSE TestParsePathInfoJSON/empty_input214=== RUN TestParsePathInfoJSON/whitespace_only215=== PAUSE TestParsePathInfoJSON/whitespace_only216=== RUN TestParsePathInfoJSON/invalid_JSON217=== PAUSE TestParsePathInfoJSON/invalid_JSON218=== CONT TestRegisterUploadedObjectReusesConnections219=== CONT TestEncodeNixBase32220=== RUN TestEncodeNixBase32/test_string_hash221=== PAUSE TestEncodeNixBase32/test_string_hash222=== RUN TestEncodeNixBase32/empty_input223=== PAUSE TestEncodeNixBase32/empty_input224=== RUN TestPartSizeForNAR/5_TiB_S3_max_object225=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object226=== RUN TestPartSizeForNAR/capped_at_5_GiB227=== PAUSE TestPartSizeForNAR/capped_at_5_GiB228=== CONT TestDumpPathWriterError229=== RUN TestSetClientTLSErrors/missing_cert_file230=== PAUSE TestSetClientTLSErrors/missing_cert_file231=== RUN TestSetClientTLSErrors/missing_key_file232--- PASS: TestStreamPushReportsEveryPath (0.03s)233=== CONT TestFilterOversizedClosures/no_limit_keeps_everything234=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped235=== PAUSE TestSetClientTLSErrors/missing_key_file2362026/10/08 12:57:14 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=2000237=== RUN TestSetClientTLSErrors/missing_ca_file238=== CONT TestConvertHashToNix32/SRI_format_to_Nix32239=== CONT TestParsePathInfoJSON/Nix_format240--- PASS: TestDoServerRequestAttachesToken (0.03s)241=== RUN TestRateLimiterFeedback/503_enables_limiter242=== PAUSE TestRateLimiterFeedback/503_enables_limiter243=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter244=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter245=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter246=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter247--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)248--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)249=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text250=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive251=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== RUN TestPathInfoCACompatibility/new_structured_format_-_text253=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text254=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method256=== CONT TestEncodeNixBase32/test_string_hash257=== CONT TestConvertHashToNix32/invalid_format258=== CONT TestParsePathInfoJSON/invalid_JSON259=== CONT TestParsePathInfoJSON/whitespace_only260=== CONT TestParsePathInfoJSON/empty_input261=== CONT TestParsePathInfoJSON/Lix_format262=== CONT TestPartSizeForNAR/5_TiB_S3_max_object263=== CONT TestEncodeNixBase32/empty_input264--- PASS: TestEncodeNixBase32 (0.00s)265 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)266 --- PASS: TestEncodeNixBase32/empty_input (0.00s)267=== PAUSE TestSetClientTLSErrors/missing_ca_file268=== CONT TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestPathInfoCACompatibility/null_ca_field270=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter271=== RUN TestSetClientTLS/rejects_connection_without_client_cert272=== CONT TestRateLimiterFeedback/429_enables_limiter2732026/10/08 12:57:14 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=0274=== CONT TestEncodeNixBase32WithRealHash275=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter276=== 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=== CONT TestRateLimiterFeedback/503_enables_limiter2822026/10/08 12:57:14 WARN Rate limiter enabled after throttle name=server-test rate=52832026/10/08 12:57:14 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:41873284=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error285=== CONT TestFilterOversizedClosures/all_closures_skipped2862026/10/08 12:57:14 WARN Rate limiter backed off name=server-test rate=5287=== RUN TestSetClientTLSErrors/invalid_ca_file288=== PAUSE TestSetClientTLSErrors/invalid_ca_file289=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2902026/10/08 12:57:14 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=50291=== CONT TestConvertHashToNix32/already_Nix32_format292=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum2932026/10/08 12:57:14 WARN Rate limiter enabled after throttle name=server-test rate=5294=== CONT TestGetStorePathHash/valid_store_path2952026/10/08 12:57:14 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:45897296=== CONT TestPartSizeForNAR/small_stays_at_minimum297=== CONT TestSetClientTLSErrors/missing_cert_file298=== CONT TestSetClientTLSErrors/invalid_ca_file2992026/10/08 12:57:14 WARN Rate limiter backed off name=server-test rate=5300=== CONT TestPartSizeForNAR/zero_stays_at_minimum301=== CONT TestSetClientTLSErrors/missing_ca_file302=== CONT TestSetClientTLSErrors/missing_key_file3032026/10/08 12:57:14 WARN Garbage collection finished on another replica. Its statistics are not available here304=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error305=== CONT TestGetStorePathHash/basename_without_hyphen_should_error306=== PAUSE TestUploadMultipart_SupersededByPeer/missing307=== CONT TestUploadMultipart_SupersededByPeer/exists308=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error309=== CONT TestUploadMultipart_SupersededByPeer/missing310=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths311--- PASS: TestParsePathInfoJSON (0.00s)312 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)313 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)314 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)315 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)316 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)317=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert318=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon319=== CONT TestPathInfoCACompatibility/new_structured_format_-_text320=== CONT TestPathInfoCACompatibility/old_string_format_-_text321=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts322=== CONT TestPartSizeForNAR/1_TiB323=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive324=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths325=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths326--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)327--- PASS: TestEncodeNixBase32WithRealHash (0.00s)328--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)329=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA330=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA331=== RUN TestSetClientTLS/preserves_debug_logging_transport332=== PAUSE TestSetClientTLS/preserves_debug_logging_transport333=== CONT TestSetClientTLS/rejects_connection_without_client_cert334=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon335=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI336=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI337=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512338=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512339=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)340--- PASS: TestGetStorePathHash (0.00s)341 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)342 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)343 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)345--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)346=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths347--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)348--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)351--- PASS: TestConvertHashToNix32 (0.00s)352 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)353 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)354 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)355--- PASS: TestFilterOversizedClosures (0.03s)356 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)357 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)358 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)359--- PASS: TestPathInfoCACompatibility (0.00s)360 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)361 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)362 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)365--- PASS: TestPartSizeForNAR (0.03s)366 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)367 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)368 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373--- PASS: TestRateLimiterFeedback (0.00s)374 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)375 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)376 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)377 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)378=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512379=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI380=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon381--- PASS: TestPathInfoHashCompatibility (0.01s)382 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)383 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)384 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)385 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)386=== CONT TestSetClientTLS/preserves_debug_logging_transport387--- PASS: TestSetClientTLSErrors (0.03s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)390 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)392=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA393--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)394 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)395 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3962026/10/08 12:57:14 http: TLS handshake error from 127.0.0.1:36412: remote error: tls: bad certificate397--- PASS: TestSetClientTLS (0.03s)398 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)399 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)400 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)401--- PASS: TestDumpPathSingleFile (0.06s)402--- PASS: TestCaseHackSuffix (0.03s)403--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)404--- PASS: TestStreamPushRequestLine (0.06s)405--- PASS: TestDumpPathWriterError (0.05s)406--- PASS: TestStreamPushBatchesUnderLoad (0.10s)407--- PASS: TestDumpPathMatchesNix (0.12s)408--- PASS: TestUploadMultipart_PartsInParallel (0.65s)409--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)410PASS411Running server tests...412The files belonging to this database system will be owned by user "nixbld".413This user must also own the server process.414415The database cluster will be initialized with locale "C".416The default database encoding has accordingly been set to "SQL_ASCII".417The default text search configuration will be set to "english".418419Data page checksums are enabled.420421creating directory /build/postgres362141886/data ... ok422creating subdirectories ... ok423selecting dynamic shared memory implementation ... posix424selecting default "max_connections" ... 100425selecting default "shared_buffers" ... 128MB426selecting default time zone ... UTC427creating configuration files ... ok428running bootstrap script ... ok429performing post-bootstrap initialization ... ok430syncing data to disk ... ok431432initdb: warning: enabling "trust" authentication for local connections433initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.434435Success. You can now start the database server using:436437 pg_ctl -D /build/postgres362141886/data -l logfile start438439/build/postgres362141886:5432 - no response4402026-10-08 12:57:16.031 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4412026-10-08 12:57:16.032 UTC [129] LOG: listening on Unix socket "/build/postgres362141886/.s.PGSQL.5432"4422026-10-08 12:57:16.036 UTC [136] LOG: database system was shut down at 2026-10-08 12:57:15 UTC4432026-10-08 12:57:16.040 UTC [129] LOG: database system is ready to accept connections444/build/postgres362141886:5432 - accepting connections445{"timestamp":"2026-10-08T12:57:16.335389038Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"50ff66cd-753c-42fe-9b64-3b25a7042f61","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}446=== RUN TestService_AuthMiddleware447=== PAUSE TestService_AuthMiddleware448=== RUN TestService_AuthMiddleware_MTLSProxyHeader449=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader450=== RUN TestService_AuthMiddleware_MTLSBoundSubjects451=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects452=== RUN TestService_ReadAuthMiddleware453=== PAUSE TestService_ReadAuthMiddleware454=== RUN TestService_AuthMiddleware_OIDC455=== PAUSE TestService_AuthMiddleware_OIDC456=== RUN TestService_RequireScope_OIDC457=== PAUSE TestService_RequireScope_OIDC458=== RUN TestService_ReadScope_PublicByDefault459=== PAUSE TestService_ReadScope_PublicByDefault460=== RUN TestCacheConfigHandler461=== PAUSE TestCacheConfigHandler462=== RUN TestCacheStatsHandler463=== PAUSE TestCacheStatsHandler464=== RUN TestClientCADerivations465=== PAUSE TestClientCADerivations466=== RUN TestClientErrorHandling467=== PAUSE TestClientErrorHandling468=== RUN TestClientIntegration469=== PAUSE TestClientIntegration470=== RUN TestClientMultipleUploads471=== PAUSE TestClientMultipleUploads472=== RUN TestClientWithDependencies473=== PAUSE TestClientWithDependencies474=== RUN TestClientSharedPathCommittedMidPush475=== PAUSE TestClientSharedPathCommittedMidPush476=== RUN TestPinProtectsFromGC477=== PAUSE TestPinProtectsFromGC478=== RUN TestClientPushesUseOnePush479=== PAUSE TestClientPushesUseOnePush480=== RUN TestClientFallsBackToClosures481=== PAUSE TestClientFallsBackToClosures482=== RUN TestDeleteClosuresRacingPins483=== PAUSE TestDeleteClosuresRacingPins484=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock485=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock486=== RUN TestResolveDBConnectionString487=== PAUSE TestResolveDBConnectionString488=== RUN TestConnectWaitsForAPeerMigration489=== PAUSE TestConnectWaitsForAPeerMigration490=== RUN TestLeadElectsOneAndHandsOver491=== PAUSE TestLeadElectsOneAndHandsOver492=== RUN TestLeadIncumbentWinsAfterRestart4932026/10/08 12:57:16 INFO lead: acquired remote=192.0.2.1:12344942026/10/08 12:57:17 INFO lead: released remote=192.0.2.1:12344952026/10/08 12:57:17 INFO lead: acquired remote=192.0.2.1:12344962026/10/08 12:57:18 INFO lead: released remote=192.0.2.1:1234497--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)498=== RUN TestLeadIncumbentAnnouncesAtOnce499=== PAUSE TestLeadIncumbentAnnouncesAtOnce500=== RUN TestLeadEndsOnShutdown501=== PAUSE TestLeadEndsOnShutdown502=== RUN TestLeadEndsWhenItsConnectionHangs5032026/10/08 12:57:18 INFO lead: acquired remote=192.0.2.1:12345042026-10-08 12:57:19.854 UTC [382] FATAL: terminating connection due to administrator command5052026/10/08 12:57:20 INFO lead: acquired remote=192.0.2.1:12345062026/10/08 12:57:21 WARN lead: lock connection lost error="timeout: context deadline exceeded"5072026/10/08 12:57:21 INFO lead: released remote=192.0.2.1:12345082026/10/08 12:57:21 INFO lead: released remote=192.0.2.1:1234509--- PASS: TestLeadEndsWhenItsConnectionHangs (3.12s)510=== RUN TestGCAdvisoryLockBlocksConcurrentRun511=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun512=== RUN TestGCBugBareHashReferences513=== PAUSE TestGCBugBareHashReferences514=== RUN TestGCMetrics515=== PAUSE TestGCMetrics516=== RUN TestPushDedupSurvivesConcurrentGC517=== PAUSE TestPushDedupSurvivesConcurrentGC518=== RUN TestDeduplicatedObjectsRecordedAsPending519=== PAUSE TestDeduplicatedObjectsRecordedAsPending520=== RUN TestGCSweepSkipsPendingObjects521=== PAUSE TestGCSweepSkipsPendingObjects522=== RUN TestTombstonedObjectOfferedWithoutWaiting523=== PAUSE TestTombstonedObjectOfferedWithoutWaiting524=== RUN TestGCSweepDeliversEachKeyOnce525=== PAUSE TestGCSweepDeliversEachKeyOnce526=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection527=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection528=== RUN TestForceGCDuringPushOffersSweptObject529=== PAUSE TestForceGCDuringPushOffersSweptObject530=== RUN TestFailedS3DeleteKeepsTombstone531=== PAUSE TestFailedS3DeleteKeepsTombstone532=== RUN TestSweepSkipsRowsLockedByPush533=== PAUSE TestSweepSkipsRowsLockedByPush534=== RUN TestRegisterCompletedObjectNeedsPendingRow535=== PAUSE TestRegisterCompletedObjectNeedsPendingRow536=== RUN TestGetExistingObjectsLocksRows537=== PAUSE TestGetExistingObjectsLocksRows538=== RUN TestSweepRechecksPendingAfterLocking539=== PAUSE TestSweepRechecksPendingAfterLocking540=== RUN TestPushWaitsForSweepHoldingRow541=== PAUSE TestPushWaitsForSweepHoldingRow542=== RUN TestCommitRacingPendingCleanupKeepsObjects543=== PAUSE TestCommitRacingPendingCleanupKeepsObjects544=== RUN TestGCEndsOnShutdown545=== PAUSE TestGCEndsOnShutdown546=== RUN TestGCTaskStore_StartNew547=== PAUSE TestGCTaskStore_StartNew548=== RUN TestGCTaskStore_DeduplicateSameParams549=== PAUSE TestGCTaskStore_DeduplicateSameParams550=== RUN TestGCTaskStore_ConflictDifferentParams551=== PAUSE TestGCTaskStore_ConflictDifferentParams552=== RUN TestGCTaskStore_GetEmpty553=== PAUSE TestGCTaskStore_GetEmpty554=== RUN TestGCTaskStore_GetReturnsLatest555=== PAUSE TestGCTaskStore_GetReturnsLatest556=== RUN TestGCTaskStore_CompletedAllowsNewTask557=== PAUSE TestGCTaskStore_CompletedAllowsNewTask558=== RUN TestGCTaskStore_PhaseUpdates559=== PAUSE TestGCTaskStore_PhaseUpdates560=== RUN TestGCTaskStore_Fail561=== PAUSE TestGCTaskStore_Fail562=== RUN TestGracefulShutdownDrainsInflight563=== PAUSE TestGracefulShutdownDrainsInflight564=== RUN TestService_healthCheckHandler565=== PAUSE TestService_healthCheckHandler566=== RUN TestService_readinessHandler567=== PAUSE TestService_readinessHandler568=== RUN TestGenerateLandingPage569=== PAUSE TestGenerateLandingPage570=== RUN TestCacheConfigHandlerMaxNarSize571=== PAUSE TestCacheConfigHandlerMaxNarSize572=== RUN TestCreatePendingClosureRejectsOversizedNAR573=== PAUSE TestCreatePendingClosureRejectsOversizedNAR574=== RUN TestNARDeduplicationMetadataUploadBug575=== PAUSE TestNARDeduplicationMetadataUploadBug576=== RUN TestMetricsInventory577=== PAUSE TestMetricsInventory578=== RUN TestMetricsCommit579=== PAUSE TestMetricsCommit580=== RUN TestService_NativeMTLS581=== PAUSE TestService_NativeMTLS582=== RUN TestServerTLSConfig583=== PAUSE TestServerTLSConfig584=== RUN TestMultipartCleanup585=== PAUSE TestMultipartCleanup586=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded587=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded588=== RUN TestPendingCleanupUsesOneCutoff589=== PAUSE TestPendingCleanupUsesOneCutoff590=== RUN TestObjectStatsTrigger591=== PAUSE TestObjectStatsTrigger592=== RUN TestObjectStatsLargeCommit593=== PAUSE TestObjectStatsLargeCommit594=== RUN TestOrphanedObjectsGC595=== PAUSE TestOrphanedObjectsGC596=== RUN TestOrphanedObjectsGCStressTest597=== PAUSE TestOrphanedObjectsGCStressTest598=== RUN TestCreatePin_ReservedPins599=== PAUSE TestCreatePin_ReservedPins600=== RUN TestPresentReportsOnlyClosureRoots601=== PAUSE TestPresentReportsOnlyClosureRoots602=== RUN TestPresentRefreshesOnlyStaleClosures603=== PAUSE TestPresentRefreshesOnlyStaleClosures604=== RUN TestPresentNotReportedWhileGCDeletesClosure605=== PAUSE TestPresentNotReportedWhileGCDeletesClosure606=== RUN TestParseSingleRange607=== PAUSE TestParseSingleRange608=== RUN TestProxyHeadersOnlyTrustedOnSocket6092026/10/08 12:57:21 INFO Starting HTTP server address=127.0.0.1:356496102026/10/08 12:57:21 INFO Starting HTTP server address=proxy.sock6112026/10/08 12:57:21 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6122026/10/08 12:57:21 INFO Shutdown signal received, draining in-flight requests timeout=10s613--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.13s)614=== RUN TestIsValidCachePath615=== PAUSE TestIsValidCachePath616=== RUN TestReadProxyNarinfo617=== PAUSE TestReadProxyNarinfo618=== RUN TestReadProxyNarinfoAlreadyDecompressed619=== PAUSE TestReadProxyNarinfoAlreadyDecompressed620=== RUN TestReadProxyContentNegotiation621=== PAUSE TestReadProxyContentNegotiation622=== RUN TestReadProxyNarStreaming623=== PAUSE TestReadProxyNarStreaming624=== RUN TestReadProxy404625=== PAUSE TestReadProxy404626=== RUN TestReadProxyInvalidPath627=== PAUSE TestReadProxyInvalidPath628=== RUN TestReadProxyHead629=== PAUSE TestReadProxyHead630=== RUN TestReadProxyOutlastsServerWriteTimeout631=== PAUSE TestReadProxyOutlastsServerWriteTimeout632=== RUN TestReadProxyConditionalGet633=== PAUSE TestReadProxyConditionalGet634=== RUN TestReadProxyRootRedirectsToIndexHTML635=== PAUSE TestReadProxyRootRedirectsToIndexHTML636=== RUN TestReadProxyDisabled637=== PAUSE TestReadProxyDisabled638=== RUN TestReadRedirectNar639=== PAUSE TestReadRedirectNar640=== RUN TestReadRedirectKeepsNarinfoProxied641=== PAUSE TestReadRedirectKeepsNarinfoProxied642=== RUN TestReadProxyRangeRequest643=== PAUSE TestReadProxyRangeRequest644=== RUN TestReadRedirectUsesPublicS3URL645=== PAUSE TestReadRedirectUsesPublicS3URL646=== RUN TestPush_OverlappingRootsStoreOneRowPerKey647=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey648=== RUN TestPush_CompleteCommitsEveryRoot649=== PAUSE TestPush_CompleteCommitsEveryRoot650=== RUN TestPush_RepeatedRootCommitsOnce651=== PAUSE TestPush_RepeatedRootCommitsOnce652=== RUN TestPush_CompleteWaitsForCleanupOfThePush653=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush654=== RUN TestPush_RootsAreLockedInByteOrder655=== PAUSE TestPush_RootsAreLockedInByteOrder656=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit657=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit658=== RUN TestPush_RejectsBadRequests659=== PAUSE TestPush_RejectsBadRequests660=== RUN TestPush_SignsNarinfosOfItsPendingObjects661=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects662=== RUN TestRedundantMultipartUpload663=== PAUSE TestRedundantMultipartUpload664=== RUN TestCompleteMultipartUpload_ErrorButObjectExists665=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists666=== RUN TestCompletedNarNotReofferedAcrossClosures667=== PAUSE TestCompletedNarNotReofferedAcrossClosures668=== RUN TestPresignedUploadRegisteredBeforeCommit669=== PAUSE TestPresignedUploadRegisteredBeforeCommit670=== RUN TestService_Rustfstest671=== PAUSE TestService_Rustfstest672=== RUN TestParseSize673=== PAUSE TestParseSize674=== RUN TestSkippedUploadsHandler675=== PAUSE TestSkippedUploadsHandler676=== RUN TestSystemdListenerNotActivated677--- PASS: TestSystemdListenerNotActivated (0.00s)678=== RUN TestWatchdogBeatsWhenHealthy679--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)680=== RUN TestWatchdogSkipsWhenUnhealthy6812026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6872026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6882026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6892026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6902026/10/08 12:57:21 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"691--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)692=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle693=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle694=== RUN TestProxyWriteTimeout695=== PAUSE TestProxyWriteTimeout696=== RUN TestPendingClosureWriteTimeout697=== PAUSE TestPendingClosureWriteTimeout698=== RUN TestIsValidUploadKey699=== PAUSE TestIsValidUploadKey700=== RUN TestUploadHandlersRejectInvalidKeys701=== PAUSE TestUploadHandlersRejectInvalidKeys702=== RUN TestUploadHandlersRejectOversizedBody703=== PAUSE TestUploadHandlersRejectOversizedBody704=== RUN TestService_cleanupPendingClosuresHandler705=== PAUSE TestService_cleanupPendingClosuresHandler706=== RUN TestService_createPendingClosureHandler707=== PAUSE TestService_createPendingClosureHandler708=== RUN TestService_verifyS3Integrity709=== PAUSE TestService_verifyS3Integrity710=== RUN TestCompleteMultipartUnregistered711=== PAUSE TestCompleteMultipartUnregistered712=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT713=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT714=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle715=== CONT TestPush_CompleteCommitsEveryRoot716=== CONT TestService_cleanupPendingClosuresHandler717=== CONT TestSkippedUploadsHandler718=== CONT TestParseSize719--- PASS: TestParseSize (0.00s)720=== CONT TestPush_OverlappingRootsStoreOneRowPerKey721=== CONT TestService_Rustfstest722=== CONT TestPresignedUploadRegisteredBeforeCommit7232026/10/08 12:57:21 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000724=== CONT TestCompletedNarNotReofferedAcrossClosures725=== CONT TestCompleteMultipartUpload_ErrorButObjectExists726=== CONT TestRedundantMultipartUpload727=== CONT TestPush_SignsNarinfosOfItsPendingObjects728=== CONT TestPush_RejectsBadRequests729=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit730=== CONT TestPush_RootsAreLockedInByteOrder731=== CONT TestPush_CompleteWaitsForCleanupOfThePush732=== CONT TestPush_RepeatedRootCommitsOnce733=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT734=== CONT TestCompleteMultipartUnregistered735=== CONT TestService_verifyS3Integrity736--- PASS: TestSkippedUploadsHandler (0.01s)737=== CONT TestService_createPendingClosureHandler738=== CONT TestIsValidUploadKey739=== CONT TestUploadHandlersRejectInvalidKeys740=== CONT TestGCTaskStore_GetEmpty741=== CONT TestService_AuthMiddleware742=== CONT TestReadRedirectUsesPublicS3URL743=== RUN TestIsValidUploadKey/narinfo744=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info745=== PAUSE TestIsValidUploadKey/narinfo746=== RUN TestIsValidUploadKey/nar_zst747=== PAUSE TestIsValidUploadKey/nar_zst748=== RUN TestIsValidUploadKey/nar_xz749=== PAUSE TestIsValidUploadKey/nar_xz750=== RUN TestIsValidUploadKey/nar_plain751=== PAUSE TestIsValidUploadKey/nar_plain752=== RUN TestIsValidUploadKey/listing753=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info754=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal755=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal756=== CONT TestReadProxyRangeRequest757--- PASS: TestGCTaskStore_GetEmpty (0.00s)758=== PAUSE TestIsValidUploadKey/listing759=== RUN TestIsValidUploadKey/build_log760=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key761=== PAUSE TestIsValidUploadKey/build_log762=== RUN TestIsValidUploadKey/build_log_home-manager_file763=== PAUSE TestIsValidUploadKey/build_log_home-manager_file764=== RUN TestIsValidUploadKey/build_log_plus_in_name765=== PAUSE TestIsValidUploadKey/build_log_plus_in_name766=== RUN TestIsValidUploadKey/build_log_question_mark767=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key768=== PAUSE TestIsValidUploadKey/build_log_question_mark769=== RUN TestIsValidUploadKey/build_log_equals770=== PAUSE TestIsValidUploadKey/build_log_equals771=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key772=== RUN TestIsValidUploadKey/realisation773=== PAUSE TestIsValidUploadKey/realisation774=== RUN TestIsValidUploadKey/realisation_plus_in_output775=== PAUSE TestIsValidUploadKey/realisation_plus_in_output776=== RUN TestIsValidUploadKey/nix-cache-info777=== PAUSE TestIsValidUploadKey/nix-cache-info778=== RUN TestIsValidUploadKey/index.html779=== PAUSE TestIsValidUploadKey/index.html780=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key781=== RUN TestIsValidUploadKey/narinfo_key,_nar_type782=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type783=== RUN TestIsValidUploadKey/nar_key,_narinfo_type784=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type785=== RUN TestIsValidUploadKey/listing_key,_narinfo_type786=== CONT TestReadRedirectKeepsNarinfoProxied787=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type788=== RUN TestIsValidUploadKey/traversal789=== PAUSE TestIsValidUploadKey/traversal790=== RUN TestIsValidUploadKey/traversal_nar791=== PAUSE TestIsValidUploadKey/traversal_nar792=== RUN TestIsValidUploadKey/absolute793=== PAUSE TestIsValidUploadKey/absolute794=== RUN TestIsValidUploadKey/empty_key795=== PAUSE TestIsValidUploadKey/empty_key796=== RUN TestIsValidUploadKey/unknown_type797=== PAUSE TestIsValidUploadKey/unknown_type798=== CONT TestReadRedirectNar7992026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures8002026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures801--- PASS: TestService_Rustfstest (0.34s)802=== CONT TestReadProxyDisabled8032026/10/08 12:57:22 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8042026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures805--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.34s)806=== CONT TestReadProxyRootRedirectsToIndexHTML8072026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures8092026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures8102026/10/08 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete811=== RUN TestPush_RejectsBadRequests/no_objects812=== PAUSE TestPush_RejectsBadRequests/no_objects813=== RUN TestPush_RejectsBadRequests/bad_root814=== PAUSE TestPush_RejectsBadRequests/bad_root815=== RUN TestPush_RejectsBadRequests/root_not_in_objects816=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects817=== RUN TestPush_RejectsBadRequests/no_roots818=== PAUSE TestPush_RejectsBadRequests/no_roots819=== CONT TestUploadHandlersRejectOversizedBody8202026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes8212026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8222026/10/08 12:57:22 INFO Signed narinfos id=1 count=18232026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8242026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8252026/10/08 12:57:22 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8262026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8272026/10/08 12:57:22 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8282026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8292026/10/08 12:57:22 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18302026/10/08 12:57:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8312026/10/08 12:57:22 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo832--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.50s)833=== CONT TestReadProxyConditionalGet8342026/10/08 12:57:22 INFO Received cleanup request method=DELETE path=/api/pending_closures8352026/10/08 12:57:22 INFO Aborted multipart uploads count=0 kept=08362026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures8372026/10/08 12:57:22 INFO Received cleanup request method=DELETE path=/api/pending_closures8382026/10/08 12:57:22 INFO Aborted multipart uploads count=1 kept=08392026/10/08 12:57:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8402026-10-08 12:57:22.354 UTC [460] ERROR: Closure does not exist: id=18412026-10-08 12:57:22.354 UTC [460] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8422026-10-08 12:57:22.354 UTC [460] STATEMENT: -- name: CommitPendingClosure :one843 SELECT commit_pending_closure($1::bigint)::bigint844 845--- PASS: TestService_cleanupPendingClosuresHandler (0.54s)846=== CONT TestReadProxyOutlastsServerWriteTimeout8472026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes8482026/10/08 12:57:22 INFO Received complete push request method=POST path=/api/pushes/1/complete8492026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes8502026/10/08 12:57:22 INFO Completed push id=1 objects=6 duration=10.601194ms851--- PASS: TestPush_CompleteCommitsEveryRoot (0.58s)852=== CONT TestPendingClosureWriteTimeout853=== RUN TestPendingClosureWriteTimeout/empty854=== PAUSE TestPendingClosureWriteTimeout/empty855=== RUN TestPendingClosureWriteTimeout/400_objects856=== PAUSE TestPendingClosureWriteTimeout/400_objects857=== RUN TestPendingClosureWriteTimeout/670k_objects858=== PAUSE TestPendingClosureWriteTimeout/670k_objects859=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline860=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline861=== CONT TestReadProxyHead862=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure863=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure864=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart865=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart866=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts867=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts868=== CONT TestProxyWriteTimeout869=== RUN TestProxyWriteTimeout/narinfo870=== PAUSE TestProxyWriteTimeout/narinfo871=== RUN TestProxyWriteTimeout/1_GiB_nar872=== PAUSE TestProxyWriteTimeout/1_GiB_nar873=== RUN TestProxyWriteTimeout/10_GiB_nar874=== PAUSE TestProxyWriteTimeout/10_GiB_nar875=== RUN TestProxyWriteTimeout/unknown_size876=== PAUSE TestProxyWriteTimeout/unknown_size877=== CONT TestReadProxyInvalidPath8782026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes8792026-10-08 12:57:22.443 UTC [509] ERROR: could not obtain lock on row in relation "closures"8802026-10-08 12:57:22.443 UTC [509] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8812026-10-08 12:57:22.443 UTC [509] ERROR: could not obtain lock on row in relation "closures"8822026-10-08 12:57:22.443 UTC [509] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8832026-10-08 12:57:22.445 UTC [509] ERROR: could not obtain lock on row in relation "closures"8842026-10-08 12:57:22.445 UTC [509] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8852026-10-08 12:57:22.445 UTC [509] ERROR: could not obtain lock on row in relation "closures"8862026-10-08 12:57:22.445 UTC [509] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8872026-10-08 12:57:22.445 UTC [509] ERROR: could not obtain lock on row in relation "closures"8882026-10-08 12:57:22.445 UTC [509] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT889--- PASS: TestPush_RootsAreLockedInByteOrder (0.63s)890=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8912026/10/08 12:57:22 INFO Received complete push request method=POST path=/api/pushes/1/complete8922026/10/08 12:57:22 INFO Completed push id=1 objects=4 duration=9.691886ms8932026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes8942026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes895--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.68s)896=== CONT TestMultipartCleanup8972026/10/08 12:57:22 INFO Aborted multipart uploads count=0 kept=08982026/10/08 12:57:22 WARN Force mode enabled - objects will be deleted immediately without grace period899--- PASS: TestReadRedirectNar (0.74s)900=== CONT TestServerTLSConfig901=== RUN TestServerTLSConfig/no_client_CA902=== PAUSE TestServerTLSConfig/no_client_CA903=== RUN TestServerTLSConfig/missing_CA_file904=== PAUSE TestServerTLSConfig/missing_CA_file905=== RUN TestServerTLSConfig/not_a_PEM_file906=== PAUSE TestServerTLSConfig/not_a_PEM_file907=== CONT TestReadProxy4049082026/10/08 12:57:22 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=09092026/10/08 12:57:22 INFO Vacuumed table table=pending_closures9102026/10/08 12:57:22 INFO Vacuumed table table=pending_objects9112026/10/08 12:57:22 INFO Vacuumed table table=multipart_uploads9122026/10/08 12:57:22 INFO Vacuumed table table=closures9132026/10/08 12:57:22 INFO Vacuumed table table=objects9142026/10/08 12:57:22 INFO Received complete push request method=POST path=/api/pushes/2/complete9152026/10/08 12:57:22 INFO Completed push id=2 objects=4 duration=3.756433ms916--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.78s)917=== CONT TestService_NativeMTLS9182026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes9192026/10/08 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/10/08 12:57:22 INFO Received complete push request method=POST path=/api/pushes/1/complete9212026/10/08 12:57:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLmZhNDAwZWM0LWNiYzItNGM1NS05YzMxLTYwYjA2MGM4YzAzZngxNzkxNDY0MjQyMTc5MDAxMTUz parts=129222026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9232026/10/08 12:57:22 INFO Completed push id=1 objects=4 duration=11.643742ms924--- PASS: TestPush_RepeatedRootCommitsOnce (0.83s)925=== CONT TestReadProxyNarStreaming926--- PASS: TestReadRedirectKeepsNarinfoProxied (0.83s)927=== CONT TestMetricsCommit9282026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/08 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9302026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9312026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9322026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/08 12:57:22 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLmM3ZmJjMTRlLWE5MmUtNDFjYy05YmVlLWNiMzE5ZWVhYmNjZHgxNzkxNDY0MjQyMjE0MDczODAy parts=129342026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures935--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.88s)936=== CONT TestReadProxyContentNegotiation9372026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/08 12:57:22 INFO Received push request method=POST path=/api/pushes940--- PASS: TestReadRedirectUsesPublicS3URL (1.00s)941=== CONT TestService_healthCheckHandler9422026/10/08 12:57:22 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"943--- PASS: TestService_AuthMiddleware (1.02s)944=== CONT TestReadProxyNarinfoAlreadyDecompressed9452026/10/08 12:57:22 INFO Received uploads request method=POST path=/api/pending_closures946--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.07s)947=== CONT TestGracefulShutdownDrainsInflight9482026/10/08 12:57:22 INFO Starting HTTP server address=127.0.0.1:434419492026/10/08 12:57:22 INFO Shutdown signal received, draining in-flight requests timeout=10s950--- PASS: TestReadProxyRangeRequest (1.09s)951=== CONT TestReadProxyNarinfo9522026/10/08 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9532026/10/08 12:57:22 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst954--- PASS: TestCompleteMultipartUnregistered (1.11s)955=== CONT TestGCTaskStore_Fail956--- PASS: TestGCTaskStore_Fail (0.00s)957=== CONT TestIsValidCachePath958=== RUN TestIsValidCachePath/narinfo959=== PAUSE TestIsValidCachePath/narinfo960=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars961=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars962=== RUN TestIsValidCachePath/nar_zst963=== PAUSE TestIsValidCachePath/nar_zst964=== RUN TestIsValidCachePath/nar_xz965=== PAUSE TestIsValidCachePath/nar_xz966=== RUN TestIsValidCachePath/nar_bz2967=== PAUSE TestIsValidCachePath/nar_bz2968=== RUN TestIsValidCachePath/nar_uncompressed969=== PAUSE TestIsValidCachePath/nar_uncompressed970=== RUN TestIsValidCachePath/ls971=== PAUSE TestIsValidCachePath/ls972=== RUN TestIsValidCachePath/log973=== PAUSE TestIsValidCachePath/log974=== RUN TestIsValidCachePath/realisation975=== PAUSE TestIsValidCachePath/realisation976=== RUN TestIsValidCachePath/nix-cache-info977=== PAUSE TestIsValidCachePath/nix-cache-info978=== RUN TestIsValidCachePath/index.html979=== PAUSE TestIsValidCachePath/index.html980=== RUN TestIsValidCachePath/traversal_parent981=== PAUSE TestIsValidCachePath/traversal_parent982=== RUN TestIsValidCachePath/traversal_in_middle983=== PAUSE TestIsValidCachePath/traversal_in_middle984=== RUN TestIsValidCachePath/invalid_char_e985=== PAUSE TestIsValidCachePath/invalid_char_e986=== RUN TestIsValidCachePath/invalid_char_u987=== PAUSE TestIsValidCachePath/invalid_char_u988=== RUN TestIsValidCachePath/random_path989=== PAUSE TestIsValidCachePath/random_path990=== RUN TestIsValidCachePath/empty991=== PAUSE TestIsValidCachePath/empty992=== RUN TestIsValidCachePath/leading_slash993=== PAUSE TestIsValidCachePath/leading_slash994=== RUN TestIsValidCachePath/wrong_extension995=== PAUSE TestIsValidCachePath/wrong_extension996=== RUN TestIsValidCachePath/short_hash997=== PAUSE TestIsValidCachePath/short_hash998=== CONT TestGCTaskStore_PhaseUpdates999--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1000=== CONT TestParseSingleRange1001=== RUN TestParseSingleRange/none1002=== PAUSE TestParseSingleRange/none1003=== RUN TestParseSingleRange/unknown_unit1004=== PAUSE TestParseSingleRange/unknown_unit1005=== RUN TestParseSingleRange/multi-range_ignored1006=== PAUSE TestParseSingleRange/multi-range_ignored1007=== RUN TestParseSingleRange/malformed_no_dash1008=== PAUSE TestParseSingleRange/malformed_no_dash1009=== RUN TestParseSingleRange/malformed_both_empty1010=== PAUSE TestParseSingleRange/malformed_both_empty1011=== RUN TestParseSingleRange/malformed_end_before_start1012=== PAUSE TestParseSingleRange/malformed_end_before_start1013=== RUN TestParseSingleRange/closed1014=== PAUSE TestParseSingleRange/closed1015=== RUN TestParseSingleRange/open-ended1016=== PAUSE TestParseSingleRange/open-ended1017=== RUN TestParseSingleRange/end_clamped_to_size1018=== PAUSE TestParseSingleRange/end_clamped_to_size1019=== RUN TestParseSingleRange/suffix1020=== PAUSE TestParseSingleRange/suffix1021=== RUN TestParseSingleRange/suffix_exceeds_size1022=== PAUSE TestParseSingleRange/suffix_exceeds_size1023=== RUN TestParseSingleRange/single_byte1024=== PAUSE TestParseSingleRange/single_byte1025=== RUN TestParseSingleRange/start_past_EOF1026=== PAUSE TestParseSingleRange/start_past_EOF1027=== RUN TestParseSingleRange/start_far_past_EOF1028=== PAUSE TestParseSingleRange/start_far_past_EOF1029=== CONT TestGCTaskStore_CompletedAllowsNewTask1030--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1031=== CONT TestPresentNotReportedWhileGCDeletesClosure1032=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1033=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1034=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1035=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1036=== CONT TestGCTaskStore_GetReturnsLatest1037--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1038=== CONT TestPresentRefreshesOnlyStaleClosures1039--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1040=== CONT TestOrphanedObjectsGC1041--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.80s)1042=== CONT TestObjectStatsLargeCommit10432026/10/08 12:57:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10442026/10/08 12:57:22 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLjUxZjNmZjViLWU3Y2EtNGIxYi05YzYxLTYyN2Y0ZGIzMjkzMngxNzkxNDY0MjQyNzA5NDk3ODc210452026/10/08 12:57:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLjUxZjNmZjViLWU3Y2EtNGIxYi05YzYxLTYyN2Y0ZGIzMjkzMngxNzkxNDY0MjQyNzA5NDk3ODc2 parts=11046--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.17s)1047=== CONT TestPresentReportsOnlyClosureRoots1048--- PASS: TestReadProxyDisabled (0.84s)1049=== CONT TestObjectStatsTrigger10502026/10/08 12:57:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1051--- PASS: TestReadProxyConditionalGet (0.73s)1052=== CONT TestCreatePin_ReservedPins10532026/10/08 12:57:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLjQ5NTY2YjJmLTA0MDktNDQwOS1hMmM0LWU5ZTY4NDFkOTJkZngxNzkxNDY0MjQyNjc5NDE0ODkw parts=1010542026/10/08 12:57:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10552026/10/08 12:57:23 INFO Completed upload id=1 objects=2 duration=6.409837ms10562026/10/08 12:57:23 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010572026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures10582026/10/08 12:57:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures10592026-10-08 12:57:23.088 UTC [559] ERROR: Push does not exist: id=110602026-10-08 12:57:23.088 UTC [559] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10612026-10-08 12:57:23.088 UTC [559] STATEMENT: SELECT commit_push($1)1062--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.27s)1063=== CONT TestService_readinessHandler10642026/10/08 12:57:23 INFO Aborted multipart uploads count=0 kept=010652026/10/08 12:57:23 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=010662026/10/08 12:57:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10672026/10/08 12:57:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10682026/10/08 12:57:23 INFO Vacuumed table table=pending_closures10692026/10/08 12:57:23 INFO Vacuumed table table=pending_objects10702026/10/08 12:57:23 INFO Vacuumed table table=multipart_uploads10712026/10/08 12:57:23 INFO Vacuumed table table=closures10722026/10/08 12:57:23 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLmRiYzBiNGY2LTVhZGItNDRhYy05Mzg2LTQ2NzgzMzRlMWRlOXgxNzkxNDY0MjQyNjU2NTIxNzQ4 error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10732026/10/08 12:57:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLjU2ZWZiMjk1LWQ5NDktNDVlMS04ZWVjLWViYmViOTdmNjExN3gxNzkxNDY0MjQyNjQ3NDg1MzQ4 parts=1210742026/10/08 12:57:23 INFO Vacuumed table table=objects10752026/10/08 12:57:23 INFO Received cleanup request method=DELETE path=/api/pending_closures10762026/10/08 12:57:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001077--- PASS: TestService_createPendingClosureHandler (1.32s)1078=== CONT TestOrphanedObjectsGCStressTest10792026/10/08 12:57:23 INFO Aborted multipart uploads count=1 kept=01080--- PASS: TestReadProxyHead (0.74s)1081=== CONT TestLeadIncumbentAnnouncesAtOnce10822026/10/08 12:57:23 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGU2OWEyNGEtMzZlMy00MzI5LWI5MGQtNmM5MmRkZWVlYWEwLjQ4OTRhNjgwLTY5MDUtNGNiNS1iMDBiLTdhMWEzMmE1NmVlOXgxNzkxNDY0MjQyNzQ0MTIyNjAy parts=1010832026/10/08 12:57:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1084--- PASS: TestRedundantMultipartUpload (1.33s)1085=== CONT TestCreatePendingClosureRejectsOversizedNAR10862026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures1087--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1088=== CONT TestGCTaskStore_ConflictDifferentParams1089--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1090=== CONT TestMetricsInventory10912026/10/08 12:57:23 INFO Completed upload id=1 objects=2 duration=2.895426ms10922026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures10932026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures10942026/10/08 12:57:23 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10952026/10/08 12:57:23 WARN Found objects in DB but missing from S3, will re-upload count=11096--- PASS: TestService_verifyS3Integrity (1.34s)1097=== CONT TestGCTaskStore_DeduplicateSameParams1098--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1099=== CONT TestNARDeduplicationMetadataUploadBug1100--- PASS: TestReadProxyInvalidPath (0.76s)1101=== CONT TestGCTaskStore_StartNew1102--- PASS: TestGCTaskStore_StartNew (0.00s)1103=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1104--- PASS: TestPresentReportsOnlyClosureRoots (0.21s)1105=== CONT TestGCSweepDeliversEachKeyOnce11062026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures1107--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.80s)1108=== CONT TestGCEndsOnShutdown1109=== RUN TestGCEndsOnShutdown/before_the_run1110=== PAUSE TestGCEndsOnShutdown/before_the_run1111=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1112=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1113=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1114=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1115=== CONT TestTombstonedObjectOfferedWithoutWaiting11162026/10/08 12:57:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45753/oidc11172026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures1118--- PASS: TestReadProxy404 (0.77s)1119=== CONT TestCommitRacingPendingCleanupKeepsObjects11202026/10/08 12:57:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11212026/10/08 12:57:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1122--- PASS: TestService_NativeMTLS (0.74s)1123=== CONT TestCacheConfigHandlerMaxNarSize1124--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1125=== CONT TestGCSweepSkipsPendingObjects1126--- PASS: TestReadProxyNarStreaming (0.73s)1127=== CONT TestGenerateLandingPage1128--- PASS: TestGenerateLandingPage (0.00s)1129=== CONT TestDeduplicatedObjectsRecordedAsPending11302026/10/08 12:57:23 INFO Received cleanup request method=DELETE path=/api/pending_closures11312026/10/08 12:57:23 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket35/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11322026/10/08 12:57:23 INFO Aborted multipart uploads count=0 kept=111332026/10/08 12:57:23 INFO Received push request method=POST path=/api/pushes11342026/10/08 12:57:23 INFO Received cleanup request method=DELETE path=/api/pending_closures11352026/10/08 12:57:23 INFO Aborted multipart uploads count=1 kept=01136--- PASS: TestMultipartCleanup (0.91s)1137=== CONT TestPushWaitsForSweepHoldingRow11382026/10/08 12:57:23 INFO Received complete push request method=POST path=/api/pushes/1/complete11392026/10/08 12:57:23 INFO Completed push id=1 objects=4 duration=11.904885ms11402026/10/08 12:57:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11412026/10/08 12:57:23 INFO Completed upload id=2 objects=2 duration=1.674855ms1142--- PASS: TestMetricsCommit (0.80s)1143=== CONT TestPushDedupSurvivesConcurrentGC1144--- PASS: TestService_healthCheckHandler (0.62s)1145=== CONT TestRegisterCompletedObjectNeedsPendingRow1146--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.65s)1147=== CONT TestGCMetrics1148--- PASS: TestReadProxyContentNegotiation (0.80s)1149=== CONT TestSweepSkipsRowsLockedByPush1150--- PASS: TestPresentRefreshesOnlyStaleClosures (0.62s)1151=== CONT TestSweepRechecksPendingAfterLocking11522026/10/08 12:57:23 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1153--- PASS: TestReadProxyNarinfo (0.69s)1154=== CONT TestGCBugBareHashReferences1155--- PASS: TestObjectStatsTrigger (0.67s)1156=== CONT TestFailedS3DeleteKeepsTombstone11572026/10/08 12:57:23 WARN readiness check failed error="closed pool"1158--- PASS: TestService_readinessHandler (0.56s)1159=== CONT TestGetExistingObjectsLocksRows11602026/10/08 12:57:23 INFO lead: acquired remote=192.0.2.1:123411612026/10/08 12:57:23 INFO lead: released remote=192.0.2.1:12341162--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.61s)1163=== CONT TestGCAdvisoryLockBlocksConcurrentRun1164--- PASS: TestMetricsInventory (0.64s)1165=== CONT TestForceGCDuringPushOffersSweptObject1166=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1167=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1168=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1169=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1170=== CONT TestService_ReadScope_PublicByDefault11712026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures1172=== NAME TestNARDeduplicationMetadataUploadBug1173 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1617118487/001/store/k3b2dngjdlgyiv3340hl9xrdfx52if1f-file1.txt11742026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/08 12:57:23 INFO Aborted multipart uploads count=0 kept=01176--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.62s)1177=== CONT TestLeadEndsOnShutdown11782026/10/08 12:57:23 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/08 12:57:23 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=011802026/10/08 12:57:23 INFO Vacuumed table table=pending_closures11812026/10/08 12:57:23 INFO Vacuumed table table=pending_objects11822026/10/08 12:57:23 INFO Vacuumed table table=multipart_uploads11832026/10/08 12:57:23 INFO Vacuumed table table=closures11842026/10/08 12:57:23 INFO Vacuumed table table=objects1185--- PASS: TestGCSweepDeliversEachKeyOnce (0.70s)1186=== CONT TestClientIntegration1187=== NAME TestOrphanedObjectsGC1188 orphaned_objects_gc_test.go:287: GC Test Summary:1189 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1190 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1191 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1192 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1193 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1194--- PASS: TestOrphanedObjectsGC (0.95s)1195=== CONT TestClientMultipleUploads11962026/10/08 12:57:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11972026/10/08 12:57:23 WARN Refused reserved pin name=worker-x86_64-linux11982026/10/08 12:57:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11992026/10/08 12:57:23 INFO Received create pin request method=POST path=/api/pins/my-app12002026/10/08 12:57:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1201--- PASS: TestCreatePin_ReservedPins (0.85s)1202=== CONT TestCacheStatsHandler12032026/10/08 12:57:23 INFO Received push request method=POST path=/api/pushes12042026/10/08 12:57:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12052026/10/08 12:57:23 INFO Uploading k3b2dngjdlgyiv3340hl9xrdfx52if1f-file1.txt (160B)12062026/10/08 12:57:23 WARN Failed to register uploaded object key=k3b2dngjdlgyiv3340hl9xrdfx52if1f.ls error="server returned 404: 404 page not found\n"12072026/10/08 12:57:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12082026/10/08 12:57:23 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12092026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures12102026/10/08 12:57:23 INFO Signed narinfos id=1 count=112112026/10/08 12:57:23 INFO Uploading 1 narinfos12122026/10/08 12:57:23 INFO Received complete push request method=POST path=/api/pushes/1/complete12132026/10/08 12:57:23 WARN Failed to register uploaded object key=k3b2dngjdlgyiv3340hl9xrdfx52if1f.narinfo error="server returned 404: 404 page not found\n"12142026/10/08 12:57:23 INFO Aborted multipart uploads count=0 kept=012152026/10/08 12:57:23 INFO Completed push id=1 objects=3 duration=8.576295ms12162026/10/08 12:57:23 INFO Upload complete. (70ms)1217=== NAME TestNARDeduplicationMetadataUploadBug1218 metadata_upload_test.go:54: Retrieved narinfo from S3:1219 StorePath: /build/TestNARDeduplicationMetadataUploadBug1617118487/001/store/k3b2dngjdlgyiv3340hl9xrdfx52if1f-file1.txt1220 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1221 Compression: zstd1222 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1223 NarSize: 1601224 References: 1225 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12262026/10/08 12:57:23 WARN Force mode enabled - objects will be deleted immediately without grace period1227 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1228 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1229 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12302026/10/08 12:57:23 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=012312026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures12322026/10/08 12:57:23 INFO Aborted multipart uploads count=0 kept=012332026/10/08 12:57:23 INFO Vacuumed table table=pending_closures12342026/10/08 12:57:23 INFO Vacuumed table table=pending_objects12352026/10/08 12:57:23 INFO Vacuumed table table=multipart_uploads1236--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.59s)1237=== CONT TestClientCADerivations12382026/10/08 12:57:23 INFO Vacuumed table table=closures12392026/10/08 12:57:23 INFO Vacuumed table table=objects12402026/10/08 12:57:23 WARN Force mode enabled - objects will be deleted immediately without grace period12412026/10/08 12:57:23 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=012422026/10/08 12:57:23 INFO Vacuumed table table=pending_closures12432026/10/08 12:57:23 INFO Vacuumed table table=pending_objects12442026/10/08 12:57:23 INFO Vacuumed table table=multipart_uploads12452026/10/08 12:57:23 INFO Vacuumed table table=closures1246--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.65s)1247=== CONT TestCacheConfigHandler1248=== RUN TestCacheConfigHandler/full_config,_no_issuer1249=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1250=== RUN TestCacheConfigHandler/no_cache_url_configured1251=== PAUSE TestCacheConfigHandler/no_cache_url_configured1252=== RUN TestCacheConfigHandler/no_signing_keys1253=== PAUSE TestCacheConfigHandler/no_signing_keys1254=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1255=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1256=== CONT TestClientErrorHandling1257=== RUN TestClientErrorHandling/InvalidStorePath1258=== PAUSE TestClientErrorHandling/InvalidStorePath1259=== RUN TestClientErrorHandling/InvalidAuthToken1260=== PAUSE TestClientErrorHandling/InvalidAuthToken1261=== RUN TestClientErrorHandling/ServerNotAvailable1262=== PAUSE TestClientErrorHandling/ServerNotAvailable1263=== CONT TestPinProtectsFromGC12642026/10/08 12:57:23 INFO Vacuumed table table=objects12652026/10/08 12:57:23 INFO Received uploads request method=POST path=/api/pending_closures1266=== NAME TestNARDeduplicationMetadataUploadBug1267 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1617118487/001/store/6403s2y0iqr206wyyfbcar2zawbrca1y-file2.txt1268--- PASS: TestGCSweepSkipsPendingObjects (0.66s)1269=== CONT TestService_ReadAuthMiddleware12702026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures1271--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.59s)1272=== CONT TestPendingCleanupUsesOneCutoff1273--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.88s)1274=== CONT TestClientPushesUseOnePush12752026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes12762026/10/08 12:57:24 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12772026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=012782026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12792026/10/08 12:57:24 INFO Signed narinfos id=2 count=112802026/10/08 12:57:24 WARN Failed to register uploaded object key=6403s2y0iqr206wyyfbcar2zawbrca1y.ls error="server returned 404: 404 page not found\n"12812026/10/08 12:57:24 INFO Uploading 1 narinfos12822026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/2/complete12832026/10/08 12:57:24 WARN Failed to register uploaded object key=6403s2y0iqr206wyyfbcar2zawbrca1y.narinfo error="server returned 404: 404 page not found\n"12842026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period12852026/10/08 12:57:24 INFO Completed push id=2 objects=3 duration=2.201ms12862026/10/08 12:57:24 INFO Upload complete. (53ms)1287=== NAME TestNARDeduplicationMetadataUploadBug1288 metadata_upload_test.go:76: Retrieved narinfo from S3:1289 StorePath: /build/TestNARDeduplicationMetadataUploadBug1617118487/001/store/6403s2y0iqr206wyyfbcar2zawbrca1y-file2.txt1290 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1291 Compression: zstd1292 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1293 NarSize: 1601294 References: 1295 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12962026/10/08 12:57:24 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=012972026/10/08 12:57:24 INFO Vacuumed table table=pending_closures12982026/10/08 12:57:24 INFO Vacuumed table table=pending_objects1299 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1300 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1301 {"version":1,"root":{"type":"regular","size":44}}13022026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13032026/10/08 12:57:24 INFO Vacuumed table table=closures13042026/10/08 12:57:24 INFO Vacuumed table table=objects1305--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)1306=== CONT TestService_RequireScope_OIDC1307--- PASS: TestGCMetrics (0.60s)1308=== CONT TestService_AuthMiddleware_OIDC13092026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013102026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013112026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period13122026/10/08 12:57:24 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=013132026/10/08 12:57:24 INFO Vacuumed table table=pending_closures13142026/10/08 12:57:24 INFO Vacuumed table table=pending_objects13152026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13162026/10/08 12:57:24 INFO Vacuumed table table=closures13172026/10/08 12:57:24 INFO Vacuumed table table=objects13182026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013192026/10/08 12:57:24 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=013202026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013212026/10/08 12:57:24 INFO Vacuumed table table=pending_closures13222026/10/08 12:57:24 INFO Vacuumed table table=pending_objects13232026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13242026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period13252026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/08 12:57:24 INFO Vacuumed table table=closures13272026/10/08 12:57:24 INFO Vacuumed table table=objects13282026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013292026/10/08 12:57:24 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=013302026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period13312026/10/08 12:57:24 INFO Vacuumed table table=pending_closures13322026/10/08 12:57:24 INFO Vacuumed table table=pending_objects13332026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13342026/10/08 12:57:24 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=013352026/10/08 12:57:24 INFO Vacuumed table table=closures13362026/10/08 12:57:24 INFO Vacuumed table table=pending_closures13372026/10/08 12:57:24 INFO Vacuumed table table=objects13382026/10/08 12:57:24 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=01339--- PASS: TestSweepSkipsRowsLockedByPush (0.64s)13402026/10/08 12:57:24 INFO Vacuumed table table=pending_objects1341=== CONT TestConnectWaitsForAPeerMigration13422026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13432026/10/08 12:57:24 INFO Vacuumed table table=closures13442026/10/08 12:57:24 INFO Vacuumed table table=objects13452026/10/08 12:57:24 INFO Vacuumed table table=pending_closures13462026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures1347--- PASS: TestPushDedupSurvivesConcurrentGC (0.70s)1348=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13492026/10/08 12:57:24 INFO Vacuumed table table=pending_objects13502026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads13512026/10/08 12:57:24 INFO Vacuumed table table=closures13522026/10/08 12:57:24 INFO Vacuumed table table=objects1353--- PASS: TestSweepRechecksPendingAfterLocking (0.60s)1354=== CONT TestResolveDBConnectionString1355=== RUN TestResolveDBConnectionString/flag_wins1356=== PAUSE TestResolveDBConnectionString/flag_wins1357=== RUN TestResolveDBConnectionString/file_when_flag_empty1358=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1359=== RUN TestResolveDBConnectionString/missing_file_is_an_error1360=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1361=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1362=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1363=== RUN TestResolveDBConnectionString/nothing_configured1364=== PAUSE TestResolveDBConnectionString/nothing_configured1365=== CONT TestService_AuthMiddleware_MTLSProxyHeader13662026/10/08 12:57:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46403/oidc1367--- PASS: TestGetExistingObjectsLocksRows (0.53s)1368=== CONT TestClientSharedPathCommittedMidPush13692026/10/08 12:57:24 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"1370--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.44s)1371=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1372--- PASS: TestService_ReadScope_PublicByDefault (0.41s)1373=== CONT TestClientFallsBackToClosures13742026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=013752026/10/08 12:57:24 INFO lead: acquired remote=192.0.2.1:123413762026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period13772026/10/08 12:57:24 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13782026/10/08 12:57:24 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13792026/10/08 12:57:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46137/oidc1380--- PASS: TestFailedS3DeleteKeepsTombstone (0.61s)1381=== CONT TestClientWithDependencies1382--- PASS: TestCacheStatsHandler (0.39s)1383=== CONT TestLeadElectsOneAndHandsOver1384--- PASS: TestGCBugBareHashReferences (0.75s)1385=== CONT TestDeleteClosuresRacingPins1386=== NAME TestClientMultipleUploads1387 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads3239548767/001/store/4fxn4w5ggn1sch9lnxbfl9pgcmg6g496-test-file-0.txt1388=== NAME TestClientIntegration1389 client_integration_test.go:286: Created store path: /build/TestClientIntegration2617214118/002/store/px04fm7kgwcgg1qhq4217v1n0cxp6whf-test-file.txt1390=== NAME TestClientMultipleUploads1391 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads3239548767/001/store/ya27hsdr4cmr9vm9nj5gz034xi45hrhp-test-file-1.txt1392--- PASS: TestService_ReadAuthMiddleware (0.41s)1393=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13942026/10/08 12:57:24 INFO Received uploads request method=POST path=/1395=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13962026/10/08 12:57:24 INFO Received request for more parts method=POST path=/1397=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13982026/10/08 12:57:24 INFO Received complete multipart upload request method=POST path=/1399=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14002026/10/08 12:57:24 INFO Received uploads request method=POST path=/1401--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1402 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1403 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1404 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1405 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1406=== CONT TestIsValidUploadKey/narinfo1407=== CONT TestIsValidUploadKey/realisation_plus_in_output1408=== CONT TestIsValidUploadKey/unknown_type1409=== CONT TestIsValidUploadKey/empty_key1410=== CONT TestIsValidUploadKey/absolute1411=== CONT TestIsValidUploadKey/traversal_nar1412=== CONT TestIsValidUploadKey/traversal1413=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1414=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1415=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1416=== CONT TestIsValidUploadKey/index.html1417=== CONT TestIsValidUploadKey/nix-cache-info1418=== CONT TestIsValidUploadKey/nar_plain1419=== CONT TestIsValidUploadKey/build_log1420=== CONT TestIsValidUploadKey/listing1421=== CONT TestIsValidUploadKey/build_log_equals1422=== CONT TestIsValidUploadKey/realisation1423=== CONT TestIsValidUploadKey/build_log_question_mark1424=== CONT TestIsValidUploadKey/nar_xz1425=== CONT TestIsValidUploadKey/nar_zst1426=== CONT TestIsValidUploadKey/build_log_plus_in_name1427=== CONT TestIsValidUploadKey/build_log_home-manager_file1428--- PASS: TestIsValidUploadKey (0.00s)1429 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1430 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1431 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1432 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1433 --- PASS: TestIsValidUploadKey/absolute (0.00s)1434 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1435 --- PASS: TestIsValidUploadKey/traversal (0.00s)1436 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1437 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1438 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1439 --- PASS: TestIsValidUploadKey/index.html (0.00s)1440 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1441 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1442 --- PASS: TestIsValidUploadKey/build_log (0.00s)1443 --- PASS: TestIsValidUploadKey/listing (0.00s)1444 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1445 --- PASS: TestIsValidUploadKey/realisation (0.00s)1446 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1447 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1448 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1449 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1450 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1451=== CONT TestPush_RejectsBadRequests/no_objects14522026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes1453=== CONT TestPush_RejectsBadRequests/root_not_in_objects14542026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes1455=== CONT TestPush_RejectsBadRequests/no_roots14562026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes1457=== CONT TestPush_RejectsBadRequests/bad_root14582026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes1459=== CONT TestPendingClosureWriteTimeout/empty1460=== CONT TestPendingClosureWriteTimeout/670k_objects1461=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1462--- PASS: TestPush_RejectsBadRequests (0.42s)1463 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1464 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1465 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1466 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1467=== NAME TestClientMultipleUploads1468 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads3239548767/001/store/i7hsnmh7k8zn94fnr59bzh6s323y5ay5-test-file-2.txt14692026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes14702026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures14712026/10/08 12:57:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1472=== NAME TestPinProtectsFromGC14732026/10/08 12:57:24 INFO Uploading px04fm7kgwcgg1qhq4217v1n0cxp6whf-test-file.txt (152B)1474 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2734464361/001/store/bxnfvkgqdi2iq6qvd45ka5xw6ll15blz-pinned-file.txt1475 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2734464361/001/store/v5vxd5fyip9vsc4j5vz19igh7zd50czj-unpinned-file.txt1476=== NAME TestClientCADerivations1477 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3020461884/001/store/wwfg3by6wmg00gx887wkkw8c2wdy8hab-ca-test14782026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14792026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14802026/10/08 12:57:24 WARN Failed to register uploaded object key=px04fm7kgwcgg1qhq4217v1n0cxp6whf.ls error="server returned 404: 404 page not found\n"14812026/10/08 12:57:24 INFO Signed narinfos id=1 count=114822026/10/08 12:57:24 INFO Uploading 1 narinfos14832026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures14842026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete14852026/10/08 12:57:24 WARN Failed to register uploaded object key=px04fm7kgwcgg1qhq4217v1n0cxp6whf.narinfo error="server returned 404: 404 page not found\n"14862026/10/08 12:57:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14872026/10/08 12:57:24 WARN mTLS auth: bound subjects configured but subject DN unavailable14882026/10/08 12:57:24 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1489--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.34s)1490=== CONT TestPendingClosureWriteTimeout/400_objects1491=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14922026/10/08 12:57:24 INFO Received uploads request method=POST path=/14932026/10/08 12:57:24 INFO Completed push id=1 objects=3 duration=7.918409ms14942026/10/08 12:57:24 INFO Upload complete. (70ms)14952026/10/08 12:57:24 INFO Received cleanup request method=DELETE path=/api/pending_closures1496--- PASS: TestPushWaitsForSweepHoldingRow (1.09s)1497=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14982026/10/08 12:57:24 INFO Received request for more parts method=POST path=/1499=== NAME TestClientCADerivations1500 client_ca_test.go:139: Found 1 dependencies (including self)15012026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes15022026/10/08 12:57:24 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15032026/10/08 12:57:24 INFO Uploading 4fxn4w5ggn1sch9lnxbfl9pgcmg6g496-test-file-0.txt (160B)15042026/10/08 12:57:24 INFO Uploading i7hsnmh7k8zn94fnr59bzh6s323y5ay5-test-file-2.txt (160B)15052026/10/08 12:57:24 INFO Uploading ya27hsdr4cmr9vm9nj5gz034xi45hrhp-test-file-1.txt (160B)1506--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)1507=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15082026/10/08 12:57:24 INFO Received complete multipart upload request method=POST path=/15092026/10/08 12:57:24 WARN Failed to register uploaded object key=4fxn4w5ggn1sch9lnxbfl9pgcmg6g496.ls error="server returned 404: 404 page not found\n"15102026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15112026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15122026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15132026/10/08 12:57:24 WARN Failed to register uploaded object key=ya27hsdr4cmr9vm9nj5gz034xi45hrhp.ls error="server returned 404: 404 page not found\n"15142026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15152026/10/08 12:57:24 WARN Failed to register uploaded object key=i7hsnmh7k8zn94fnr59bzh6s323y5ay5.ls error="server returned 404: 404 page not found\n"15162026/10/08 12:57:24 INFO Signed narinfos id=1 count=315172026/10/08 12:57:24 INFO Uploading 3 narinfos15182026/10/08 12:57:24 WARN Failed to register uploaded object key=ya27hsdr4cmr9vm9nj5gz034xi45hrhp.narinfo error="server returned 404: 404 page not found\n"15192026/10/08 12:57:24 WARN Failed to register uploaded object key=i7hsnmh7k8zn94fnr59bzh6s323y5ay5.narinfo error="server returned 404: 404 page not found\n"15202026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete15212026/10/08 12:57:24 WARN Failed to register uploaded object key=4fxn4w5ggn1sch9lnxbfl9pgcmg6g496.narinfo error="server returned 404: 404 page not found\n"15222026/10/08 12:57:24 INFO All 1 paths already cached1523=== NAME TestClientIntegration1524 client_integration_test.go:312: Retrieved narinfo from S3:1525 StorePath: /build/TestClientIntegration2617214118/002/store/px04fm7kgwcgg1qhq4217v1n0cxp6whf-test-file.txt1526 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1527 Compression: zstd1528 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11529 NarSize: 1521530 References: 1531 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115322026/10/08 12:57:24 INFO Completed push id=1 objects=9 duration=5.478789ms15332026/10/08 12:57:24 INFO Upload complete. (61ms)1534=== NAME TestClientMultipleUploads1535 client_integration_test.go:369: Uploaded 3 paths in 97.592662ms1536=== NAME TestClientIntegration1537 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1538 client_integration_test.go:313: Decompressed .ls content (64 bytes):1539 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1540 client_integration_test.go:316: Testing garbage collection...15412026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes1542--- PASS: TestClientMultipleUploads (0.63s)1543=== CONT TestProxyWriteTimeout/narinfo1544=== CONT TestProxyWriteTimeout/10_GiB_nar1545=== CONT TestProxyWriteTimeout/1_GiB_nar1546=== CONT TestProxyWriteTimeout/unknown_size1547--- PASS: TestProxyWriteTimeout (0.00s)1548 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1549 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1550 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1551 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1552=== CONT TestServerTLSConfig/no_client_CA1553=== CONT TestServerTLSConfig/not_a_PEM_file1554=== CONT TestServerTLSConfig/missing_CA_file1555--- PASS: TestServerTLSConfig (0.00s)1556 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1557 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1558 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1559=== CONT TestIsValidCachePath/narinfo1560=== CONT TestIsValidCachePath/index.html1561=== CONT TestIsValidCachePath/short_hash1562=== CONT TestIsValidCachePath/wrong_extension1563=== CONT TestIsValidCachePath/leading_slash1564=== CONT TestIsValidCachePath/empty1565=== CONT TestIsValidCachePath/random_path1566=== CONT TestIsValidCachePath/invalid_char_u1567=== CONT TestIsValidCachePath/invalid_char_e1568=== CONT TestIsValidCachePath/traversal_in_middle1569=== CONT TestIsValidCachePath/traversal_parent1570=== CONT TestIsValidCachePath/nar_uncompressed1571=== CONT TestIsValidCachePath/nix-cache-info1572=== CONT TestIsValidCachePath/realisation1573=== CONT TestIsValidCachePath/log1574=== CONT TestIsValidCachePath/ls1575=== CONT TestIsValidCachePath/nar_xz1576=== CONT TestIsValidCachePath/nar_bz21577=== CONT TestIsValidCachePath/nar_zst1578=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1579--- PASS: TestIsValidCachePath (0.00s)1580 --- PASS: TestIsValidCachePath/narinfo (0.00s)1581 --- PASS: TestIsValidCachePath/index.html (0.00s)1582 --- PASS: TestIsValidCachePath/short_hash (0.00s)1583 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1584 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1585 --- PASS: TestIsValidCachePath/empty (0.00s)1586 --- PASS: TestIsValidCachePath/random_path (0.00s)1587 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1588 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1589 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1590 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1591 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1592 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1593 --- PASS: TestIsValidCachePath/realisation (0.00s)1594 --- PASS: TestIsValidCachePath/log (0.00s)1595 --- PASS: TestIsValidCachePath/ls (0.00s)1596 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1597 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1598 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1599 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1600=== CONT TestParseSingleRange/none1601=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale16022026/10/08 12:57:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16032026/10/08 12:57:24 INFO Uploading bxnfvkgqdi2iq6qvd45ka5xw6ll15blz-pinned-file.txt (128B)1604=== CONT TestParseSingleRange/start_far_past_EOF1605=== CONT TestParseSingleRange/start_past_EOF1606=== CONT TestParseSingleRange/single_byte1607=== CONT TestParseSingleRange/suffix_exceeds_size1608=== CONT TestParseSingleRange/suffix1609=== CONT TestParseSingleRange/end_clamped_to_size16102026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1611=== CONT TestParseSingleRange/open-ended1612=== CONT TestParseSingleRange/closed1613=== CONT TestParseSingleRange/malformed_end_before_start1614=== CONT TestParseSingleRange/malformed_both_empty1615=== CONT TestParseSingleRange/malformed_no_dash1616=== CONT TestParseSingleRange/multi-range_ignored1617=== CONT TestParseSingleRange/unknown_unit1618--- PASS: TestParseSingleRange (0.00s)1619 --- PASS: TestParseSingleRange/none (0.00s)1620 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1621 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1622 --- PASS: TestParseSingleRange/single_byte (0.00s)1623 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1624 --- PASS: TestParseSingleRange/suffix (0.00s)1625 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1626 --- PASS: TestParseSingleRange/open-ended (0.00s)1627 --- PASS: TestParseSingleRange/closed (0.00s)1628 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1629 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1630 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1631 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1632 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1633=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16342026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16352026/10/08 12:57:24 WARN Failed to register uploaded object key=bxnfvkgqdi2iq6qvd45ka5xw6ll15blz.ls error="server returned 404: 404 page not found\n"16362026/10/08 12:57:24 INFO Signed narinfos id=1 count=116372026/10/08 12:57:24 INFO Uploading 1 narinfos16382026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete16392026/10/08 12:57:24 WARN Failed to register uploaded object key=bxnfvkgqdi2iq6qvd45ka5xw6ll15blz.narinfo error="server returned 404: 404 page not found\n"16402026/10/08 12:57:24 INFO Completed push id=1 objects=3 duration=7.701928ms16412026/10/08 12:57:24 INFO Upload complete. (61ms)16422026/10/08 12:57:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures16432026/10/08 12:57:24 INFO Garbage collection started1644=== RUN TestService_RequireScope_OIDC/builder_may_write1645=== PAUSE TestService_RequireScope_OIDC/builder_may_write1646=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1647=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1648=== RUN TestService_RequireScope_OIDC/ops_may_admin1649=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1650=== RUN TestService_RequireScope_OIDC/ops_may_not_write1651=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1652=== RUN TestService_RequireScope_OIDC/reader_may_not_write1653=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1654=== RUN TestService_RequireScope_OIDC/static_token_may_admin1655=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1656=== RUN TestService_RequireScope_OIDC/static_token_may_write1657=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1658=== RUN TestService_RequireScope_OIDC/reader_may_read1659=== PAUSE TestService_RequireScope_OIDC/reader_may_read1660=== RUN TestService_RequireScope_OIDC/writer_implies_read1661=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1662=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1663=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1664=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1665=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1666=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1667=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1668=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1669=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1670=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1671=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1672=== CONT TestGCEndsOnShutdown/before_the_run1673=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16742026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=016752026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period1676--- PASS: TestObjectStatsLargeCommit (1.64s)1677=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16782026/10/08 12:57:24 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=016792026/10/08 12:57:24 INFO Vacuumed table table=pending_closures16802026/10/08 12:57:24 INFO Vacuumed table table=pending_objects16812026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads16822026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes16832026/10/08 12:57:24 INFO Vacuumed table table=closures16842026/10/08 12:57:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16852026/10/08 12:57:24 INFO Uploading wwfg3by6wmg00gx887wkkw8c2wdy8hab-ca-test (144B)16862026/10/08 12:57:24 INFO Vacuumed table table=objects16872026/10/08 12:57:24 WARN Failed to register uploaded object key=log/2y3inacd76p6c49yl37x5b6lxscmc284-ca-test.drv error="server returned 404: 404 page not found\n"16882026/10/08 12:57:24 WARN Failed to register uploaded object key=wwfg3by6wmg00gx887wkkw8c2wdy8hab.ls error="server returned 404: 404 page not found\n"16892026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16902026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16912026/10/08 12:57:24 INFO Signed narinfos id=1 count=116922026/10/08 12:57:24 INFO Uploading 1 narinfos16932026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes16942026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes16952026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete16962026/10/08 12:57:24 WARN Failed to register uploaded object key=wwfg3by6wmg00gx887wkkw8c2wdy8hab.narinfo error="server returned 404: 404 page not found\n"16972026/10/08 12:57:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16982026/10/08 12:57:24 INFO Uploading v5vxd5fyip9vsc4j5vz19igh7zd50czj-unpinned-file.txt (128B)16992026/10/08 12:57:24 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17002026/10/08 12:57:24 INFO Uploading 8s2wczjf01gzrlabh0snakbndl782wgx-shared-dep (136B)17012026/10/08 12:57:24 INFO Uploading dz8hkzhwsp03igv8xxxiy3zyzb7xj32a-a (216B)17022026/10/08 12:57:24 WARN Failed to register uploaded object key=v5vxd5fyip9vsc4j5vz19igh7zd50czj.ls error="server returned 404: 404 page not found\n"17032026/10/08 12:57:24 INFO Completed push id=1 objects=4 duration=7.095262ms17042026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17052026/10/08 12:57:24 INFO Upload complete. (105ms)17062026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17072026/10/08 12:57:24 INFO Signed narinfos id=2 count=117082026/10/08 12:57:24 INFO Uploading 1 narinfos17092026/10/08 12:57:24 WARN Failed to register uploaded object key=fxzckqizhqdgprb7v9hhd3vbiijr9k5g.ls error="server returned 404: 404 page not found\n"17102026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/0rifkbzwjlg8d17k76lykjlxrd40f9f5qlz89rin796jiiafx2r0.nar.zst error="server returned 404: 404 page not found\n"17112026/10/08 12:57:24 WARN Failed to register uploaded object key=8s2wczjf01gzrlabh0snakbndl782wgx.ls error="server returned 404: 404 page not found\n"17122026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17132026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17142026/10/08 12:57:24 WARN Failed to register uploaded object key=dz8hkzhwsp03igv8xxxiy3zyzb7xj32a.ls error="server returned 404: 404 page not found\n"1715=== NAME TestClientCADerivations1716 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3020461884/001/store/wwfg3by6wmg00gx887wkkw8c2wdy8hab-ca-test1717 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1718 Compression: zstd1719 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1720 NarSize: 1441721 References: 1722 Deriver: /build/TestClientCADerivations3020461884/001/store/2y3inacd76p6c49yl37x5b6lxscmc284-ca-test.drv1723 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1724 client_ca_test.go:185: Checking for realisation files in S3...17252026/10/08 12:57:24 INFO Signed narinfos id=1 count=317262026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/2/complete17272026/10/08 12:57:24 INFO Uploading 3 narinfos17282026/10/08 12:57:24 WARN Failed to register uploaded object key=v5vxd5fyip9vsc4j5vz19igh7zd50czj.narinfo error="server returned 404: 404 page not found\n"1729 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1730 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17312026/10/08 12:57:24 INFO Completed push id=2 objects=3 duration=1.697575ms17322026/10/08 12:57:24 INFO Upload complete. (47ms)17332026/10/08 12:57:24 WARN Failed to register uploaded object key=8s2wczjf01gzrlabh0snakbndl782wgx.narinfo error="server returned 404: 404 page not found\n"17342026/10/08 12:57:24 WARN Failed to register uploaded object key=dz8hkzhwsp03igv8xxxiy3zyzb7xj32a.narinfo error="server returned 404: 404 page not found\n"17352026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/10/08 12:57:24 WARN Failed to register uploaded object key=fxzckqizhqdgprb7v9hhd3vbiijr9k5g.narinfo error="server returned 404: 404 page not found\n"17372026/10/08 12:57:24 INFO Completed push id=1 objects=8 duration=7.370825ms17382026/10/08 12:57:24 INFO Upload complete. (64ms)1739=== NAME TestClientPushesUseOnePush1740 client_pushes_test.go:97: Retrieved narinfo from S3:1741 StorePath: /build/TestClientPushesUseOnePush2488856316/001/store/8s2wczjf01gzrlabh0snakbndl782wgx-shared-dep1742 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1743 Compression: zstd1744 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821745 NarSize: 1361746 References: 1747 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1748=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1749=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1750=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1751=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1752=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1753=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1754=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1755=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1756=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1757=== NAME TestClientPushesUseOnePush1758 client_pushes_test.go:97: Retrieved narinfo from S3:1759 StorePath: /build/TestClientPushesUseOnePush2488856316/001/store/dz8hkzhwsp03igv8xxxiy3zyzb7xj32a-a1760 URL: nar/0rifkbzwjlg8d17k76lykjlxrd40f9f5qlz89rin796jiiafx2r0.nar.zst1761 Compression: zstd1762 NarHash: sha256:0rifkbzwjlg8d17k76lykjlxrd40f9f5qlz89rin796jiiafx2r01763 NarSize: 2161764 References: /build/TestClientPushesUseOnePush2488856316/001/store/8s2wczjf01gzrlabh0snakbndl782wgx-shared-dep1765 CA: text:sha256:1n1kh7fvigmfhmqibnl6cvd949j8l0knmvfqazmsg8jgkmlwr0b91766 client_pushes_test.go:97: Retrieved narinfo from S3:1767 StorePath: /build/TestClientPushesUseOnePush2488856316/001/store/fxzckqizhqdgprb7v9hhd3vbiijr9k5g-b1768 URL: nar/0rifkbzwjlg8d17k76lykjlxrd40f9f5qlz89rin796jiiafx2r0.nar.zst1769 Compression: zstd1770 NarHash: sha256:0rifkbzwjlg8d17k76lykjlxrd40f9f5qlz89rin796jiiafx2r01771 NarSize: 2161772 References: /build/TestClientPushesUseOnePush2488856316/001/store/8s2wczjf01gzrlabh0snakbndl782wgx-shared-dep1773 CA: text:sha256:1n1kh7fvigmfhmqibnl6cvd949j8l0knmvfqazmsg8jgkmlwr0b91774--- PASS: TestClientPushesUseOnePush (0.62s)1775=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17762026/10/08 12:57:24 INFO lead: acquired remote=192.0.2.1:123417772026/10/08 12:57:24 INFO Starting cleanup of old closures method=DELETE path=/api/closures17782026/10/08 12:57:24 INFO Garbage collection started17792026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=017802026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period1781=== NAME TestClientWithDependencies1782 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies4221898112/001/store/mrg1dawzp50w17f3n34lpwmp66cddjys-test-script17832026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes17842026/10/08 12:57:24 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17852026/10/08 12:57:24 INFO Uploading gjnkxq49k4zvp6smn2f98q4rbh9b69p4-top (224B)17862026/10/08 12:57:24 INFO Uploading 2b7ayrkl3537j9pwzfzrpp1wkkgkh9ap-shared-dep (136B)1787=== NAME TestClientCADerivations1788 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1789 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1790 error: binary cache 's3://bucket76?endpoint=http://localhost:39867®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3020461884/001/store'1791 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117922026/10/08 12:57:24 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=017932026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1hbqd9f0wkpg9vqsh626h6lf67h33vcmcffkkw03v4mbjlcj56mq.nar.zst error="server returned 404: 404 page not found\n"17942026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17952026/10/08 12:57:24 WARN Failed to register uploaded object key=2b7ayrkl3537j9pwzfzrpp1wkkgkh9ap.ls error="server returned 404: 404 page not found\n"17962026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17972026/10/08 12:57:24 WARN Failed to register uploaded object key=gjnkxq49k4zvp6smn2f98q4rbh9b69p4.ls error="server returned 404: 404 page not found\n"1798--- PASS: TestClientCADerivations (0.77s)1799=== CONT TestCacheConfigHandler/full_config,_no_issuer18002026/10/08 12:57:24 INFO Signed narinfos id=1 count=21801=== CONT TestCacheConfigHandler/no_signing_keys18022026/10/08 12:57:24 INFO Uploading 2 narinfos1803=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1804=== CONT TestCacheConfigHandler/no_cache_url_configured1805--- PASS: TestCacheConfigHandler (0.00s)1806 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1807 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1808 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1809 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1810=== CONT TestClientErrorHandling/InvalidStorePath18112026/10/08 12:57:24 INFO Vacuumed table table=pending_closures18122026/10/08 12:57:24 WARN Failed to register uploaded object key=2b7ayrkl3537j9pwzfzrpp1wkkgkh9ap.narinfo error="server returned 404: 404 page not found\n"18132026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete18142026/10/08 12:57:24 WARN Failed to register uploaded object key=gjnkxq49k4zvp6smn2f98q4rbh9b69p4.narinfo error="server returned 404: 404 page not found\n"18152026/10/08 12:57:24 INFO Vacuumed table table=pending_objects18162026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads18172026/10/08 12:57:24 INFO Vacuumed table table=closures18182026/10/08 12:57:24 INFO Completed push id=1 objects=6 duration=6.494397ms18192026/10/08 12:57:24 INFO Upload complete. (85ms)18202026/10/08 12:57:24 INFO Vacuumed table table=objects1821=== NAME TestClientSharedPathCommittedMidPush1822 client_integration_test.go:680: Retrieved narinfo from S3:1823 StorePath: /build/TestClientSharedPathCommittedMidPush2536450674/001/store/2b7ayrkl3537j9pwzfzrpp1wkkgkh9ap-shared-dep1824 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1825 Compression: zstd1826 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821827 NarSize: 1361828 References: 1829 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18302026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures1831 client_integration_test.go:680: Retrieved narinfo from S3:1832 StorePath: /build/TestClientSharedPathCommittedMidPush2536450674/001/store/gjnkxq49k4zvp6smn2f98q4rbh9b69p4-top1833 URL: nar/1hbqd9f0wkpg9vqsh626h6lf67h33vcmcffkkw03v4mbjlcj56mq.nar.zst1834 Compression: zstd1835 NarHash: sha256:1hbqd9f0wkpg9vqsh626h6lf67h33vcmcffkkw03v4mbjlcj56mq1836 NarSize: 2241837 References: /build/TestClientSharedPathCommittedMidPush2536450674/001/store/2b7ayrkl3537j9pwzfzrpp1wkkgkh9ap-shared-dep1838 CA: text:sha256:1bblk86x2ppnrzsgpn23whxk2846sjfv41kfccl06jd1a71d8rlb1839=== NAME TestClientWithDependencies1840 client_integration_test.go:615: Found 1 dependencies (including self)1841--- PASS: TestClientSharedPathCommittedMidPush (0.58s)1842=== CONT TestClientErrorHandling/ServerNotAvailable18432026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures18452026/10/08 12:57:24 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18462026/10/08 12:57:24 INFO Uploading p7mwwy3d1ifmwyqc36idbyfn6lv19h4z-shared-dep (136B)18472026/10/08 12:57:24 INFO Uploading 689ww0i81i9yx09kwr93kx4avwa93gqy-b (216B)18482026/10/08 12:57:24 WARN Failed to register uploaded object key=p7mwwy3d1ifmwyqc36idbyfn6lv19h4z.ls error="server returned 404: 404 page not found\n"18492026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/03iiaaap1kz8rm431ps4yg2y65sj4al79hn0lmfg8ps50s797amg.nar.zst error="server returned 404: 404 page not found\n"18502026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18512026/10/08 12:57:24 WARN Failed to register uploaded object key=2qym4vzdwbcny1kbbp4x202j0hm8rzhm.ls error="server returned 404: 404 page not found\n"18522026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18532026/10/08 12:57:24 WARN Failed to register uploaded object key=689ww0i81i9yx09kwr93kx4avwa93gqy.ls error="server returned 404: 404 page not found\n"18542026/10/08 12:57:24 INFO Signed narinfos id=1 count=218552026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18562026/10/08 12:57:24 INFO Signed narinfos id=2 count=218572026/10/08 12:57:24 INFO Uploading 4 narinfos18582026/10/08 12:57:24 WARN Failed to register uploaded object key=689ww0i81i9yx09kwr93kx4avwa93gqy.narinfo error="server returned 404: 404 page not found\n"18592026/10/08 12:57:24 WARN Failed to register uploaded object key=2qym4vzdwbcny1kbbp4x202j0hm8rzhm.narinfo error="server returned 404: 404 page not found\n"18602026/10/08 12:57:24 WARN Failed to register uploaded object key=p7mwwy3d1ifmwyqc36idbyfn6lv19h4z.narinfo error="server returned 404: 404 page not found\n"18612026/10/08 12:57:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18622026/10/08 12:57:24 WARN Failed to register uploaded object key=p7mwwy3d1ifmwyqc36idbyfn6lv19h4z.narinfo error="server returned 404: 404 page not found\n"18632026/10/08 12:57:24 INFO Received push request method=POST path=/api/pushes18642026/10/08 12:57:24 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18652026/10/08 12:57:24 INFO Completed upload id=1 objects=6 duration=5.583649ms18662026/10/08 12:57:24 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18672026/10/08 12:57:24 INFO Completed upload id=2 objects=6 duration=1.712035ms18682026/10/08 12:57:24 INFO Upload complete. (73ms)18692026/10/08 12:57:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18702026/10/08 12:57:24 INFO Uploading mrg1dawzp50w17f3n34lpwmp66cddjys-test-script (136B)1871=== NAME TestClientFallsBackToClosures1872 client_pushes_test.go:112: Retrieved narinfo from S3:1873 StorePath: /build/TestClientFallsBackToClosures2008696283/001/store/p7mwwy3d1ifmwyqc36idbyfn6lv19h4z-shared-dep1874 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1875 Compression: zstd1876 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821877 NarSize: 1361878 References: 1879 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1880 client_pushes_test.go:112: Retrieved narinfo from S3:1881 StorePath: /build/TestClientFallsBackToClosures2008696283/001/store/2qym4vzdwbcny1kbbp4x202j0hm8rzhm-a1882 URL: nar/03iiaaap1kz8rm431ps4yg2y65sj4al79hn0lmfg8ps50s797amg.nar.zst1883 Compression: zstd1884 NarHash: sha256:03iiaaap1kz8rm431ps4yg2y65sj4al79hn0lmfg8ps50s797amg1885 NarSize: 2161886 References: /build/TestClientFallsBackToClosures2008696283/001/store/p7mwwy3d1ifmwyqc36idbyfn6lv19h4z-shared-dep1887 CA: text:sha256:0j8lbgklzcggf4x9iyg6v2i58wna6iqqxfbcqhl84llrq2kbhlfm18882026/10/08 12:57:24 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18892026/10/08 12:57:24 WARN Failed to register uploaded object key=mrg1dawzp50w17f3n34lpwmp66cddjys.ls error="server returned 404: 404 page not found\n"18902026/10/08 12:57:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1891 client_pushes_test.go:112: Retrieved narinfo from S3:1892 StorePath: /build/TestClientFallsBackToClosures2008696283/001/store/689ww0i81i9yx09kwr93kx4avwa93gqy-b1893 URL: nar/03iiaaap1kz8rm431ps4yg2y65sj4al79hn0lmfg8ps50s797amg.nar.zst18942026/10/08 12:57:24 WARN Failed to register uploaded object key=log/xycyvivc67zsrb3qjw5pbmyp013plsfs-test-script.drv error="server returned 404: 404 page not found\n"1895 Compression: zstd18962026/10/08 12:57:24 INFO Signed narinfos id=1 count=11897 NarHash: sha256:03iiaaap1kz8rm431ps4yg2y65sj4al79hn0lmfg8ps50s797amg1898 NarSize: 2161899 References: /build/TestClientFallsBackToClosures2008696283/001/store/p7mwwy3d1ifmwyqc36idbyfn6lv19h4z-shared-dep1900 CA: text:sha256:0j8lbgklzcggf4x9iyg6v2i58wna6iqqxfbcqhl84llrq2kbhlfm19012026/10/08 12:57:24 INFO Uploading 1 narinfos19022026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=01903--- PASS: TestClientFallsBackToClosures (0.64s)1904=== CONT TestClientErrorHandling/InvalidAuthToken19052026/10/08 12:57:24 INFO Received complete push request method=POST path=/api/pushes/1/complete19062026/10/08 12:57:24 WARN Failed to register uploaded object key=mrg1dawzp50w17f3n34lpwmp66cddjys.narinfo error="server returned 404: 404 page not found\n"19072026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period19082026/10/08 12:57:24 INFO Completed push id=1 objects=4 duration=5.992973ms19092026/10/08 12:57:24 INFO Upload complete. (62ms)1910=== NAME TestClientWithDependencies1911 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4221898112/001/store) requires matching store prefix19122026/10/08 12:57:24 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39867/bucket94/?delete=\": context canceled"1913=== CONT TestResolveDBConnectionString/flag_wins1914=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1915=== CONT TestResolveDBConnectionString/nothing_configured1916=== CONT TestResolveDBConnectionString/missing_file_is_an_error1917=== CONT TestResolveDBConnectionString/file_when_flag_empty1918--- PASS: TestClientWithDependencies (0.60s)1919=== CONT TestService_RequireScope_OIDC/reader_may_read1920=== CONT TestService_RequireScope_OIDC/builder_may_write1921--- PASS: TestResolveDBConnectionString (0.00s)1922 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1923 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1924 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1925 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1926 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1927=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1928=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19292026/10/08 12:57:24 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]1930=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1931=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1932=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1933=== CONT TestService_RequireScope_OIDC/writer_implies_read1934=== CONT TestService_RequireScope_OIDC/static_token_may_write1935=== CONT TestService_RequireScope_OIDC/static_token_may_admin1936=== CONT TestService_RequireScope_OIDC/ops_may_admin1937=== CONT TestService_RequireScope_OIDC/reader_may_not_write1938=== CONT TestService_RequireScope_OIDC/ops_may_not_write1939=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1940=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19412026/10/08 12:57:24 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]1942=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1943=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1944=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1945--- PASS: TestService_RequireScope_OIDC (0.48s)1946 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19602026/10/08 12:57:24 WARN Authentication failed token_preview=eyJhbGciOi...aCYAbMjxLw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1961--- PASS: TestService_AuthMiddleware_OIDC (0.57s)1962 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1963 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1964 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1965 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19662026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=01967--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.71s)19682026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period19692026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures19702026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=01971--- PASS: TestGCEndsOnShutdown (0.00s)1972 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.30s)1973 --- PASS: TestGCEndsOnShutdown/before_the_run (0.30s)1974 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.34s)19752026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period19762026/10/08 12:57:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.089235ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19772026/10/08 12:57:24 INFO Received uploads request method=POST path=/api/pending_closures19782026/10/08 12:57:24 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=019792026/10/08 12:57:24 INFO Vacuumed table table=pending_closures19802026/10/08 12:57:24 INFO Vacuumed table table=pending_objects19812026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads19822026/10/08 12:57:24 INFO Vacuumed table table=closures19832026/10/08 12:57:24 INFO Vacuumed table table=objects19842026/10/08 12:57:24 INFO Aborted multipart uploads count=0 kept=019852026/10/08 12:57:24 WARN Force mode enabled - objects will be deleted immediately without grace period19862026/10/08 12:57:24 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=019872026/10/08 12:57:24 INFO Vacuumed table table=pending_closures19882026/10/08 12:57:24 INFO Vacuumed table table=pending_objects19892026/10/08 12:57:24 INFO Vacuumed table table=multipart_uploads19902026/10/08 12:57:24 INFO Vacuumed table table=closures19912026/10/08 12:57:24 INFO Vacuumed table table=objects1992--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1993 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.32s)1994 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)19952026/10/08 12:57:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19962026/10/08 12:57:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19972026/10/08 12:57:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.745453ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19982026/10/08 12:57:25 INFO lead: released remote=192.0.2.1:12341999--- PASS: TestLeadEndsOnShutdown (1.43s)2000--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2001 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.76s)2002 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.77s)2003--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2004 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2005 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2006 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.86s)2007=== NAME TestOrphanedObjectsGCStressTest2008 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2009 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20102026/10/08 12:57:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=793.049113ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2011--- PASS: TestPendingClosureWriteTimeout (0.00s)2012 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2013 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2014 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2015 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.16s)2016=== NAME TestOrphanedObjectsGCStressTest2017 orphaned_objects_gc_test.go:503: Stress test completed successfully:2018 orphaned_objects_gc_test.go:504: - Active objects preserved: 202019 orphaned_objects_gc_test.go:505: - Objects deleted: 2102020 orphaned_objects_gc_test.go:506: - Total GC'd: 2102021--- PASS: TestOrphanedObjectsGCStressTest (2.67s)2022--- PASS: TestDeleteClosuresRacingPins (1.50s)20232026/10/08 12:57:25 INFO lead: released remote=192.0.2.1:123420242026/10/08 12:57:25 INFO lead: acquired remote=192.0.2.1:123420252026/10/08 12:57:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.548843017s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20262026/10/08 12:57:26 WARN Rate limiter enabled after throttle name=s3-test rate=520272026/10/08 12:57:26 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2028=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2029 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102030 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002031--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.61s)20322026/10/08 12:57:26 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02033=== NAME TestClientIntegration2034 client_integration_test.go:323: Objects in database after GC:2035 client_integration_test.go:323: Successfully deleted all objects with GC --force2036--- PASS: TestClientIntegration (2.66s)20372026/10/08 12:57:26 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020382026/10/08 12:57:26 INFO Received create pin request method=POST path=/api/pins/myapp20392026/10/08 12:57:26 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2734464361/001/store/bxnfvkgqdi2iq6qvd45ka5xw6ll15blz-pinned-file.txt narinfo_key=bxnfvkgqdi2iq6qvd45ka5xw6ll15blz.narinfo20402026/10/08 12:57:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures20412026/10/08 12:57:26 INFO Garbage collection started20422026/10/08 12:57:26 INFO Aborted multipart uploads count=0 kept=020432026/10/08 12:57:26 WARN Force mode enabled - objects will be deleted immediately without grace period20442026/10/08 12:57:26 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=020452026/10/08 12:57:26 INFO Vacuumed table table=pending_closures20462026/10/08 12:57:26 INFO Vacuumed table table=pending_objects20472026/10/08 12:57:26 INFO Vacuumed table table=multipart_uploads20482026/10/08 12:57:26 INFO Vacuumed table table=closures20492026/10/08 12:57:26 INFO Vacuumed table table=objects20502026/10/08 12:57:27 INFO lead: released remote=192.0.2.1:12342051--- PASS: TestLeadElectsOneAndHandsOver (2.74s)2052--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.96s)20532026/10/08 12:57:27 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20542026/10/08 12:57:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.359018ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20552026/10/08 12:57:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=434.919149ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/08 12:57:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.448742ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2057=== NAME TestPinProtectsFromGC2058 client_integration_test.go:840: Pin successfully protected closure from garbage collection2059--- PASS: TestPinProtectsFromGC (4.71s)2060--- PASS: TestConnectWaitsForAPeerMigration (5.15s)20612026/10/08 12:57:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.714574533s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/10/08 12:57:30 INFO Aborted multipart uploads count=1 kept=020632026/10/08 12:57:30 INFO Received cleanup request method=DELETE path=/api/pending_closures20642026/10/08 12:57:30 INFO Aborted multipart uploads count=1 kept=02065--- PASS: TestPendingCleanupUsesOneCutoff (6.46s)20662026/10/08 12:57:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20672026/10/08 12:57:31 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20682026/10/08 12:57:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.699907ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20692026/10/08 12:57:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.080684ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20702026/10/08 12:57:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.706561ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20712026/10/08 12:57:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.67924476s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20722026/10/08 12:57:34 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20732026/10/08 12:57:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.780178ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20742026/10/08 12:57:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.732677ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20752026/10/08 12:57:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=764.129084ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20762026/10/08 12:57:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.624588392s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2077--- PASS: TestClientErrorHandling (0.00s)2078 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)2079 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.25s)2080 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)2081PASS20822026-10-08 12:57:37.661 UTC [129] LOG: received smart shutdown request20832026-10-08 12:57:37.665 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120842026-10-08 12:57:37.679 UTC [134] LOG: shutting down20852026-10-08 12:57:37.680 UTC [134] LOG: checkpoint starting: shutdown immediate20862026-10-08 12:57:38.812 UTC [134] LOG: checkpoint complete: wrote 10607 buffers (64.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.209 s, sync=0.878 s, total=1.133 s; sync files=34045, longest=0.170 s, average=0.001 s; distance=531600 kB, estimate=531600 kB; lsn=0/21E8A048, redo lsn=0/21E8A04820872026-10-08 12:57:38.890 UTC [129] LOG: database system is shut down2088Running OIDC tests...2089=== RUN TestAudienceForIssuer2090=== PAUSE TestAudienceForIssuer2091=== RUN TestGlobMatch2092=== PAUSE TestGlobMatch2093=== RUN TestValidateToken_ValidToken2094=== PAUSE TestValidateToken_ValidToken2095=== RUN TestValidateToken_WrongAudience2096=== PAUSE TestValidateToken_WrongAudience2097=== RUN TestValidateToken_Expired2098=== PAUSE TestValidateToken_Expired2099=== RUN TestValidateToken_BoundClaimsMismatch2100=== PAUSE TestValidateToken_BoundClaimsMismatch2101=== RUN TestValidateToken_BoundSubjectMismatch2102=== PAUSE TestValidateToken_BoundSubjectMismatch2103=== RUN TestValidateToken_MultipleProviders2104=== PAUSE TestValidateToken_MultipleProviders2105=== RUN TestValidateToken_NoMatchingProvider2106=== PAUSE TestValidateToken_NoMatchingProvider2107=== RUN TestValidateToken_KubernetesServiceAccount2108=== PAUSE TestValidateToken_KubernetesServiceAccount2109=== RUN TestNewValidator_KubernetesRequiresCA2110=== PAUSE TestNewValidator_KubernetesRequiresCA2111=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2112=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2113=== RUN TestPins_ReservedForMatchingRule2114=== PAUSE TestPins_ReservedForMatchingRule2115=== RUN TestPins_TopLevelShorthand2116=== PAUSE TestPins_TopLevelShorthand2117=== RUN TestPins_ConfigValidation2118=== PAUSE TestPins_ConfigValidation2119=== RUN TestScopes_LegacyProviderDefaultsToWrite2120=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2121=== RUN TestScopes_Rules2122=== PAUSE TestScopes_Rules2123=== RUN TestScopes_ConfigValidation2124=== PAUSE TestScopes_ConfigValidation2125=== CONT TestAudienceForIssuer2126=== CONT TestValidateToken_KubernetesServiceAccount2127=== CONT TestValidateToken_BoundSubjectMismatch2128=== CONT TestValidateToken_BoundClaimsMismatch2129=== CONT TestValidateToken_WrongAudience2130--- PASS: TestAudienceForIssuer (0.00s)2131=== CONT TestValidateToken_ValidToken2132=== CONT TestGlobMatch2133=== RUN TestGlobMatch/foo_foo2134=== PAUSE TestGlobMatch/foo_foo2135=== RUN TestGlobMatch/foo_bar2136=== PAUSE TestGlobMatch/foo_bar2137=== RUN TestGlobMatch/*_2138=== PAUSE TestGlobMatch/*_2139=== RUN TestGlobMatch/*_anything2140=== PAUSE TestGlobMatch/*_anything2141=== RUN TestGlobMatch/foo*_foo2142=== PAUSE TestGlobMatch/foo*_foo2143=== RUN TestGlobMatch/foo*_foobar2144=== PAUSE TestGlobMatch/foo*_foobar2145=== RUN TestGlobMatch/foo*_bar2146=== PAUSE TestGlobMatch/foo*_bar2147=== RUN TestGlobMatch/*bar_bar2148=== PAUSE TestGlobMatch/*bar_bar2149=== RUN TestGlobMatch/*bar_foobar2150=== PAUSE TestGlobMatch/*bar_foobar2151=== RUN TestGlobMatch/*bar_foo2152=== PAUSE TestGlobMatch/*bar_foo2153=== RUN TestGlobMatch/foo*bar_foobar2154=== PAUSE TestGlobMatch/foo*bar_foobar2155=== RUN TestGlobMatch/foo*bar_foo123bar2156=== PAUSE TestGlobMatch/foo*bar_foo123bar2157=== RUN TestGlobMatch/foo*bar_foobarbaz2158=== PAUSE TestGlobMatch/foo*bar_foobarbaz2159=== RUN TestGlobMatch/*/*_foo/bar2160=== PAUSE TestGlobMatch/*/*_foo/bar2161=== RUN TestGlobMatch/*/*_foo2162=== PAUSE TestGlobMatch/*/*_foo2163=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2164=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2165=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02166=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02167=== RUN TestGlobMatch/refs/*/main_refs/heads/main2168=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2169=== RUN TestGlobMatch/fo?_foo2170=== PAUSE TestGlobMatch/fo?_foo2171=== RUN TestGlobMatch/fo?_fo2172=== PAUSE TestGlobMatch/fo?_fo2173=== RUN TestGlobMatch/fo?_fooo2174=== PAUSE TestGlobMatch/fo?_fooo2175=== RUN TestGlobMatch/?oo_foo2176=== PAUSE TestGlobMatch/?oo_foo2177=== RUN TestGlobMatch/?oo_boo2178=== PAUSE TestGlobMatch/?oo_boo2179=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2180=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2181=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2182=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2183=== CONT TestGlobMatch/foo_foo2184=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2185=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2186=== CONT TestGlobMatch/?oo_boo2187=== CONT TestGlobMatch/?oo_foo2188=== CONT TestGlobMatch/fo?_fooo2189=== CONT TestGlobMatch/fo?_fo2190=== CONT TestGlobMatch/fo?_foo2191=== CONT TestGlobMatch/refs/*/main_refs/heads/main2192=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02193=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2194=== CONT TestGlobMatch/*/*_foo2195=== CONT TestGlobMatch/*/*_foo/bar2196=== CONT TestGlobMatch/foo*bar_foobarbaz2197=== CONT TestGlobMatch/foo*bar_foo123bar2198=== CONT TestGlobMatch/foo*bar_foobar2199=== CONT TestGlobMatch/*bar_foo2200=== CONT TestGlobMatch/*bar_foobar2201=== CONT TestGlobMatch/*bar_bar2202=== CONT TestGlobMatch/foo*_bar2203=== CONT TestGlobMatch/foo*_foobar2204=== CONT TestGlobMatch/foo*_foo2205=== CONT TestGlobMatch/*_anything2206=== CONT TestGlobMatch/*_2207=== CONT TestGlobMatch/foo_bar2208--- PASS: TestGlobMatch (0.00s)2209 --- PASS: TestGlobMatch/foo_foo (0.00s)2210 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2211 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2212 --- PASS: TestGlobMatch/?oo_boo (0.00s)2213 --- PASS: TestGlobMatch/?oo_foo (0.00s)2214 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2215 --- PASS: TestGlobMatch/fo?_fo (0.00s)2216 --- PASS: TestGlobMatch/fo?_foo (0.00s)2217 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2218 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2219 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2220 --- PASS: TestGlobMatch/*/*_foo (0.00s)2221 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2222 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2223 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2224 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2225 --- PASS: TestGlobMatch/*bar_foo (0.00s)2226 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2227 --- PASS: TestGlobMatch/*bar_bar (0.00s)2228 --- PASS: TestGlobMatch/foo*_bar (0.00s)2229 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2230 --- PASS: TestGlobMatch/foo*_foo (0.00s)2231 --- PASS: TestGlobMatch/*_anything (0.00s)2232 --- PASS: TestGlobMatch/*_ (0.00s)2233 --- PASS: TestGlobMatch/foo_bar (0.00s)2234=== CONT TestPins_ConfigValidation2235=== CONT TestScopes_ConfigValidation2236=== CONT TestScopes_Rules2237=== CONT TestScopes_LegacyProviderDefaultsToWrite2238=== CONT TestValidateToken_MultipleProviders2239=== CONT TestValidateToken_NoMatchingProvider2240=== CONT TestPins_ReservedForMatchingRule2241--- PASS: TestPins_ConfigValidation (0.00s)2242=== CONT TestPins_TopLevelShorthand2243=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2244--- PASS: TestScopes_ConfigValidation (0.00s)2245=== CONT TestValidateToken_Expired2246=== CONT TestNewValidator_KubernetesRequiresCA22472026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36585/oidc2248--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)22492026/10/08 12:57:40 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322502026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42425/oidc22512026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35417/oidc2252--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)2253--- PASS: TestScopes_Rules (0.08s)2254--- PASS: TestPins_ReservedForMatchingRule (0.08s)22552026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46139/oidc2256--- PASS: TestValidateToken_Expired (0.08s)22572026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43449/oidc22582026/10/08 12:57:40 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41733/oidc22592026/10/08 12:57:40 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35815/oidc2260--- PASS: TestValidateToken_WrongAudience (0.11s)22612026/10/08 12:57:40 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:410432262--- PASS: TestValidateToken_MultipleProviders (0.11s)2263--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)22642026/10/08 12:57:40 http: TLS handshake error from 127.0.0.1:49302: remote error: tls: bad certificate2265--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)22662026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40839/oidc2267--- PASS: TestPins_TopLevelShorthand (0.13s)22682026/10/08 12:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35009/oidc2269--- PASS: TestValidateToken_BoundSubjectMismatch (0.20s)22702026/10/08 12:57:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34809/oidc2271--- PASS: TestValidateToken_NoMatchingProvider (0.21s)22722026/10/08 12:57:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40127/oidc2273--- PASS: TestValidateToken_ValidToken (0.25s)22742026/10/08 12:57:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33661/oidc2275--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.39s)2276PASS2277Running hook tests...2278=== RUN TestSendPathsEmpty2279=== PAUSE TestSendPathsEmpty2280=== RUN TestQueueEnqueueAndFetch2281=== PAUSE TestQueueEnqueueAndFetch2282=== RUN TestQueueDeduplication2283=== PAUSE TestQueueDeduplication2284=== RUN TestQueueRemove2285=== PAUSE TestQueueRemove2286=== RUN TestQueueFetchBatchLimit2287=== PAUSE TestQueueFetchBatchLimit2288=== RUN TestQueueRetryMovesToBack2289=== PAUSE TestQueueRetryMovesToBack2290=== RUN TestQueueFetchRemoveLifecycle2291=== PAUSE TestQueueFetchRemoveLifecycle2292=== RUN TestQueueConcurrentWriters2293=== PAUSE TestQueueConcurrentWriters2294=== RUN TestQueueRemoveLargeClosure2295=== PAUSE TestQueueRemoveLargeClosure2296=== RUN TestServerClientIntegration2297--- PASS: TestServerClientIntegration (0.00s)2298=== RUN TestServerQueueError22992026/10/08 12:57:41 ERROR Failed to queue paths error="permission denied" count=12300--- PASS: TestServerQueueError (0.00s)2301=== RUN TestGetListenerSocketActivation2302 server_test.go:219: === RUN TestGetListenerSocketActivation2303 --- PASS: TestGetListenerSocketActivation (0.00s)2304 PASS2305 2306--- PASS: TestGetListenerSocketActivation (0.01s)2307=== RUN TestDrainIsolatesPoisonPath2308=== PAUSE TestDrainIsolatesPoisonPath2309=== RUN TestRunNotBlockedByPoisonHead2310=== PAUSE TestRunNotBlockedByPoisonHead2311=== RUN TestDrainGivesUpWhenServerDown2312=== PAUSE TestDrainGivesUpWhenServerDown2313=== RUN TestFailedPathPrunedByLaterClosure2314=== PAUSE TestFailedPathPrunedByLaterClosure2315=== RUN TestWorkerUploadsAndRemoves2316=== PAUSE TestWorkerUploadsAndRemoves2317=== RUN TestWorkerSkipsGCdPaths2318=== PAUSE TestWorkerSkipsGCdPaths2319=== RUN TestWorkerPrunesClosureDeps2320=== PAUSE TestWorkerPrunesClosureDeps2321=== RUN TestDrainTimeout2322=== PAUSE TestDrainTimeout2323=== CONT TestSendPathsEmpty2324=== CONT TestDrainTimeout2325--- PASS: TestSendPathsEmpty (0.00s)2326=== CONT TestQueueConcurrentWriters2327=== CONT TestQueueFetchRemoveLifecycle2328=== CONT TestQueueRemoveLargeClosure2329=== CONT TestWorkerPrunesClosureDeps2330=== CONT TestQueueRetryMovesToBack2331=== CONT TestWorkerSkipsGCdPaths2332=== CONT TestQueueFetchBatchLimit2333=== CONT TestWorkerUploadsAndRemoves2334=== CONT TestQueueRemove2335=== CONT TestRunNotBlockedByPoisonHead2336=== CONT TestQueueDeduplication2337=== CONT TestDrainIsolatesPoisonPath2338=== CONT TestDrainGivesUpWhenServerDown2339=== CONT TestQueueEnqueueAndFetch2340=== CONT TestFailedPathPrunedByLaterClosure23412026/10/08 12:57:41 INFO Upload queue status pending=223422026/10/08 12:57:41 INFO Uploading batch count=123432026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=123442026/10/08 12:57:41 INFO Upload queue status pending=223452026/10/08 12:57:41 INFO Uploading batch count=223462026/10/08 12:57:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths767323442/002/nonexistent23472026/10/08 12:57:41 INFO Uploading batch count=223482026/10/08 12:57:41 INFO Uploading batch count=423492026/10/08 12:57:41 INFO Upload queue status pending=223502026/10/08 12:57:41 INFO Uploading batch count=12351--- PASS: TestQueueEnqueueAndFetch (0.02s)23522026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=423532026/10/08 12:57:41 INFO Uploading batch count=223542026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=223552026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/a2356--- PASS: TestQueueFetchBatchLimit (0.02s)23572026/10/08 12:57:41 INFO Uploading batch count=123582026/10/08 12:57:41 INFO Uploading batch count=12359--- PASS: TestQueueRemove (0.02s)23602026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath561918517/002/bbb23612026/10/08 12:57:41 INFO Uploading batch count=12362--- PASS: TestQueueDeduplication (0.02s)23632026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/b2364--- PASS: TestQueueRetryMovesToBack (0.02s)2365--- PASS: TestQueueFetchRemoveLifecycle (0.02s)23662026/10/08 12:57:41 INFO Uploading batch count=223672026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=223682026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/c23692026/10/08 12:57:41 INFO Uploading batch count=123702026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=123712026/10/08 12:57:41 INFO Upload queue status pending=323722026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/d2373--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23742026/10/08 12:57:41 INFO Uploading batch count=123752026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=123762026/10/08 12:57:41 INFO Uploading batch count=123772026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=123782026/10/08 12:57:41 INFO Uploading batch count=223792026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=223802026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/e23812026/10/08 12:57:41 INFO Uploading batch count=123822026/10/08 12:57:41 ERROR Upload failed error="upload failed" count=123832026/10/08 12:57:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1725670240/002/f23842026/10/08 12:57:41 ERROR Drain finished with paths left in queue remaining=123852026/10/08 12:57:41 ERROR Drain finished with paths left in queue remaining=102386--- PASS: TestDrainIsolatesPoisonPath (0.02s)2387--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2388--- PASS: TestWorkerSkipsGCdPaths (0.04s)2389--- PASS: TestWorkerPrunesClosureDeps (0.04s)2390--- PASS: TestWorkerUploadsAndRemoves (0.04s)2391--- PASS: TestQueueRemoveLargeClosure (0.09s)23922026/10/08 12:57:41 ERROR Upload failed error="context deadline exceeded" count=223932026/10/08 12:57:41 ERROR Drain finished with paths left in queue remaining=42394--- PASS: TestDrainTimeout (0.22s)2395--- PASS: TestQueueConcurrentWriters (0.27s)23962026/10/08 12:57:42 INFO Uploading batch count=123972026/10/08 12:57:42 INFO Uploading batch count=123982026/10/08 12:57:42 INFO Uploading batch count=123992026/10/08 12:57:42 ERROR Upload failed error="upload failed" count=124002026/10/08 12:57:42 INFO Uploading batch count=124012026/10/08 12:57:42 ERROR Upload failed error="upload failed" count=124022026/10/08 12:57:42 INFO Uploading batch count=124032026/10/08 12:57:42 ERROR Upload failed error="upload failed" count=124042026/10/08 12:57:42 INFO Uploading batch count=124052026/10/08 12:57:42 ERROR Upload failed error="upload failed" count=124062026/10/08 12:57:42 ERROR Drain finished with paths left in queue remaining=12407--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2408PASS2409Running signing tests...2410=== RUN TestExternalSigner2411=== PAUSE TestExternalSigner2412=== RUN TestExternalSignerWrongPublicKey2413=== PAUSE TestExternalSignerWrongPublicKey2414=== RUN TestExternalSignerErrors2415=== PAUSE TestExternalSignerErrors2416=== RUN TestExternalSignerRestartsAfterCrash2417=== PAUSE TestExternalSignerRestartsAfterCrash2418=== RUN TestExternalSignerProgramErrorKeepsProcess2419=== PAUSE TestExternalSignerProgramErrorKeepsProcess2420=== RUN TestExternalSignerClose2421=== PAUSE TestExternalSignerClose2422=== RUN TestExternalSignerRejectsInvalidPublicKey2423=== PAUSE TestExternalSignerRejectsInvalidPublicKey2424=== RUN TestExternalSignerCancellation2425=== PAUSE TestExternalSignerCancellation2426=== RUN TestGenerateFingerprint2427=== PAUSE TestGenerateFingerprint2428=== RUN TestParseSigningKey2429=== PAUSE TestParseSigningKey2430=== RUN TestSign2431=== PAUSE TestSign2432=== RUN TestSignBatch2433=== PAUSE TestSignBatch2434=== RUN TestNilKeyPublicKey2435=== PAUSE TestNilKeyPublicKey2436=== RUN TestSignErrors2437=== PAUSE TestSignErrors2438=== CONT TestExternalSigner2439=== CONT TestExternalSignerCancellation2440=== CONT TestSignBatch2441=== CONT TestSignErrors2442=== CONT TestSign2443=== CONT TestParseSigningKey2444=== RUN TestParseSigningKey/valid_32-byte_key2445=== CONT TestGenerateFingerprint2446=== RUN TestGenerateFingerprint/basic_with_references2447=== CONT TestExternalSignerProgramErrorKeepsProcess2448=== PAUSE TestGenerateFingerprint/basic_with_references2449=== RUN TestGenerateFingerprint/no_references2450=== PAUSE TestGenerateFingerprint/no_references2451=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2452=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2453=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2454=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2455=== RUN TestGenerateFingerprint/invalid_nar_hash_length2456=== CONT TestExternalSignerRejectsInvalidPublicKey2457=== RUN TestExternalSignerRejectsInvalidPublicKey/#002458=== CONT TestExternalSignerClose2459=== CONT TestNilKeyPublicKey2460--- PASS: TestNilKeyPublicKey (0.00s)2461=== CONT TestExternalSignerErrors2462=== RUN TestExternalSignerErrors/exit_at_startup2463=== PAUSE TestExternalSignerErrors/exit_at_startup2464=== RUN TestExternalSignerErrors/invalid_JSON2465=== PAUSE TestExternalSignerErrors/invalid_JSON2466=== CONT TestExternalSignerRestartsAfterCrash2467=== CONT TestExternalSignerWrongPublicKey2468=== PAUSE TestParseSigningKey/valid_32-byte_key2469=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2470=== RUN TestGenerateFingerprint/invalid_store_path_prefix2471=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2472=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002473=== RUN TestExternalSignerErrors/wrong_shape2474=== PAUSE TestExternalSignerErrors/wrong_shape2475=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2476=== RUN TestExternalSignerErrors/missing_signatures2477=== PAUSE TestExternalSignerErrors/missing_signatures2478=== RUN TestGenerateFingerprint/invalid_reference_prefix2479=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2480=== CONT TestGenerateFingerprint/basic_with_references2481=== CONT TestGenerateFingerprint/invalid_nar_hash_length2482=== CONT TestGenerateFingerprint/invalid_reference_prefix2483=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2484=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2485=== RUN TestParseSigningKey/no_colon2486=== PAUSE TestParseSigningKey/no_colon2487=== RUN TestParseSigningKey/empty_name2488=== PAUSE TestParseSigningKey/empty_name2489=== RUN TestParseSigningKey/invalid_base642490=== PAUSE TestParseSigningKey/invalid_base642491=== RUN TestParseSigningKey/wrong_length2492=== PAUSE TestParseSigningKey/wrong_length2493=== RUN TestExternalSignerErrors/wrong_signature_name2494=== PAUSE TestExternalSignerErrors/wrong_signature_name2495=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2496=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2497=== CONT TestGenerateFingerprint/no_references2498=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2499=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2500=== CONT TestGenerateFingerprint/invalid_store_path_prefix2501--- PASS: TestGenerateFingerprint (0.00s)2502 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2503 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2504 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2505 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2506 --- PASS: TestGenerateFingerprint/no_references (0.00s)2507 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2508 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2509=== CONT TestParseSigningKey/valid_32-byte_key2510=== CONT TestParseSigningKey/wrong_length2511=== CONT TestParseSigningKey/no_colon2512=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2513=== CONT TestParseSigningKey/invalid_base642514=== CONT TestParseSigningKey/empty_name2515=== RUN TestExternalSignerErrors/null2516=== PAUSE TestExternalSignerErrors/null2517=== RUN TestExternalSignerErrors/null_signatures2518=== PAUSE TestExternalSignerErrors/null_signatures2519=== RUN TestExternalSignerErrors/unrequested_key2520=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2521=== PAUSE TestExternalSignerErrors/unrequested_key2522=== RUN TestExternalSignerErrors/missing_signature_name2523=== PAUSE TestExternalSignerErrors/missing_signature_name2524=== RUN TestExternalSignerErrors/wrong_signatures_shape2525=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2526=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2527=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2528=== RUN TestExternalSignerErrors/too_few_signatures2529=== PAUSE TestExternalSignerErrors/too_few_signatures2530=== RUN TestExternalSignerErrors/invalid_signature_base642531=== PAUSE TestExternalSignerErrors/invalid_signature_base642532=== RUN TestExternalSignerErrors/wrong_signature_length2533=== PAUSE TestExternalSignerErrors/wrong_signature_length2534=== RUN TestExternalSignerErrors/program_error2535=== PAUSE TestExternalSignerErrors/program_error2536=== RUN TestExternalSignerErrors/exit_on_request2537=== PAUSE TestExternalSignerErrors/exit_on_request2538=== RUN TestExternalSignerErrors/wrong_id2539=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2540=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2541=== CONT TestExternalSignerRejectsInvalidPublicKey/#002542=== RUN TestSignErrors/nil_key2543=== PAUSE TestSignErrors/nil_key2544=== RUN TestSignErrors/nil_narinfo2545=== PAUSE TestSignErrors/nil_narinfo2546=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2547=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2548=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2549=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2550=== PAUSE TestExternalSignerErrors/wrong_id2551=== CONT TestExternalSignerErrors/exit_at_startup2552=== CONT TestExternalSignerErrors/wrong_signatures_shape2553=== CONT TestExternalSignerErrors/exit_on_request2554=== CONT TestExternalSignerErrors/program_error2555=== CONT TestExternalSignerErrors/wrong_id2556=== RUN TestSignErrors/invalid_narinfo2557=== PAUSE TestSignErrors/invalid_narinfo2558--- PASS: TestParseSigningKey (0.00s)2559 --- PASS: TestParseSigningKey/wrong_length (0.00s)2560 --- PASS: TestParseSigningKey/no_colon (0.00s)2561 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2562 --- PASS: TestParseSigningKey/empty_name (0.00s)2563 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2564 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2565--- PASS: TestSign (0.00s)2566--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2567 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2568 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2569 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2570 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2571 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2572=== CONT TestExternalSignerErrors/null2573--- PASS: TestSignBatch (0.00s)2574=== CONT TestExternalSignerErrors/missing_signature_name2575=== CONT TestExternalSignerErrors/unrequested_key2576--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2577=== CONT TestExternalSignerErrors/null_signatures2578=== CONT TestExternalSignerErrors/wrong_signature_length2579=== CONT TestExternalSignerErrors/invalid_signature_base642580=== CONT TestExternalSignerErrors/too_few_signatures2581=== CONT TestExternalSignerErrors/missing_signatures2582=== CONT TestExternalSignerErrors/wrong_signature_name2583=== CONT TestExternalSignerErrors/wrong_shape2584=== CONT TestExternalSignerErrors/invalid_JSON2585=== RUN TestSignErrors/canceled2586=== PAUSE TestSignErrors/canceled2587=== CONT TestSignErrors/nil_key2588--- PASS: TestExternalSignerWrongPublicKey (0.01s)2589--- PASS: TestExternalSignerClose (0.01s)2590=== CONT TestSignErrors/canceled2591=== CONT TestSignErrors/nil_narinfo2592=== CONT TestSignErrors/invalid_narinfo2593--- PASS: TestSignErrors (0.01s)2594 --- PASS: TestSignErrors/nil_key (0.00s)2595 --- PASS: TestSignErrors/canceled (0.00s)2596 --- PASS: TestSignErrors/nil_narinfo (0.00s)2597 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2598--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2599--- PASS: TestExternalSigner (0.01s)2600--- PASS: TestExternalSignerErrors (0.00s)2601 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2602 --- PASS: TestExternalSignerErrors/program_error (0.00s)2603 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2604 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2605 --- PASS: TestExternalSignerErrors/null (0.01s)2606 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2607 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2608 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2609 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2610 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2611 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2612 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2613 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2614 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2615 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2616 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2617--- PASS: TestExternalSignerCancellation (0.02s)2618PASS2619Running OpenBao signer tests...2620=== RUN TestSign2621=== PAUSE TestSign2622=== RUN TestSignErrors2623=== PAUSE TestSignErrors2624=== RUN TestServe2625=== PAUSE TestServe2626=== RUN TestServeRejectsGarbage2627=== PAUSE TestServeRejectsGarbage2628=== CONT TestSign2629=== CONT TestSignErrors2630=== CONT TestServe2631=== RUN TestSignErrors/http_error2632=== CONT TestServeRejectsGarbage2633--- PASS: TestServeRejectsGarbage (0.00s)2634=== PAUSE TestSignErrors/http_error2635=== RUN TestSignErrors/invalid_json2636=== PAUSE TestSignErrors/invalid_json2637=== RUN TestSignErrors/no_prefix2638=== PAUSE TestSignErrors/no_prefix2639=== RUN TestSignErrors/invalid_base642640=== PAUSE TestSignErrors/invalid_base642641=== CONT TestSignErrors/http_error2642=== CONT TestSignErrors/no_prefix2643--- PASS: TestServe (0.00s)2644=== CONT TestSignErrors/invalid_base642645=== CONT TestSignErrors/invalid_json2646--- PASS: TestSign (0.00s)2647--- PASS: TestSignErrors (0.00s)2648 --- PASS: TestSignErrors/invalid_json (0.00s)2649 --- PASS: TestSignErrors/http_error (0.00s)2650 --- PASS: TestSignErrors/invalid_base64 (0.00s)2651 --- PASS: TestSignErrors/no_prefix (0.00s)2652PASS