niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #477
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.83s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestRegisterUploadedObject_OutlivesPush56=== PAUSE TestRegisterUploadedObject_OutlivesPush57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestScriptTokenScriptFails115=== CONT TestScriptTokenEmptyCommand116--- PASS: TestScriptTokenEmptyCommand (0.00s)117=== CONT TestDoWithRetry_FinalResponseBodyReadable118=== CONT TestStreamPushStopsWhenCanceled119--- PASS: TestStreamPushStopsWhenCanceled (0.00s)120=== CONT TestSetClientTLSDoesNotMutateDefaultTransport121--- PASS: TestScriptTokenScriptFails (0.00s)122=== CONT TestRetryTimeoutOutlastsMaxRetries123=== CONT TestScriptTokenBadJSON124=== CONT TestDoWithRetry_BodyReplayedViaGetBody125=== CONT TestScriptTokenEmptyToken126=== CONT TestClientSignaturesByStorePath127--- PASS: TestClientSignaturesByStorePath (0.00s)128=== CONT TestSetClientTLS129=== CONT TestStreamPushReportsSkippedPaths130=== CONT TestStreamPushReportsSignatures131=== CONT TestStreamPushRequestLine132=== CONT TestScriptTokenCachesUntilRefresh1332026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:334591342026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=server-test rate=5135=== CONT TestStreamPushGivesUpOnDeadServer1362026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40449137=== CONT TestScriptTokenNoExpiryRerunsEveryCall1382026/11/10 08:17:14 ERROR Upload failed error="connection refused" count=20139=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun1402026/11/10 08:17:14 ERROR Server seems unavailable, giving up on batch untried=17141=== CONT TestStreamPushIsolatesFailures142=== CONT TestFileTokenEmpty143=== CONT TestStreamPushBatchesUnderLoad144=== CONT TestFileTokenMissing145=== CONT TestStreamPushReportsEveryPath1462026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=server-test rate=5147=== CONT TestFileTokenReadsAndCaches148=== CONT TestShellSplitErrors1492026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:42851150=== CONT TestStaticToken151=== CONT TestShellSplit1522026/11/10 08:17:14 ERROR Upload failed error=boom count=1153=== CONT TestSetClientTLSErrors154=== CONT TestUploadMultipart_PartsInParallel155--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (1.26s)156=== CONT TestDumpPathWriterError157--- PASS: TestStreamPushReportsSkippedPaths (0.00s)158--- PASS: TestScriptTokenBadJSON (2.01s)1592026/11/10 08:17:14 ERROR Upload failed error=boom count=11602026/11/10 08:17:14 WARN Rate limiter backed off name=server-test rate=5161=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false162--- PASS: TestStreamPushGivesUpOnDeadServer (0.02s)163=== CONT TestFilterOversizedClosures164--- PASS: TestShellSplitErrors (0.00s)165=== RUN TestFilterOversizedClosures/no_limit_keeps_everything166--- PASS: TestStreamPushReportsSignatures (0.02s)167--- PASS: TestDoWithRetry_FinalResponseBodyReadable (2.04s)168=== CONT TestCaseHackSuffix1692026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:33459170--- PASS: TestDoServerRequestAttachesToken (2.04s)171=== CONT TestPartSizeForNAR172--- PASS: TestScriptTokenEmptyToken (2.03s)173=== CONT TestUploadMultipart_ReturnsAfterDroppedBody174=== RUN TestPartSizeForNAR/zero_stays_at_minimum175=== CONT TestDumpPathSingleFile176=== CONT TestDumpPathMatchesNix1772026/11/10 08:17:14 ERROR Upload failed error="bad path" count=3178--- PASS: TestStreamPushIsolatesFailures (0.03s)179=== CONT TestPathInfoCACompatibility180=== RUN TestPathInfoCACompatibility/null_ca_field181=== PAUSE TestPathInfoCACompatibility/null_ca_field182=== RUN TestPathInfoCACompatibility/old_string_format_-_text1832026/11/10 08:17:14 WARN Rate limiter backed off name=server-test rate=5184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1852026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:42851186=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive187=== CONT TestRegisterUploadedObject_OutlivesPush188=== CONT TestResolveStorePath189--- PASS: TestStaticToken (0.00s)190=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1912026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:33459192=== RUN TestPathInfoCACompatibility/new_structured_format_-_text193=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false194=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer195=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything196=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess197=== CONT TestRegisterUploadedObjectReusesConnections198=== RUN TestSetClientTLSErrors/missing_cert_file199=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum200=== RUN TestPartSizeForNAR/small_stays_at_minimum201=== PAUSE TestPartSizeForNAR/small_stays_at_minimum202=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica203=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped204=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2052026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=server-test rate=5206=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry207=== CONT TestPathInfoHashCompatibility208=== CONT TestRateLimiterFeedback209--- PASS: TestShellSplit (0.00s)210=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text211=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true212=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum213=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum214=== CONT TestParsePathInfoJSONMultiplePaths215=== RUN TestRateLimiterFeedback/429_enables_limiter216=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths217=== CONT TestParsePathInfoJSON218=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true219=== PAUSE TestSetClientTLSErrors/missing_cert_file220=== RUN TestSetClientTLSErrors/missing_key_file221=== RUN TestFilterOversizedClosures/all_closures_skipped222=== PAUSE TestFilterOversizedClosures/all_closures_skipped223=== PAUSE TestRateLimiterFeedback/429_enables_limiter224=== RUN TestRateLimiterFeedback/503_enables_limiter225=== PAUSE TestRateLimiterFeedback/503_enables_limiter226=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter227=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter228=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter229=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter230=== CONT TestEncodeNixBase32WithRealHash231=== CONT TestEncodeNixBase32232=== RUN TestEncodeNixBase32/test_string_hash233=== PAUSE TestEncodeNixBase32/test_string_hash234=== RUN TestEncodeNixBase32/empty_input235=== PAUSE TestEncodeNixBase32/empty_input236=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts237=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts238=== RUN TestPartSizeForNAR/1_TiB239=== PAUSE TestPartSizeForNAR/1_TiB240=== RUN TestPartSizeForNAR/5_TiB_S3_max_object241=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object242=== RUN TestPartSizeForNAR/capped_at_5_GiB243=== PAUSE TestPartSizeForNAR/capped_at_5_GiB244=== CONT TestGetStorePathHash245=== RUN TestGetStorePathHash/valid_store_path246=== PAUSE TestGetStorePathHash/valid_store_path247=== RUN TestGetStorePathHash/basename_without_hyphen_should_error248=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error249=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error250=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2512026/11/10 08:17:14 INFO Garbage collection started252=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error253=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error254=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false255=== RUN TestParsePathInfoJSON/Nix_format256=== PAUSE TestParsePathInfoJSON/Nix_format257=== RUN TestParsePathInfoJSON/Lix_format258=== PAUSE TestParsePathInfoJSON/Lix_format259=== RUN TestParsePathInfoJSON/empty_input260=== PAUSE TestParsePathInfoJSON/empty_input261=== RUN TestParsePathInfoJSON/whitespace_only262=== PAUSE TestParsePathInfoJSON/whitespace_only263=== RUN TestParsePathInfoJSON/invalid_JSON264=== PAUSE TestParsePathInfoJSON/invalid_JSON265=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true266=== CONT TestFilterOversizedClosures/no_limit_keeps_everything267=== CONT TestEncodeNixBase32/test_string_hash268=== CONT TestRateLimiterFeedback/429_enables_limiter269=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)270=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)271=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon272=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon273=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI274=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI275=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512276=== CONT TestFilterOversizedClosures/all_closures_skipped2772026/11/10 08:17: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=50278=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2792026/11/10 08:17: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=2000280=== CONT TestPartSizeForNAR/zero_stays_at_minimum281=== CONT TestGetStorePathHash/valid_store_path282=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter284=== RUN TestSetClientTLS/rejects_connection_without_client_cert285=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths286--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (2.04s)287=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method288=== PAUSE TestSetClientTLSErrors/missing_key_file289=== CONT TestConvertHashToNix32290=== RUN TestConvertHashToNix32/SRI_format_to_Nix32291=== CONT TestRateLimiterFeedback/503_enables_limiter292=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32293=== RUN TestConvertHashToNix32/already_Nix32_format294=== PAUSE TestConvertHashToNix32/already_Nix32_format295=== RUN TestConvertHashToNix32/invalid_format2962026/11/10 08:17:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:36195/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:36195/api/uploads/complete297=== PAUSE TestConvertHashToNix32/invalid_format2982026/11/10 08:17:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"299--- PASS: TestFileTokenEmpty (0.00s)3002026/11/10 08:17:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:36195/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:36195/api/uploads/complete301--- PASS: TestFileTokenMissing (0.00s)3022026/11/10 08:17:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"303--- PASS: TestStreamPushReportsEveryPath (0.00s)304--- PASS: TestFileTokenReadsAndCaches (0.03s)305--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)306--- PASS: TestRegisterUploadedObject_OutlivesPush (0.03s)307--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)308--- PASS: TestResolveStorePath (0.00s)309--- PASS: TestEncodeNixBase32WithRealHash (0.00s)310=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method311=== RUN TestSetClientTLSErrors/missing_ca_file312=== PAUSE TestSetClientTLSErrors/missing_ca_file313=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512314=== CONT TestEncodeNixBase32/empty_input315=== CONT TestPartSizeForNAR/1_TiB316=== CONT TestParsePathInfoJSON/Nix_format317=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths318=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths319=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert320=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA321=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA322=== RUN TestSetClientTLS/preserves_debug_logging_transport323=== PAUSE TestSetClientTLS/preserves_debug_logging_transport324--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.06s)325--- PASS: TestFilterOversizedClosures (0.04s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)327 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)328 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)329=== CONT TestPartSizeForNAR/capped_at_5_GiB330=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error331=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error332=== CONT TestGetStorePathHash/basename_without_hyphen_should_error333=== CONT TestParsePathInfoJSON/invalid_JSON334=== CONT TestParsePathInfoJSON/whitespace_only335=== CONT TestParsePathInfoJSON/empty_input336=== CONT TestParsePathInfoJSON/Lix_format337=== CONT TestConvertHashToNix32/SRI_format_to_Nix323382026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=server-test rate=5339=== RUN TestSetClientTLSErrors/invalid_ca_file340=== PAUSE TestSetClientTLSErrors/invalid_ca_file341=== CONT TestPartSizeForNAR/5_TiB_S3_max_object342=== CONT TestConvertHashToNix32/invalid_format343=== CONT TestConvertHashToNix32/already_Nix32_format344=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3452026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:406693462026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=server-test rate=5347=== CONT TestSetClientTLS/rejects_connection_without_client_cert3482026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40575349=== CONT TestPartSizeForNAR/small_stays_at_minimum3502026/11/10 08:17:14 WARN Rate limiter backed off name=server-test rate=5351=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive352=== CONT TestPathInfoCACompatibility/old_string_format_-_text353=== CONT TestSetClientTLSErrors/missing_cert_file354=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512355=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI356=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon357=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts358=== CONT TestSetClientTLSErrors/missing_ca_file3592026/11/10 08:17:14 WARN Rate limiter backed off name=server-test rate=53602026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:33459361=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths362=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA363=== CONT TestSetClientTLS/preserves_debug_logging_transport3642026/11/10 08:17:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:36195/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:36195/api/uploads/complete3652026/11/10 08:17:14 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"3662026/11/10 08:17:14 INFO Garbage collection started367=== CONT TestPathInfoCACompatibility/new_structured_format_-_text368=== CONT TestSetClientTLSErrors/missing_key_file369=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)370=== CONT TestPathInfoCACompatibility/null_ca_field371--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.29s)372--- PASS: TestGetStorePathHash (0.00s)373 --- PASS: TestGetStorePathHash/valid_store_path (0.25s)374 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)376 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)377=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method378=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum379--- PASS: TestEncodeNixBase32 (0.00s)380 --- PASS: TestEncodeNixBase32/test_string_hash (0.25s)381 --- PASS: TestEncodeNixBase32/empty_input (0.00s)382--- PASS: TestStreamPushBatchesUnderLoad (0.06s)383 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.25s)384 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.25s)385--- PASS: TestConvertHashToNix32 (0.00s)386 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)387 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)388 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)389--- PASS: TestParsePathInfoJSON (0.00s)390 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)391 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)392 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)393 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)394 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)395=== CONT TestSetClientTLSErrors/invalid_ca_file396--- PASS: TestParsePathInfoJSONMultiplePaths (0.25s)397 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)398 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)399--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.26s)400--- PASS: TestRateLimiterFeedback (0.00s)401 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)402 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.25s)403 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)404 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)405--- PASS: TestPathInfoHashCompatibility (0.25s)406 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)407 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)408 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)409 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)410--- PASS: TestPathInfoCACompatibility (0.29s)411 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)412 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)413 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)414 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)415 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)4162026/11/10 08:17: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=0417--- PASS: TestSetClientTLSErrors (0.30s)418 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)419 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)420 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)421 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)422--- PASS: TestPartSizeForNAR (0.04s)423 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)424 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)425 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)426 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)427 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)428 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)429 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)4302026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:334594312026/11/10 08:17:14 WARN Garbage collection finished on another replica. Its statistics are not available here432--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.27s)4332026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:334594342026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:334594352026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:334594362026/11/10 08:17:14 WARN Rate limiter enabled after throttle name=s3-test rate=54372026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:466074382026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:33459439--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.28s)440--- PASS: TestStreamPushRequestLine (0.34s)4412026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:334594422026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:334594432026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:334594442026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:334594452026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:334594462026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:334594472026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:334594482026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:33459449--- PASS: TestRegisterUploadedObjectReusesConnections (0.29s)4502026/11/10 08:17:14 http: TLS handshake error from 127.0.0.1:34892: remote error: tls: bad certificate4512026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:33459452--- PASS: TestCaseHackSuffix (0.32s)453--- PASS: TestSetClientTLS (1.08s)454 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)455 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)456 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4572026/11/10 08:17:14 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:33459458--- PASS: TestDumpPathWriterError (0.33s)459--- PASS: TestRetryTimeoutOutlastsMaxRetries (2.37s)460--- PASS: TestDumpPathSingleFile (0.75s)461--- PASS: TestDumpPathMatchesNix (0.78s)462--- PASS: TestUploadMultipart_PartsInParallel (0.93s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.05s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "nixbld".467This user must also own the server process.468469The database cluster will be initialized with locale "C".470The default database encoding has accordingly been set to "SQL_ASCII".471The default text search configuration will be set to "english".472473Data page checksums are enabled.474475creating directory /build/postgres4260759308/data ... ok476creating subdirectories ... ok477selecting dynamic shared memory implementation ... posix478selecting default "max_connections" ... 100479selecting default "shared_buffers" ... 128MB480selecting default time zone ... UTC481creating configuration files ... ok482running bootstrap script ... ok483performing post-bootstrap initialization ... ok484syncing data to disk ... ok485486initdb: warning: enabling "trust" authentication for local connections487initdb: 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.488489Success. You can now start the database server using:490491 pg_ctl -D /build/postgres4260759308/data -l logfile start492493/build/postgres4260759308:5432 - no response494/build/postgres4260759308:5432 - no response495/build/postgres4260759308:5432 - no response496/build/postgres4260759308:5432 - no response497/build/postgres4260759308:5432 - no response498/build/postgres4260759308:5432 - no response499/build/postgres4260759308:5432 - no response5002026-11-10 08:17:19.912 UTC [133] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5012026-11-10 08:17:19.912 UTC [133] LOG: listening on Unix socket "/build/postgres4260759308/.s.PGSQL.5432"5022026-11-10 08:17:19.920 UTC [146] LOG: database system was shut down at 2026-11-10 08:17:18 UTC5032026-11-10 08:17:19.927 UTC [133] LOG: database system is ready to accept connections504/build/postgres4260759308:5432 - accepting connections505{"timestamp":"2026-11-10T08:17:25.786026246Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e3ccd658-3a06-4ed9-94b4-6a683a22301c","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":6,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(197)"}506{"timestamp":"2026-11-10T08:17:25.894865588Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8d257ef7-12b1-4899-b0be-c0962acea83d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}507=== RUN TestAbortSucceeded508=== PAUSE TestAbortSucceeded509=== RUN TestService_AuthMiddleware510=== PAUSE TestService_AuthMiddleware511=== RUN TestService_AuthMiddleware_MTLSProxyHeader512=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader513=== RUN TestService_AuthMiddleware_MTLSBoundSubjects514=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects515=== RUN TestService_ReadAuthMiddleware516=== PAUSE TestService_ReadAuthMiddleware517=== RUN TestService_AuthMiddleware_OIDC518=== PAUSE TestService_AuthMiddleware_OIDC519=== RUN TestService_RequireScope_OIDC520=== PAUSE TestService_RequireScope_OIDC521=== RUN TestService_ReadScope_PublicByDefault522=== PAUSE TestService_ReadScope_PublicByDefault523=== RUN TestCacheConfigHandler524=== PAUSE TestCacheConfigHandler525=== RUN TestCacheStatsHandler526=== PAUSE TestCacheStatsHandler527=== RUN TestClientCADerivations528=== PAUSE TestClientCADerivations529=== RUN TestClientErrorHandling530=== PAUSE TestClientErrorHandling531=== RUN TestClientIntegration532=== PAUSE TestClientIntegration533=== RUN TestClientMultipleUploads534=== PAUSE TestClientMultipleUploads535=== RUN TestClientWithDependencies536=== PAUSE TestClientWithDependencies537=== RUN TestClientSharedPathCommittedMidPush538=== PAUSE TestClientSharedPathCommittedMidPush539=== RUN TestPinProtectsFromGC540=== PAUSE TestPinProtectsFromGC541=== RUN TestClientPushesUseOnePush542=== PAUSE TestClientPushesUseOnePush543=== RUN TestClientFallsBackToClosures544=== PAUSE TestClientFallsBackToClosures545=== RUN TestDeleteClosuresRacingPins546=== PAUSE TestDeleteClosuresRacingPins547=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock548=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock549=== RUN TestResolveDBConnectionString550=== PAUSE TestResolveDBConnectionString551=== RUN TestConnectWaitsForAPeerMigration552=== PAUSE TestConnectWaitsForAPeerMigration553=== RUN TestLeadElectsOneAndHandsOver554=== PAUSE TestLeadElectsOneAndHandsOver555=== RUN TestLeadIncumbentWinsAfterRestart5562026/11/10 08:17:26 INFO lead: acquired remote=192.0.2.1:12345572026/11/10 08:17:26 INFO lead: released remote=192.0.2.1:12345582026/11/10 08:17:27 INFO lead: acquired remote=192.0.2.1:12345592026/11/10 08:17:28 INFO lead: released remote=192.0.2.1:1234560--- PASS: TestLeadIncumbentWinsAfterRestart (2.13s)561=== RUN TestLeadIncumbentAnnouncesAtOnce562=== PAUSE TestLeadIncumbentAnnouncesAtOnce563=== RUN TestLeadEndsOnShutdown564=== PAUSE TestLeadEndsOnShutdown565=== RUN TestLeadEndsWhenItsConnectionHangs5662026/11/10 08:17:28 INFO lead: acquired remote=192.0.2.1:12345672026-11-10 08:17:29.876 UTC [394] FATAL: terminating connection due to administrator command5682026/11/10 08:17:30 INFO lead: acquired remote=192.0.2.1:12345692026/11/10 08:17:31 WARN lead: lock connection lost error="timeout: context deadline exceeded"5702026/11/10 08:17:31 INFO lead: released remote=192.0.2.1:12345712026/11/10 08:17:31 INFO lead: released remote=192.0.2.1:1234572--- PASS: TestLeadEndsWhenItsConnectionHangs (3.32s)573=== RUN TestGCAdvisoryLockBlocksConcurrentRun574=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun575=== RUN TestGCBugBareHashReferences576=== PAUSE TestGCBugBareHashReferences577=== RUN TestGCMetrics578=== PAUSE TestGCMetrics579=== RUN TestPushDedupSurvivesConcurrentGC580=== PAUSE TestPushDedupSurvivesConcurrentGC581=== RUN TestDeduplicatedObjectsRecordedAsPending582=== PAUSE TestDeduplicatedObjectsRecordedAsPending583=== RUN TestGCSweepSkipsPendingObjects584=== PAUSE TestGCSweepSkipsPendingObjects585=== RUN TestTombstonedObjectOfferedWithoutWaiting586=== PAUSE TestTombstonedObjectOfferedWithoutWaiting587=== RUN TestGCSweepDeliversEachKeyOnce588=== PAUSE TestGCSweepDeliversEachKeyOnce589=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection590=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection591=== RUN TestForceGCDuringPushOffersSweptObject592=== PAUSE TestForceGCDuringPushOffersSweptObject593=== RUN TestFailedS3DeleteKeepsTombstone594=== PAUSE TestFailedS3DeleteKeepsTombstone595=== RUN TestSweepSkipsRowsLockedByPush596=== PAUSE TestSweepSkipsRowsLockedByPush597=== RUN TestRegisterCompletedObjectNeedsPendingRow598=== PAUSE TestRegisterCompletedObjectNeedsPendingRow599=== RUN TestGetExistingObjectsLocksRows600=== PAUSE TestGetExistingObjectsLocksRows601=== RUN TestSweepRechecksPendingAfterLocking602=== PAUSE TestSweepRechecksPendingAfterLocking603=== RUN TestPushWaitsForSweepHoldingRow604=== PAUSE TestPushWaitsForSweepHoldingRow605=== RUN TestCommitRacingPendingCleanupKeepsObjects606=== PAUSE TestCommitRacingPendingCleanupKeepsObjects607=== RUN TestGCEndsOnShutdown608=== PAUSE TestGCEndsOnShutdown609=== RUN TestGCTaskStore_StartNew610=== PAUSE TestGCTaskStore_StartNew611=== RUN TestGCTaskStore_DeduplicateSameParams612=== PAUSE TestGCTaskStore_DeduplicateSameParams613=== RUN TestGCTaskStore_ConflictDifferentParams614=== PAUSE TestGCTaskStore_ConflictDifferentParams615=== RUN TestGCTaskStore_GetEmpty616=== PAUSE TestGCTaskStore_GetEmpty617=== RUN TestGCTaskStore_GetReturnsLatest618=== PAUSE TestGCTaskStore_GetReturnsLatest619=== RUN TestGCTaskStore_CompletedAllowsNewTask620=== PAUSE TestGCTaskStore_CompletedAllowsNewTask621=== RUN TestGCTaskStore_PhaseUpdates622=== PAUSE TestGCTaskStore_PhaseUpdates623=== RUN TestGCTaskStore_Fail624=== PAUSE TestGCTaskStore_Fail625=== RUN TestGracefulShutdownDrainsInflight626=== PAUSE TestGracefulShutdownDrainsInflight627=== RUN TestService_healthCheckHandler628=== PAUSE TestService_healthCheckHandler629=== RUN TestService_readinessHandler630=== PAUSE TestService_readinessHandler631=== RUN TestGenerateLandingPage632=== PAUSE TestGenerateLandingPage633=== RUN TestEnsureAbortUploadsRule634=== PAUSE TestEnsureAbortUploadsRule635=== RUN TestCacheConfigHandlerMaxNarSize636=== PAUSE TestCacheConfigHandlerMaxNarSize637=== RUN TestCreatePendingClosureRejectsOversizedNAR638=== PAUSE TestCreatePendingClosureRejectsOversizedNAR639=== RUN TestNARDeduplicationMetadataUploadBug640=== PAUSE TestNARDeduplicationMetadataUploadBug641=== RUN TestMetricsInventory642=== PAUSE TestMetricsInventory643=== RUN TestMetricsCommit644=== PAUSE TestMetricsCommit645=== RUN TestService_NativeMTLS646=== PAUSE TestService_NativeMTLS647=== RUN TestServerTLSConfig648=== PAUSE TestServerTLSConfig649=== RUN TestMultipartCleanup650=== PAUSE TestMultipartCleanup651=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded652=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded653=== RUN TestPendingCleanupUsesOneCutoff654=== PAUSE TestPendingCleanupUsesOneCutoff655=== RUN TestObjectStatsTrigger656=== PAUSE TestObjectStatsTrigger657=== RUN TestObjectStatsUpdatedOncePerCommit658=== PAUSE TestObjectStatsUpdatedOncePerCommit659=== RUN TestOrphanedObjectsGC660=== PAUSE TestOrphanedObjectsGC661=== RUN TestOrphanedObjectsGCStressTest662=== PAUSE TestOrphanedObjectsGCStressTest663=== RUN TestCreatePin_ReservedPins664=== PAUSE TestCreatePin_ReservedPins665=== RUN TestPresentReportsOnlyClosureRoots666=== PAUSE TestPresentReportsOnlyClosureRoots667=== RUN TestPresentRefreshesOnlyStaleClosures668=== PAUSE TestPresentRefreshesOnlyStaleClosures669=== RUN TestPresentNotReportedWhileGCDeletesClosure670=== PAUSE TestPresentNotReportedWhileGCDeletesClosure671=== RUN TestParseSingleRange672=== PAUSE TestParseSingleRange673=== RUN TestProxyHeadersOnlyTrustedOnSocket6742026/11/10 08:17:31 INFO Starting HTTP server address=proxy.sock6752026/11/10 08:17:31 INFO Starting HTTP server address=127.0.0.1:425996762026/11/10 08:17:31 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6772026/11/10 08:17:31 INFO Shutdown signal received, draining in-flight requests timeout=10s678--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.39s)679=== RUN TestIsValidCachePath680=== PAUSE TestIsValidCachePath681=== RUN TestReadProxyNarinfo682=== PAUSE TestReadProxyNarinfo683=== RUN TestReadProxyNarinfoAlreadyDecompressed684=== PAUSE TestReadProxyNarinfoAlreadyDecompressed685=== RUN TestReadProxyContentNegotiation686=== PAUSE TestReadProxyContentNegotiation687=== RUN TestReadProxyNarStreaming688=== PAUSE TestReadProxyNarStreaming689=== RUN TestReadProxy404690=== PAUSE TestReadProxy404691=== RUN TestReadProxyInvalidPath692=== PAUSE TestReadProxyInvalidPath693=== RUN TestReadProxyHead694=== PAUSE TestReadProxyHead695=== RUN TestReadProxyOutlastsServerWriteTimeout696=== PAUSE TestReadProxyOutlastsServerWriteTimeout697=== RUN TestReadProxyConditionalGet698=== PAUSE TestReadProxyConditionalGet699=== RUN TestReadProxyRootRedirectsToIndexHTML700=== PAUSE TestReadProxyRootRedirectsToIndexHTML701=== RUN TestReadProxyDisabled702=== PAUSE TestReadProxyDisabled703=== RUN TestReadRedirectNar704=== PAUSE TestReadRedirectNar705=== RUN TestReadRedirectKeepsNarinfoProxied706=== PAUSE TestReadRedirectKeepsNarinfoProxied707=== RUN TestReadProxyRangeRequest708=== PAUSE TestReadProxyRangeRequest709=== RUN TestReadRedirectUsesPublicS3URL710=== PAUSE TestReadRedirectUsesPublicS3URL711=== RUN TestPush_OverlappingRootsStoreOneRowPerKey712=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey713=== RUN TestPush_CompleteCommitsEveryRoot714=== PAUSE TestPush_CompleteCommitsEveryRoot715=== RUN TestPush_RepeatedRootCommitsOnce716=== PAUSE TestPush_RepeatedRootCommitsOnce717=== RUN TestPush_CompleteWaitsForCleanupOfThePush718=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush719=== RUN TestPush_RootsAreLockedInByteOrder720=== PAUSE TestPush_RootsAreLockedInByteOrder721=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit722=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit723=== RUN TestPush_RejectsBadRequests724=== PAUSE TestPush_RejectsBadRequests725=== RUN TestPush_SignsNarinfosOfItsPendingObjects726=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects727=== RUN TestSharedNarBothUploadsComplete728=== PAUSE TestSharedNarBothUploadsComplete729=== RUN TestCompleteMultipartUpload_ErrorButObjectExists730=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists731=== RUN TestCompletedNarNotReofferedAcrossClosures732=== PAUSE TestCompletedNarNotReofferedAcrossClosures733=== RUN TestPresignedUploadRegisteredBeforeCommit734=== PAUSE TestPresignedUploadRegisteredBeforeCommit735=== RUN TestService_Rustfstest736=== PAUSE TestService_Rustfstest737=== RUN TestParseSize738=== PAUSE TestParseSize739=== RUN TestSkippedUploadsHandler740=== PAUSE TestSkippedUploadsHandler741=== RUN TestSystemdListenerNotActivated742--- PASS: TestSystemdListenerNotActivated (0.00s)743=== RUN TestWatchdogBeatsWhenHealthy744--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)745=== RUN TestWatchdogSkipsWhenUnhealthy7462026/11/10 08:17:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/10 08:17:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/10 08:17:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/10 08:17:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7552026/11/10 08:17:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"756--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)757=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle758=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle759=== RUN TestProxyWriteTimeout760=== PAUSE TestProxyWriteTimeout761=== RUN TestPendingClosureWriteTimeout762=== PAUSE TestPendingClosureWriteTimeout763=== RUN TestIsValidUploadKey764=== PAUSE TestIsValidUploadKey765=== RUN TestUploadHandlersRejectInvalidKeys766=== PAUSE TestUploadHandlersRejectInvalidKeys767=== RUN TestUploadHandlersRejectOversizedBody768=== PAUSE TestUploadHandlersRejectOversizedBody769=== RUN TestService_cleanupPendingClosuresHandler770=== PAUSE TestService_cleanupPendingClosuresHandler771=== RUN TestService_createPendingClosureHandler772=== PAUSE TestService_createPendingClosureHandler773=== RUN TestService_verifyS3Integrity774=== PAUSE TestService_verifyS3Integrity775=== RUN TestService_verifyS3ReuploadsStaleNarinfo776=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo777=== RUN TestCompleteMultipartUnregistered778=== PAUSE TestCompleteMultipartUnregistered779=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT780=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT781=== CONT TestPendingClosureWriteTimeout782=== CONT TestService_Rustfstest783=== CONT TestService_createPendingClosureHandler784=== CONT TestAbortSucceeded785=== CONT TestGracefulShutdownDrainsInflight786=== CONT TestProxyWriteTimeout787=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle788=== CONT TestSkippedUploadsHandler789=== CONT TestParseSize790--- PASS: TestParseSize (0.00s)791=== CONT TestReadRedirectNar792=== CONT TestReadProxyDisabled793=== CONT TestPresignedUploadRegisteredBeforeCommit794=== CONT TestCompletedNarNotReofferedAcrossClosures795=== CONT TestCompleteMultipartUpload_ErrorButObjectExists796--- PASS: TestAbortSucceeded (0.00s)7972026/11/10 08:17:32 INFO Starting HTTP server address=127.0.0.1:331517982026/11/10 08:17:32 INFO Shutdown signal received, draining in-flight requests timeout=10s799=== CONT TestSharedNarBothUploadsComplete800=== CONT TestPush_SignsNarinfosOfItsPendingObjects801=== CONT TestPush_RejectsBadRequests8022026/11/10 08:17:32 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000803=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit804=== CONT TestPush_RootsAreLockedInByteOrder805=== CONT TestPush_CompleteWaitsForCleanupOfThePush806=== CONT TestPush_RepeatedRootCommitsOnce807=== CONT TestPush_CompleteCommitsEveryRoot808=== CONT TestPush_OverlappingRootsStoreOneRowPerKey809=== CONT TestReadRedirectUsesPublicS3URL810=== CONT TestReadProxyRangeRequest811=== CONT TestReadRedirectKeepsNarinfoProxied812=== RUN TestPendingClosureWriteTimeout/empty813=== RUN TestProxyWriteTimeout/narinfo814--- PASS: TestSkippedUploadsHandler (2.03s)815=== CONT TestReadProxyRootRedirectsToIndexHTML816=== PAUSE TestPendingClosureWriteTimeout/empty817=== RUN TestPendingClosureWriteTimeout/400_objects818=== PAUSE TestPendingClosureWriteTimeout/400_objects819=== RUN TestPendingClosureWriteTimeout/670k_objects820=== PAUSE TestPendingClosureWriteTimeout/670k_objects821=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline822=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline823=== CONT TestReadProxyConditionalGet824=== PAUSE TestProxyWriteTimeout/narinfo825=== RUN TestProxyWriteTimeout/1_GiB_nar826=== PAUSE TestProxyWriteTimeout/1_GiB_nar827=== RUN TestProxyWriteTimeout/10_GiB_nar828=== PAUSE TestProxyWriteTimeout/10_GiB_nar829=== RUN TestProxyWriteTimeout/unknown_size830=== PAUSE TestProxyWriteTimeout/unknown_size831=== CONT TestGCAdvisoryLockBlocksConcurrentRun832--- PASS: TestGracefulShutdownDrainsInflight (2.21s)833=== CONT TestGCTaskStore_Fail834--- PASS: TestGCTaskStore_Fail (0.00s)835=== CONT TestGCTaskStore_PhaseUpdates836--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)837=== CONT TestGCTaskStore_CompletedAllowsNewTask838--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)839=== CONT TestGCTaskStore_GetReturnsLatest840--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)841=== CONT TestGCTaskStore_GetEmpty842--- PASS: TestGCTaskStore_GetEmpty (0.00s)843=== CONT TestReadProxyOutlastsServerWriteTimeout8442026/11/10 08:17:34 INFO Received push request method=POST path=/api/pushes8452026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures846--- PASS: TestReadRedirectNar (2.40s)847=== CONT TestGCTaskStore_ConflictDifferentParams848--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)849=== CONT TestReadProxyHead8502026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8512026/11/10 08:17:34 INFO Signed narinfos id=1 count=18522026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8532026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8542026/11/10 08:17:34 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8552026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8562026/11/10 08:17:34 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8572026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8582026/11/10 08:17:34 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18592026/11/10 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8602026/11/10 08:17:34 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo861--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.41s)862=== CONT TestGCTaskStore_DeduplicateSameParams863--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)864=== CONT TestReadProxyInvalidPath865--- PASS: TestService_Rustfstest (2.42s)866=== CONT TestGCTaskStore_StartNew867--- PASS: TestGCTaskStore_StartNew (0.00s)868=== CONT TestReadProxy404869=== RUN TestPush_RejectsBadRequests/no_roots870=== PAUSE TestPush_RejectsBadRequests/no_roots871=== RUN TestPush_RejectsBadRequests/no_objects872=== PAUSE TestPush_RejectsBadRequests/no_objects873=== RUN TestPush_RejectsBadRequests/bad_root874=== PAUSE TestPush_RejectsBadRequests/bad_root875=== RUN TestPush_RejectsBadRequests/root_not_in_objects876=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects877=== CONT TestGCEndsOnShutdown878=== RUN TestGCEndsOnShutdown/before_the_run879=== PAUSE TestGCEndsOnShutdown/before_the_run880=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete881=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete882=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark883=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark884=== CONT TestCommitRacingPendingCleanupKeepsObjects8852026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8862026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8872026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8882026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8892026/11/10 08:17:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8902026/11/10 08:17:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8912026/11/10 08:17:34 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLmY2OTljNmI3LWMzYjEtNDk3Yy05N2ZlLTkzMzc0YjgzODIyM3gxNzk0Mjk4NjU0NTk5MjM1ODE1892--- PASS: TestReadProxyDisabled (2.55s)893=== CONT TestReadProxyNarStreaming8942026/11/10 08:17:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLmY2OTljNmI3LWMzYjEtNDk3Yy05N2ZlLTkzMzc0YjgzODIyM3gxNzk0Mjk4NjU0NTk5MjM1ODE1 parts=1895--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.56s)896=== CONT TestPushWaitsForSweepHoldingRow8972026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8982026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures8992026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures9002026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures9012026/11/10 08:17:34 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9022026/11/10 08:17:34 INFO Received uploads request method=POST path=/api/pending_closures903--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.67s)904=== CONT TestReadProxyContentNegotiation9052026/11/10 08:17:34 INFO Received push request method=POST path=/api/pushes9062026/11/10 08:17:34 INFO Received push request method=POST path=/api/pushes907--- PASS: TestReadProxyRangeRequest (0.73s)908=== CONT TestGCSweepDeliversEachKeyOnce909--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.76s)910=== CONT TestReadProxyNarinfoAlreadyDecompressed911--- PASS: TestReadProxyConditionalGet (0.77s)912=== CONT TestTombstonedObjectOfferedWithoutWaiting9132026/11/10 08:17:34 INFO Received push request method=POST path=/api/pushes9142026/11/10 08:17:34 INFO Received complete push request method=POST path=/api/pushes/1/complete915--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.87s)916=== CONT TestReadProxyNarinfo9172026/11/10 08:17:35 INFO Received push request method=POST path=/api/pushes9182026/11/10 08:17:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9192026/11/10 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete9202026/11/10 08:17:35 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjAwZjAwZGU1LTQyYTctNDE2ZC05ZjExLTE5YTYyYTU3NzVlZXgxNzk0Mjk4NjU0NjI3MTA0Mjcy parts=109212026/11/10 08:17:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9222026/11/10 08:17:35 INFO Completed upload id=1 objects=2 duration=10.222634ms9232026/11/10 08:17:35 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009242026/11/10 08:17:35 INFO Received uploads request method=POST path=/api/pending_closures9252026/11/10 08:17:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures9262026/11/10 08:17:35 INFO Aborted multipart uploads count=0 kept=09272026/11/10 08:17:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9282026/11/10 08:17:35 INFO Completed push id=1 objects=6 duration=139.396163ms9292026-11-10 08:17:35.201 UTC [514] ERROR: could not obtain lock on row in relation "closures"9302026-11-10 08:17:35.201 UTC [514] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT931--- PASS: TestPush_CompleteCommitsEveryRoot (1.07s)932=== CONT TestGCSweepSkipsPendingObjects9332026-11-10 08:17:35.205 UTC [514] ERROR: could not obtain lock on row in relation "closures"9342026-11-10 08:17:35.205 UTC [514] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9352026-11-10 08:17:35.207 UTC [514] ERROR: could not obtain lock on row in relation "closures"9362026-11-10 08:17:35.207 UTC [514] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9372026-11-10 08:17:35.208 UTC [514] ERROR: could not obtain lock on row in relation "closures"9382026-11-10 08:17:35.208 UTC [514] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9392026-11-10 08:17:35.208 UTC [514] ERROR: could not obtain lock on row in relation "closures"9402026-11-10 08:17:35.208 UTC [514] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9412026/11/10 08:17:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjZhOTk1Y2M4LWYwZTgtNDM0Mi1iMDFiLWU0OTMxY2NhNjQ5YngxNzk0Mjk4NjU0NzAyMjk3NDI0 parts=12942--- PASS: TestPush_RootsAreLockedInByteOrder (1.09s)943=== CONT TestIsValidCachePath944=== RUN TestIsValidCachePath/narinfo945=== PAUSE TestIsValidCachePath/narinfo946=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars947=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars948=== RUN TestIsValidCachePath/nar_zst949=== PAUSE TestIsValidCachePath/nar_zst950=== RUN TestIsValidCachePath/nar_xz951=== PAUSE TestIsValidCachePath/nar_xz952=== RUN TestIsValidCachePath/nar_bz2953=== PAUSE TestIsValidCachePath/nar_bz2954=== RUN TestIsValidCachePath/nar_uncompressed955=== PAUSE TestIsValidCachePath/nar_uncompressed956=== RUN TestIsValidCachePath/ls957=== PAUSE TestIsValidCachePath/ls958=== RUN TestIsValidCachePath/log959=== PAUSE TestIsValidCachePath/log960=== RUN TestIsValidCachePath/realisation961=== PAUSE TestIsValidCachePath/realisation962=== RUN TestIsValidCachePath/nix-cache-info963=== PAUSE TestIsValidCachePath/nix-cache-info964=== RUN TestIsValidCachePath/index.html965=== PAUSE TestIsValidCachePath/index.html966=== RUN TestIsValidCachePath/traversal_parent967=== PAUSE TestIsValidCachePath/traversal_parent968=== RUN TestIsValidCachePath/traversal_in_middle969=== PAUSE TestIsValidCachePath/traversal_in_middle970=== RUN TestIsValidCachePath/invalid_char_e971=== PAUSE TestIsValidCachePath/invalid_char_e972=== RUN TestIsValidCachePath/invalid_char_u973=== PAUSE TestIsValidCachePath/invalid_char_u974=== RUN TestIsValidCachePath/random_path975=== PAUSE TestIsValidCachePath/random_path976=== RUN TestIsValidCachePath/empty977=== PAUSE TestIsValidCachePath/empty978=== RUN TestIsValidCachePath/leading_slash979=== PAUSE TestIsValidCachePath/leading_slash980=== RUN TestIsValidCachePath/wrong_extension981=== PAUSE TestIsValidCachePath/wrong_extension982=== RUN TestIsValidCachePath/short_hash983=== PAUSE TestIsValidCachePath/short_hash984=== CONT TestDeduplicatedObjectsRecordedAsPending9852026/11/10 08:17:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9862026/11/10 08:17:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjBmZWE1ZjZhLTU5ZjEtNDkyZS1iNmQwLTM4NTQxMjZlNDY4YngxNzk0Mjk4NjU0Nzc2ODM5Mzkw parts=129872026/11/10 08:17:35 INFO Received uploads request method=POST path=/api/pending_closures988--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.17s)989=== CONT TestParseSingleRange990=== RUN TestParseSingleRange/none991=== PAUSE TestParseSingleRange/none992=== RUN TestParseSingleRange/unknown_unit993=== PAUSE TestParseSingleRange/unknown_unit994=== RUN TestParseSingleRange/multi-range_ignored995=== PAUSE TestParseSingleRange/multi-range_ignored996=== RUN TestParseSingleRange/malformed_no_dash997=== PAUSE TestParseSingleRange/malformed_no_dash998=== RUN TestParseSingleRange/malformed_both_empty999=== PAUSE TestParseSingleRange/malformed_both_empty1000=== RUN TestParseSingleRange/malformed_end_before_start1001=== PAUSE TestParseSingleRange/malformed_end_before_start1002=== RUN TestParseSingleRange/closed1003=== PAUSE TestParseSingleRange/closed1004=== RUN TestParseSingleRange/open-ended1005=== PAUSE TestParseSingleRange/open-ended1006=== RUN TestParseSingleRange/end_clamped_to_size1007=== PAUSE TestParseSingleRange/end_clamped_to_size1008=== RUN TestParseSingleRange/suffix1009=== PAUSE TestParseSingleRange/suffix1010=== RUN TestParseSingleRange/suffix_exceeds_size1011=== PAUSE TestParseSingleRange/suffix_exceeds_size1012=== RUN TestParseSingleRange/single_byte1013=== PAUSE TestParseSingleRange/single_byte1014=== RUN TestParseSingleRange/start_past_EOF1015=== PAUSE TestParseSingleRange/start_past_EOF1016=== RUN TestParseSingleRange/start_far_past_EOF1017=== PAUSE TestParseSingleRange/start_far_past_EOF1018=== CONT TestPushDedupSurvivesConcurrentGC1019--- PASS: TestReadProxyNarStreaming (0.68s)1020=== CONT TestPresentNotReportedWhileGCDeletesClosure1021=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1022=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1023=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1024=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1025=== CONT TestPresentReportsOnlyClosureRoots1026--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.50s)1027=== CONT TestGCMetrics10282026/11/10 08:17:35 INFO Received uploads request method=POST path=/api/pending_closures1029--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.52s)1030=== CONT TestCreatePin_ReservedPins1031--- PASS: TestReadProxyContentNegotiation (0.69s)1032=== CONT TestPresentRefreshesOnlyStaleClosures10332026/11/10 08:17:35 INFO Received uploads request method=POST path=/api/pending_closures1034--- PASS: TestReadProxyInvalidPath (1.02s)1035=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10362026/11/10 08:17:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37277/oidc1037--- PASS: TestReadProxy404 (1.03s)1038=== CONT TestOrphanedObjectsGCStressTest1039--- PASS: TestReadRedirectKeepsNarinfoProxied (1.50s)1040=== CONT TestSweepRechecksPendingAfterLocking10412026/11/10 08:17:35 INFO Received push request method=POST path=/api/pushes10422026/11/10 08:17:35 INFO Received push request method=POST path=/api/pushes10432026/11/10 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete10442026/11/10 08:17:35 INFO Completed push id=1 objects=4 duration=168.630112ms1045--- PASS: TestPush_RepeatedRootCommitsOnce (1.80s)1046=== CONT TestGetExistingObjectsLocksRows10472026/11/10 08:17:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10482026/11/10 08:17:35 INFO Completed push id=1 objects=4 duration=1.034845844s10492026/11/10 08:17:35 INFO Received push request method=POST path=/api/pushes1050--- PASS: TestPushWaitsForSweepHoldingRow (1.32s)1051=== CONT TestRegisterCompletedObjectNeedsPendingRow10522026/11/10 08:17:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLmJlNjE4YjZkLTg4MzItNDUzMS05ZmFjLTQ5MmRmMThhZjgzNHgxNzk0Mjk4NjU0NzE4MDIyMTg4 parts=121053--- PASS: TestSharedNarBothUploadsComplete (3.91s)1054=== CONT TestSweepSkipsRowsLockedByPush10552026/11/10 08:17:36 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"1056--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.91s)1057=== CONT TestOrphanedObjectsGC10582026-11-10 08:17:36.061 UTC [584] ERROR: Push does not exist: id=110592026-11-10 08:17:36.061 UTC [584] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10602026-11-10 08:17:36.061 UTC [584] STATEMENT: SELECT commit_push($1)1061--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.93s)1062=== CONT TestFailedS3DeleteKeepsTombstone10632026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=010642026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=010652026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period10662026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=010672026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period10682026/11/10 08:17:36 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=010692026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period10702026/11/10 08:17:36 INFO Vacuumed table table=pending_closures10712026/11/10 08:17:36 INFO Vacuumed table table=pending_objects1072--- PASS: TestReadProxyHead (1.61s)1073=== CONT TestObjectStatsUpdatedOncePerCommit10742026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads10752026/11/10 08:17:36 INFO Vacuumed table table=closures10762026/11/10 08:17:36 INFO Vacuumed table table=objects10772026/11/10 08:17:36 INFO Received uploads request method=POST path=/api/pending_closures10782026/11/10 08:17:36 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=010792026/11/10 08:17:36 INFO Vacuumed table table=pending_closures10802026/11/10 08:17:36 INFO Vacuumed table table=pending_objects1081--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.60s)1082=== CONT TestForceGCDuringPushOffersSweptObject1083=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1084=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1085=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1086=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1087=== CONT TestObjectStatsTrigger10882026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads10892026/11/10 08:17:36 INFO Vacuumed table table=closures10902026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=010912026/11/10 08:17:36 INFO Vacuumed table table=objects10922026/11/10 08:17:36 INFO Received complete push request method=POST path=/api/pushes/2/complete10932026/11/10 08:17:36 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=010942026/11/10 08:17:36 INFO Completed push id=2 objects=4 duration=4.913526ms1095--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.04s)1096=== CONT TestGCBugBareHashReferences10972026/11/10 08:17:36 INFO Vacuumed table table=pending_closures10982026/11/10 08:17:36 INFO Vacuumed table table=pending_objects10992026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11002026/11/10 08:17:36 INFO Vacuumed table table=closures11012026/11/10 08:17:36 INFO Vacuumed table table=objects1102--- PASS: TestGCSweepDeliversEachKeyOnce (1.32s)1103=== CONT TestMetricsInventory1104--- PASS: TestReadRedirectUsesPublicS3URL (2.10s)1105=== CONT TestNARDeduplicationMetadataUploadBug11062026/11/10 08:17:36 INFO Received uploads request method=POST path=/api/pending_closures11072026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=011082026/11/10 08:17:36 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=011092026/11/10 08:17:36 INFO Vacuumed table table=pending_closures11102026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11112026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11122026/11/10 08:17:36 INFO Vacuumed table table=closures11132026/11/10 08:17:36 INFO Vacuumed table table=objects11142026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=011152026/11/10 08:17:36 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001116=== CONT TestClientMultipleUploads1117--- PASS: TestService_createPendingClosureHandler (4.27s)1118--- PASS: TestPresentReportsOnlyClosureRoots (1.03s)1119=== CONT TestCacheConfigHandlerMaxNarSize1120--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1121=== CONT TestLeadEndsOnShutdown11222026/11/10 08:17:36 INFO Received uploads request method=POST path=/api/pending_closures1123=== CONT TestPendingCleanupUsesOneCutoff1124--- PASS: TestPresentRefreshesOnlyStaleClosures (1.08s)11252026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period11262026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period11272026/11/10 08:17:36 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=011282026/11/10 08:17:36 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=011292026/11/10 08:17:36 INFO Vacuumed table table=pending_closures11302026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11312026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11322026/11/10 08:17:36 INFO Vacuumed table table=closures11332026/11/10 08:17:36 INFO Vacuumed table table=objects11342026/11/10 08:17:36 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=01135--- PASS: TestGCMetrics (1.19s)1136=== CONT TestEnsureAbortUploadsRule11372026/11/10 08:17:36 INFO Vacuumed table table=pending_closures11382026/11/10 08:17:36 INFO Vacuumed table table=pending_closures11392026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11402026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11412026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11422026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11432026/11/10 08:17:36 INFO Vacuumed table table=closures11442026/11/10 08:17:36 INFO Vacuumed table table=objects11452026/11/10 08:17:36 INFO Vacuumed table table=closures11462026/11/10 08:17:36 INFO Vacuumed table table=objects1147--- PASS: TestGCSweepSkipsPendingObjects (1.41s)1148=== CONT TestLeadIncumbentAnnouncesAtOnce11492026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=011502026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period11512026/11/10 08:17:36 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=01152--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.08s)1153=== CONT TestGenerateLandingPage11542026/11/10 08:17:36 INFO Vacuumed table table=pending_closures1155--- PASS: TestGenerateLandingPage (0.01s)1156=== CONT TestCreatePendingClosureRejectsOversizedNAR11572026/11/10 08:17:36 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1159=== CONT TestLeadElectsOneAndHandsOver11602026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11612026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11622026/11/10 08:17:36 INFO Vacuumed table table=closures11632026/11/10 08:17:36 INFO Vacuumed table table=objects1164--- PASS: TestPushDedupSurvivesConcurrentGC (1.36s)1165=== CONT TestService_readinessHandler11662026/11/10 08:17:36 INFO Aborted multipart uploads count=0 kept=011672026/11/10 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/11/10 08:17:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11692026/11/10 08:17:36 WARN Refused reserved pin name=worker-x86_64-linux11702026/11/10 08:17:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11712026/11/10 08:17:36 INFO Received create pin request method=POST path=/api/pins/my-app11722026/11/10 08:17:36 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1173--- PASS: TestCreatePin_ReservedPins (1.29s)1174=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11752026/11/10 08:17:36 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=011762026/11/10 08:17:36 INFO Received uploads request method=POST path=/api/pending_closures11772026/11/10 08:17:36 INFO Vacuumed table table=pending_closures11782026/11/10 08:17:36 INFO Vacuumed table table=pending_objects11792026/11/10 08:17:36 INFO Vacuumed table table=multipart_uploads11802026/11/10 08:17:36 INFO Vacuumed table table=closures11812026/11/10 08:17:36 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1182--- PASS: TestReadProxyNarinfo (1.74s)1183=== CONT TestConnectWaitsForAPeerMigration1184--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.53s)1185=== CONT TestService_healthCheckHandler11862026/11/10 08:17:36 INFO Vacuumed table table=objects1187--- PASS: TestSweepRechecksPendingAfterLocking (1.12s)1188=== CONT TestMultipartCleanup1189--- PASS: TestGetExistingObjectsLocksRows (0.86s)1190=== CONT TestResolveDBConnectionString1191=== RUN TestResolveDBConnectionString/flag_wins1192=== PAUSE TestResolveDBConnectionString/flag_wins1193=== RUN TestResolveDBConnectionString/file_when_flag_empty1194=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1195=== RUN TestResolveDBConnectionString/missing_file_is_an_error1196=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1197=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1198=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1199=== RUN TestResolveDBConnectionString/nothing_configured1200=== PAUSE TestResolveDBConnectionString/nothing_configured1201=== CONT TestServerTLSConfig1202=== RUN TestServerTLSConfig/no_client_CA1203=== PAUSE TestServerTLSConfig/no_client_CA1204=== RUN TestServerTLSConfig/missing_CA_file1205=== PAUSE TestServerTLSConfig/missing_CA_file1206=== RUN TestServerTLSConfig/not_a_PEM_file1207=== PAUSE TestServerTLSConfig/not_a_PEM_file1208=== CONT TestClientPushesUseOnePush1209--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.82s)1210=== CONT TestService_NativeMTLS1211--- PASS: TestObjectStatsUpdatedOncePerCommit (0.84s)1212=== CONT TestPinProtectsFromGC1213--- PASS: TestObjectStatsTrigger (0.85s)1214=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12152026/11/10 08:17:37 INFO lead: acquired remote=192.0.2.1:12341216--- PASS: TestMetricsInventory (0.89s)1217=== CONT TestMetricsCommit12182026/11/10 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures12192026/11/10 08:17:37 INFO Aborted multipart uploads count=0 kept=012202026/11/10 08:17:37 INFO Aborted multipart uploads count=0 kept=012212026/11/10 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures12222026/11/10 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures12232026/11/10 08:17:37 INFO Received cleanup request method=DELETE path=/api/pending_closures12242026/11/10 08:17:37 INFO lead: acquired remote=192.0.2.1:123412252026/11/10 08:17:37 INFO lead: released remote=192.0.2.1:12341226--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.67s)1227=== CONT TestClientSharedPathCommittedMidPush12282026/11/10 08:17:37 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket62 days=21229--- PASS: TestEnsureAbortUploadsRule (0.72s)1230=== CONT TestDeleteClosuresRacingPins1231--- PASS: TestGCBugBareHashReferences (1.13s)1232=== CONT TestClientWithDependencies12332026/11/10 08:17:37 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/11/10 08:17:37 WARN Force mode enabled - objects will be deleted immediately without grace period12352026/11/10 08:17:37 INFO lead: acquired remote=192.0.2.1:123412362026/11/10 08:17:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012372026/11/10 08:17:37 INFO Vacuumed table table=pending_closures12382026/11/10 08:17:37 INFO Vacuumed table table=pending_objects12392026/11/10 08:17:37 INFO Vacuumed table table=multipart_uploads12402026/11/10 08:17:37 INFO Vacuumed table table=closures12412026/11/10 08:17:37 INFO Vacuumed table table=objects12422026/11/10 08:17:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12432026/11/10 08:17:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1244--- PASS: TestFailedS3DeleteKeepsTombstone (1.27s)1245=== CONT TestClientFallsBackToClosures12462026/11/10 08:17:37 INFO Aborted multipart uploads count=0 kept=01247=== NAME TestNARDeduplicationMetadataUploadBug1248 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3371736839/001/store/khy34a31wk7dzj6ikq04xq5myhfl5wrd-file1.txt1249=== NAME TestClientMultipleUploads1250 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads117451975/001/store/j3jjvppdwcim4j9zbx0sir0a357pj4wl-test-file-0.txt12512026/11/10 08:17:37 WARN readiness check failed error="closed pool"1252--- PASS: TestService_readinessHandler (0.73s)1253=== CONT TestService_ReadScope_PublicByDefault12542026/11/10 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures12552026/11/10 08:17:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12562026/11/10 08:17:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1257--- PASS: TestService_NativeMTLS (0.64s)1258=== CONT TestService_ReadAuthMiddleware1259--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.75s)1260=== CONT TestClientCADerivations12612026/11/10 08:17:37 INFO Received uploads request method=POST path=/api/pending_closures12622026/11/10 08:17:37 INFO Received push request method=POST path=/api/pushes12632026/11/10 08:17:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12642026/11/10 08:17:37 INFO Received cleanup request method=DELETE path=/api/pending_closures12652026/11/10 08:17:37 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket68/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12662026/11/10 08:17:37 INFO Aborted multipart uploads count=0 kept=112672026/11/10 08:17:37 INFO Received cleanup request method=DELETE path=/api/pending_closures12682026/11/10 08:17:37 INFO Aborted multipart uploads count=1 kept=01269--- PASS: TestMultipartCleanup (0.88s)1270=== CONT TestService_RequireScope_OIDC1271=== NAME TestClientMultipleUploads1272 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads117451975/001/store/5jh1m1gwms27bcp93whs1kmf8j9whi8l-test-file-1.txt1273 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads117451975/001/store/44ik85piy43w7wpfr140c72dqiqq641n-test-file-2.txt1274--- PASS: TestService_ReadScope_PublicByDefault (0.59s)1275=== CONT TestCacheStatsHandler12762026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes12772026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12782026/11/10 08:17:38 INFO Uploading khy34a31wk7dzj6ikq04xq5myhfl5wrd-file1.txt (160B)12792026/11/10 08:17:38 WARN Force mode enabled - objects will be deleted immediately without grace period1280=== NAME TestClientWithDependencies1281 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1664007752/001/store/qs2ah7dcxqcqsj6rvihwgnb9miq6wzyd-test-script1282--- PASS: TestService_ReadAuthMiddleware (0.60s)1283=== CONT TestService_AuthMiddleware_OIDC12842026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12852026/11/10 08:17:38 WARN Failed to register uploaded object key=khy34a31wk7dzj6ikq04xq5myhfl5wrd.ls error="server returned 404: 404 page not found\n"12862026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12872026/11/10 08:17:38 INFO Signed narinfos id=1 count=112882026/11/10 08:17:38 INFO Uploading 1 narinfos12892026/11/10 08:17:38 INFO lead: released remote=192.0.2.1:12341290=== NAME TestClientCADerivations1291 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1795572512/001/store/z12541hdm4mxr05yx9664yrcv7pnd395-ca-test1292--- PASS: TestLeadEndsOnShutdown (1.69s)1293=== CONT TestCacheConfigHandler1294=== RUN TestCacheConfigHandler/full_config,_no_issuer1295=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1296=== RUN TestCacheConfigHandler/no_cache_url_configured1297=== PAUSE TestCacheConfigHandler/no_cache_url_configured1298=== RUN TestCacheConfigHandler/no_signing_keys1299=== PAUSE TestCacheConfigHandler/no_signing_keys1300=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1301=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1302=== CONT TestClientErrorHandling1303=== RUN TestClientErrorHandling/InvalidStorePath1304=== PAUSE TestClientErrorHandling/InvalidStorePath1305=== RUN TestClientErrorHandling/InvalidAuthToken1306=== PAUSE TestClientErrorHandling/InvalidAuthToken1307=== RUN TestClientErrorHandling/ServerNotAvailable1308=== PAUSE TestClientErrorHandling/ServerNotAvailable1309=== CONT TestClientIntegration13102026/11/10 08:17:38 INFO Completed push id=1 objects=4 duration=511.84945ms13112026/11/10 08:17:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13122026/11/10 08:17:38 INFO Completed upload id=2 objects=2 duration=1.681815ms13132026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13142026/11/10 08:17:38 WARN Failed to register uploaded object key=khy34a31wk7dzj6ikq04xq5myhfl5wrd.narinfo error="server returned 404: 404 page not found\n"1315--- PASS: TestMetricsCommit (1.00s)1316=== CONT TestService_AuthMiddleware_MTLSProxyHeader13172026/11/10 08:17:38 INFO Completed push id=1 objects=3 duration=15.21736ms13182026/11/10 08:17:38 INFO Upload complete. (113ms)13192026/11/10 08:17:38 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=013202026/11/10 08:17:38 INFO Vacuumed table table=pending_closures13212026/11/10 08:17:38 INFO Vacuumed table table=pending_objects13222026/11/10 08:17:38 INFO Vacuumed table table=multipart_uploads13232026/11/10 08:17:38 INFO Vacuumed table table=closures13242026/11/10 08:17:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42631/oidc13252026/11/10 08:17:38 INFO Vacuumed table table=objects1326--- PASS: TestSweepSkipsRowsLockedByPush (2.10s)1327=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1328=== NAME TestNARDeduplicationMetadataUploadBug1329 metadata_upload_test.go:54: Retrieved narinfo from S3:1330 StorePath: /build/TestNARDeduplicationMetadataUploadBug3371736839/001/store/khy34a31wk7dzj6ikq04xq5myhfl5wrd-file1.txt1331 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1332 Compression: zstd1333 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1334 NarSize: 1601335 References: 1336 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1337=== NAME TestClientWithDependencies1338 client_integration_test.go:662: Found 1 dependencies (including self)1339=== NAME TestNARDeduplicationMetadataUploadBug1340 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1341 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1342 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1343--- PASS: TestService_healthCheckHandler (1.39s)1344=== CONT TestUploadHandlersRejectOversizedBody1345=== NAME TestPinProtectsFromGC1346 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC1067130628/001/store/8jr7cdzxv20phy05am5gv0fcazv53ww2-pinned-file.txt1347 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC1067130628/001/store/13rv7ypc27xl68j76kzrjglh8rarg3f1-unpinned-file.txt13482026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1349=== NAME TestClientCADerivations1350 client_ca_test.go:139: Found 1 dependencies (including self)1351=== NAME TestOrphanedObjectsGC1352 orphaned_objects_gc_test.go:287: GC Test Summary:1353 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1354 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1355 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1356 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1357 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1358--- PASS: TestOrphanedObjectsGC (2.11s)1359=== CONT TestService_AuthMiddleware13602026/11/10 08:17:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13612026/11/10 08:17:38 INFO Uploading j3jjvppdwcim4j9zbx0sir0a357pj4wl-test-file-0.txt (160B)13622026/11/10 08:17:38 INFO Uploading 44ik85piy43w7wpfr140c72dqiqq641n-test-file-2.txt (160B)13632026/11/10 08:17:38 INFO Uploading 5jh1m1gwms27bcp93whs1kmf8j9whi8l-test-file-1.txt (160B)13642026/11/10 08:17:38 WARN Failed to register uploaded object key=44ik85piy43w7wpfr140c72dqiqq641n.ls error="server returned 404: 404 page not found\n"13652026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13662026/11/10 08:17:38 WARN Failed to register uploaded object key=5jh1m1gwms27bcp93whs1kmf8j9whi8l.ls error="server returned 404: 404 page not found\n"13672026/11/10 08:17:38 WARN Failed to register uploaded object key=j3jjvppdwcim4j9zbx0sir0a357pj4wl.ls error="server returned 404: 404 page not found\n"13682026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13692026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13702026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13712026/11/10 08:17:38 INFO Signed narinfos id=1 count=313722026/11/10 08:17:38 INFO Uploading 3 narinfos13732026/11/10 08:17:38 WARN Failed to register uploaded object key=5jh1m1gwms27bcp93whs1kmf8j9whi8l.narinfo error="server returned 404: 404 page not found\n"13742026/11/10 08:17:38 WARN Failed to register uploaded object key=44ik85piy43w7wpfr140c72dqiqq641n.narinfo error="server returned 404: 404 page not found\n"13752026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete13762026/11/10 08:17:38 WARN Failed to register uploaded object key=j3jjvppdwcim4j9zbx0sir0a357pj4wl.narinfo error="server returned 404: 404 page not found\n"13772026/11/10 08:17:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33223/oidc13782026/11/10 08:17:38 INFO Completed push id=1 objects=9 duration=12.447315ms13792026/11/10 08:17:38 INFO Upload complete. (218ms)1380=== NAME TestClientMultipleUploads1381 client_integration_test.go:416: Uploaded 3 paths in 314.07305ms1382=== NAME TestNARDeduplicationMetadataUploadBug1383 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3371736839/001/store/14yjjsvnwrs34skpws81h49dj6lp1nl4-file2.txt1384--- PASS: TestClientMultipleUploads (1.84s)1385=== CONT TestUploadHandlersRejectInvalidKeys1386=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1387=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1388=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1389=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1390=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1391=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1392=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1393=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1394=== CONT TestService_cleanupPendingClosuresHandler1395=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1396=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1397=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1398=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1399=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1400=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1401=== CONT TestCompleteMultipartUnregistered1402--- PASS: TestCacheStatsHandler (0.38s)1403=== CONT TestIsValidUploadKey1404=== RUN TestIsValidUploadKey/narinfo1405=== PAUSE TestIsValidUploadKey/narinfo1406=== RUN TestIsValidUploadKey/nar_zst1407=== PAUSE TestIsValidUploadKey/nar_zst1408=== RUN TestIsValidUploadKey/nar_xz1409=== PAUSE TestIsValidUploadKey/nar_xz1410=== RUN TestIsValidUploadKey/nar_plain1411=== PAUSE TestIsValidUploadKey/nar_plain1412=== RUN TestIsValidUploadKey/listing1413=== PAUSE TestIsValidUploadKey/listing1414=== RUN TestIsValidUploadKey/build_log1415=== PAUSE TestIsValidUploadKey/build_log1416=== RUN TestIsValidUploadKey/build_log_home-manager_file1417=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1418=== RUN TestIsValidUploadKey/build_log_plus_in_name1419=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1420=== RUN TestIsValidUploadKey/build_log_question_mark1421=== PAUSE TestIsValidUploadKey/build_log_question_mark1422=== RUN TestIsValidUploadKey/build_log_equals1423=== PAUSE TestIsValidUploadKey/build_log_equals1424=== RUN TestIsValidUploadKey/realisation1425=== PAUSE TestIsValidUploadKey/realisation1426=== RUN TestIsValidUploadKey/realisation_plus_in_output1427=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1428=== RUN TestIsValidUploadKey/nix-cache-info1429=== PAUSE TestIsValidUploadKey/nix-cache-info1430=== RUN TestIsValidUploadKey/index.html1431=== PAUSE TestIsValidUploadKey/index.html1432=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1433=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1434=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1435=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1436=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1437=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1438=== RUN TestIsValidUploadKey/traversal1439=== PAUSE TestIsValidUploadKey/traversal1440=== RUN TestIsValidUploadKey/traversal_nar1441=== PAUSE TestIsValidUploadKey/traversal_nar1442=== RUN TestIsValidUploadKey/absolute1443=== PAUSE TestIsValidUploadKey/absolute1444=== RUN TestIsValidUploadKey/empty_key1445=== PAUSE TestIsValidUploadKey/empty_key1446=== RUN TestIsValidUploadKey/unknown_type1447=== PAUSE TestIsValidUploadKey/unknown_type1448=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT14492026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes14502026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14512026/11/10 08:17:38 INFO Uploading 8jr7cdzxv20phy05am5gv0fcazv53ww2-pinned-file.txt (128B)14522026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes14532026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14542026/11/10 08:17:38 INFO Signed narinfos id=1 count=114552026/11/10 08:17:38 INFO Uploading 1 narinfos14562026/11/10 08:17:38 WARN Failed to register uploaded object key=8jr7cdzxv20phy05am5gv0fcazv53ww2.ls error="server returned 404: 404 page not found\n"14572026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14582026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14592026/11/10 08:17:38 INFO Uploading qs2ah7dcxqcqsj6rvihwgnb9miq6wzyd-test-script (136B)14602026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14612026/11/10 08:17:38 WARN Failed to register uploaded object key=8jr7cdzxv20phy05am5gv0fcazv53ww2.narinfo error="server returned 404: 404 page not found\n"14622026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14632026/11/10 08:17:38 WARN Failed to register uploaded object key=qs2ah7dcxqcqsj6rvihwgnb9miq6wzyd.ls error="server returned 404: 404 page not found\n"14642026/11/10 08:17:38 WARN Failed to register uploaded object key=log/07yc6dkbyi860zkc695fvskgjfsnc6h4-test-script.drv error="server returned 404: 404 page not found\n"14652026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14662026/11/10 08:17:38 INFO Signed narinfos id=1 count=114672026/11/10 08:17:38 INFO Uploading 1 narinfos14682026/11/10 08:17:38 INFO Completed push id=1 objects=3 duration=13.04694ms14692026/11/10 08:17:38 INFO Upload complete. (217ms)14702026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete14712026/11/10 08:17:38 WARN Failed to register uploaded object key=qs2ah7dcxqcqsj6rvihwgnb9miq6wzyd.narinfo error="server returned 404: 404 page not found\n"1472--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)1473=== CONT TestService_verifyS3ReuploadsStaleNarinfo1474=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1475=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1476=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1477=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1478=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1479=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1480=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1481=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1482=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1483=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1484=== CONT TestService_verifyS3Integrity14852026/11/10 08:17:38 INFO Completed push id=1 objects=4 duration=10.677918ms14862026/11/10 08:17:38 INFO Upload complete. (220ms)1487=== NAME TestClientWithDependencies1488 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1664007752/001/store) requires matching store prefix14892026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1490--- PASS: TestClientWithDependencies (1.14s)1491=== CONT TestPendingClosureWriteTimeout/empty1492=== CONT TestPendingClosureWriteTimeout/670k_objects1493=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14942026/11/10 08:17:38 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14952026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14962026/11/10 08:17:38 INFO Signed narinfos id=2 count=114972026/11/10 08:17:38 WARN Failed to register uploaded object key=14yjjsvnwrs34skpws81h49dj6lp1nl4.ls error="server returned 404: 404 page not found\n"14982026/11/10 08:17:38 INFO Uploading 1 narinfos1499=== NAME TestClientIntegration1500 client_integration_test.go:291: Created store path: /build/TestClientIntegration3755066943/002/store/gv6bfkcflyydgbygscgbjwvm0is1w3f5-test-file.txt15012026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/2/complete15022026/11/10 08:17:38 WARN Failed to register uploaded object key=14yjjsvnwrs34skpws81h49dj6lp1nl4.narinfo error="server returned 404: 404 page not found\n"15032026/11/10 08:17:38 INFO Completed push id=2 objects=3 duration=4.084297ms15042026/11/10 08:17:38 INFO Upload complete. (177ms)1505=== NAME TestNARDeduplicationMetadataUploadBug1506 metadata_upload_test.go:76: Retrieved narinfo from S3:1507 StorePath: /build/TestNARDeduplicationMetadataUploadBug3371736839/001/store/14yjjsvnwrs34skpws81h49dj6lp1nl4-file2.txt1508 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1509 Compression: zstd1510 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1511 NarSize: 1601512 References: 1513 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1514 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1515 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1516 {"version":1,"root":{"type":"regular","size":44}}1517--- PASS: TestNARDeduplicationMetadataUploadBug (2.27s)1518=== CONT TestPendingClosureWriteTimeout/400_objects1519=== CONT TestProxyWriteTimeout/narinfo1520=== CONT TestProxyWriteTimeout/10_GiB_nar1521=== CONT TestProxyWriteTimeout/1_GiB_nar1522=== CONT TestProxyWriteTimeout/unknown_size1523--- PASS: TestProxyWriteTimeout (2.04s)1524 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1525 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1526 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1527 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1528=== CONT TestPush_RejectsBadRequests/no_roots15292026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1530=== CONT TestPush_RejectsBadRequests/bad_root15312026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1532=== CONT TestPush_RejectsBadRequests/no_objects15332026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1534=== CONT TestPush_RejectsBadRequests/root_not_in_objects15352026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1536=== CONT TestGCEndsOnShutdown/before_the_run1537--- PASS: TestPush_RejectsBadRequests (2.43s)1538 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1539 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1540 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1541 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)15422026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes15432026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15442026/11/10 08:17:38 INFO Uploading z12541hdm4mxr05yx9664yrcv7pnd395-ca-test (144B)15452026/11/10 08:17:38 INFO Received cleanup request method=DELETE path=/api/pending_closures15462026/11/10 08:17:38 WARN Failed to register uploaded object key=z12541hdm4mxr05yx9664yrcv7pnd395.ls error="server returned 404: 404 page not found\n"15472026/11/10 08:17:38 INFO Aborted multipart uploads count=0 kept=015482026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15492026/11/10 08:17:38 WARN Failed to register uploaded object key=log/dpv6ay20fkbzz1ksgccdwh40kx7xqbgm-ca-test.drv error="server returned 404: 404 page not found\n"15502026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15512026/11/10 08:17:38 INFO Signed narinfos id=1 count=115522026/11/10 08:17:38 INFO Uploading 1 narinfos15532026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures15542026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete15552026/11/10 08:17:38 WARN Failed to register uploaded object key=z12541hdm4mxr05yx9664yrcv7pnd395.narinfo error="server returned 404: 404 page not found\n"15562026/11/10 08:17:38 INFO lead: released remote=192.0.2.1:123415572026/11/10 08:17:38 INFO Completed push id=1 objects=4 duration=10.094852ms15582026/11/10 08:17:38 INFO Upload complete. (189ms)1559=== NAME TestClientCADerivations1560 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1795572512/001/store/z12541hdm4mxr05yx9664yrcv7pnd395-ca-test1561 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1562 Compression: zstd1563 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1564 NarSize: 1441565 References: 1566 Deriver: /build/TestClientCADerivations1795572512/001/store/dpv6ay20fkbzz1ksgccdwh40kx7xqbgm-ca-test.drv1567 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1568 client_ca_test.go:185: Checking for realisation files in S3...15692026/11/10 08:17:38 INFO Received cleanup request method=DELETE path=/api/pending_closures15702026/11/10 08:17:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15712026/11/10 08:17:38 WARN mTLS auth: bound subjects configured but subject DN unavailable15722026/11/10 08:17:38 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1573--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)1574=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15752026/11/10 08:17:38 INFO Aborted multipart uploads count=1 kept=015762026/11/10 08:17:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15772026-11-10 08:17:38.592 UTC [1224] ERROR: Closure does not exist: id=115782026-11-10 08:17:38.592 UTC [1224] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15792026-11-10 08:17:38.592 UTC [1224] STATEMENT: -- name: CommitPendingClosure :one1580 SELECT commit_pending_closure($1::bigint)::bigint1581 1582--- PASS: TestService_cleanupPendingClosuresHandler (0.38s)1583=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15842026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes15852026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/11/10 08:17:38 INFO Uploading 13rv7ypc27xl68j76kzrjglh8rarg3f1-unpinned-file.txt (128B)1587=== NAME TestClientCADerivations1588 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1589 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15902026/11/10 08:17:38 WARN Failed to register uploaded object key=13rv7ypc27xl68j76kzrjglh8rarg3f1.ls error="server returned 404: 404 page not found\n"15912026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15922026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15932026/11/10 08:17:38 INFO Signed narinfos id=2 count=115942026/11/10 08:17:38 INFO Uploading 1 narinfos15952026/11/10 08:17:38 INFO lead: acquired remote=192.0.2.1:12341596=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1597=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1598=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1599=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1600=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1601=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1602=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1603=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1604=== CONT TestIsValidCachePath/narinfo1605=== CONT TestIsValidCachePath/index.html1606=== CONT TestIsValidCachePath/short_hash1607=== CONT TestIsValidCachePath/wrong_extension1608=== CONT TestIsValidCachePath/leading_slash1609=== CONT TestIsValidCachePath/empty1610=== CONT TestIsValidCachePath/random_path1611=== CONT TestIsValidCachePath/invalid_char_u1612=== CONT TestIsValidCachePath/invalid_char_e1613=== CONT TestIsValidCachePath/traversal_in_middle1614=== CONT TestIsValidCachePath/traversal_parent1615=== CONT TestIsValidCachePath/nar_uncompressed1616=== CONT TestIsValidCachePath/nix-cache-info1617=== CONT TestIsValidCachePath/realisation1618=== CONT TestIsValidCachePath/log1619=== CONT TestIsValidCachePath/ls1620=== CONT TestIsValidCachePath/nar_xz1621=== CONT TestIsValidCachePath/nar_bz21622=== CONT TestIsValidCachePath/nar_zst1623=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1624--- PASS: TestIsValidCachePath (0.00s)1625 --- PASS: TestIsValidCachePath/narinfo (0.00s)1626 --- PASS: TestIsValidCachePath/index.html (0.00s)1627 --- PASS: TestIsValidCachePath/short_hash (0.00s)1628 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1629 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1630 --- PASS: TestIsValidCachePath/empty (0.00s)1631 --- PASS: TestIsValidCachePath/random_path (0.00s)1632 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1633 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1634 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1635 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1636 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1637 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1638 --- PASS: TestIsValidCachePath/realisation (0.00s)1639 --- PASS: TestIsValidCachePath/log (0.00s)1640 --- PASS: TestIsValidCachePath/ls (0.00s)1641 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1642 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1643 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1644 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1645=== CONT TestParseSingleRange/none1646=== CONT TestParseSingleRange/open-ended1647=== CONT TestParseSingleRange/start_far_past_EOF1648=== CONT TestParseSingleRange/start_past_EOF1649=== CONT TestParseSingleRange/single_byte1650=== CONT TestParseSingleRange/suffix_exceeds_size1651=== CONT TestParseSingleRange/malformed_both_empty1652=== CONT TestParseSingleRange/closed1653=== CONT TestParseSingleRange/malformed_end_before_start1654=== CONT TestParseSingleRange/suffix16552026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/2/complete1656=== CONT TestParseSingleRange/end_clamped_to_size1657=== CONT TestParseSingleRange/multi-range_ignored1658=== CONT TestParseSingleRange/malformed_no_dash1659=== CONT TestParseSingleRange/unknown_unit1660--- PASS: TestParseSingleRange (0.00s)1661 --- PASS: TestParseSingleRange/none (0.00s)1662 --- PASS: TestParseSingleRange/open-ended (0.00s)1663 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1664 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1665 --- PASS: TestParseSingleRange/single_byte (0.00s)1666 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1667 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1668 --- PASS: TestParseSingleRange/closed (0.00s)1669 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1670 --- PASS: TestParseSingleRange/suffix (0.00s)1671 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1672 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1673 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1674 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1675=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16762026/11/10 08:17:38 WARN Failed to register uploaded object key=13rv7ypc27xl68j76kzrjglh8rarg3f1.narinfo error="server returned 404: 404 page not found\n"16772026/11/10 08:17:38 INFO Completed push id=2 objects=3 duration=4.562542ms16782026/11/10 08:17:38 INFO Upload complete. (161ms)16792026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures1680--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.33s)1681=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1682=== RUN TestService_RequireScope_OIDC/builder_may_write1683=== PAUSE TestService_RequireScope_OIDC/builder_may_write1684=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1685=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1686=== RUN TestService_RequireScope_OIDC/ops_may_admin1687=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1688=== RUN TestService_RequireScope_OIDC/ops_may_not_write1689=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1690=== RUN TestService_RequireScope_OIDC/reader_may_not_write1691=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1692=== RUN TestService_RequireScope_OIDC/static_token_may_admin1693=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1694=== RUN TestService_RequireScope_OIDC/static_token_may_write1695=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1696=== RUN TestService_RequireScope_OIDC/reader_may_read1697=== PAUSE TestService_RequireScope_OIDC/reader_may_read1698=== RUN TestService_RequireScope_OIDC/writer_implies_read1699=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1700=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1701=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1702=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1703=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1704=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1705=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1706=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1707=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1708=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1709=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1710=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17112026/11/10 08:17:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17122026/11/10 08:17:38 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1713--- PASS: TestCompleteMultipartUnregistered (0.41s)1714=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17152026/11/10 08:17:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures17162026/11/10 08:17:38 INFO Garbage collection started17172026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes17182026/11/10 08:17:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17192026/11/10 08:17:38 INFO Uploading gv6bfkcflyydgbygscgbjwvm0is1w3f5-test-file.txt (152B)17202026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures17212026/11/10 08:17:38 INFO Aborted multipart uploads count=0 kept=017222026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures17232026/11/10 08:17:38 WARN Failed to register uploaded object key=gv6bfkcflyydgbygscgbjwvm0is1w3f5.ls error="server returned 404: 404 page not found\n"17242026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17252026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17262026/11/10 08:17:38 INFO Signed narinfos id=1 count=117272026/11/10 08:17:38 INFO Uploading 1 narinfos17282026/11/10 08:17:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17292026/11/10 08:17:38 INFO Uploading z43z7dn1dlkpwvqmvxrg1h1mvyn9b42x-b (216B)17302026/11/10 08:17:38 INFO Uploading 813ay6xyvp8fl9nid6lr4f56sxk4gjpb-shared-dep (136B)17312026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures17322026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17332026/11/10 08:17:38 WARN Failed to register uploaded object key=gv6bfkcflyydgbygscgbjwvm0is1w3f5.narinfo error="server returned 404: 404 page not found\n"1734--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.76s)1735=== CONT TestResolveDBConnectionString/flag_wins1736=== CONT TestResolveDBConnectionString/nothing_configured1737=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1738=== CONT TestResolveDBConnectionString/missing_file_is_an_error1739=== CONT TestResolveDBConnectionString/file_when_flag_empty1740=== CONT TestServerTLSConfig/no_client_CA1741=== CONT TestServerTLSConfig/not_a_PEM_file1742--- PASS: TestResolveDBConnectionString (0.00s)1743 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1744 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1745 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1746 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1747 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1748=== CONT TestServerTLSConfig/missing_CA_file1749--- PASS: TestServerTLSConfig (0.00s)1750 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1751 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1752 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1753=== CONT TestCacheConfigHandler/full_config,_no_issuer1754=== CONT TestClientErrorHandling/InvalidStorePath17552026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17562026/11/10 08:17:38 WARN Failed to register uploaded object key=z43z7dn1dlkpwvqmvxrg1h1mvyn9b42x.ls error="server returned 404: 404 page not found\n"17572026/11/10 08:17:38 WARN Failed to register uploaded object key=8x1s0cac98qdsdqghls4nsnyx75p3k4x.ls error="server returned 404: 404 page not found\n"17582026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/0n1sjmkxgz6bpp9kb7bsz402v1wdgz8sra2pr988crwy97kzbsal.nar.zst error="server returned 404: 404 page not found\n"17592026/11/10 08:17:38 WARN Failed to register uploaded object key=813ay6xyvp8fl9nid6lr4f56sxk4gjpb.ls error="server returned 404: 404 page not found\n"17602026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17612026/11/10 08:17:38 INFO Signed narinfos id=2 count=217622026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17632026/11/10 08:17:38 INFO Signed narinfos id=1 count=217642026/11/10 08:17:38 INFO Uploading 4 narinfos17652026/11/10 08:17:38 INFO Completed push id=1 objects=3 duration=9.679228ms17662026/11/10 08:17:38 INFO Upload complete. (171ms)17672026/11/10 08:17:38 WARN Failed to register uploaded object key=813ay6xyvp8fl9nid6lr4f56sxk4gjpb.narinfo error="server returned 404: 404 page not found\n"17682026/11/10 08:17:38 WARN Failed to register uploaded object key=z43z7dn1dlkpwvqmvxrg1h1mvyn9b42x.narinfo error="server returned 404: 404 page not found\n"17692026/11/10 08:17:38 WARN Failed to register uploaded object key=8x1s0cac98qdsdqghls4nsnyx75p3k4x.narinfo error="server returned 404: 404 page not found\n"17702026/11/10 08:17:38 WARN Failed to register uploaded object key=813ay6xyvp8fl9nid6lr4f56sxk4gjpb.narinfo error="server returned 404: 404 page not found\n"17712026/11/10 08:17:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17722026/11/10 08:17:38 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1773--- PASS: TestService_AuthMiddleware (0.63s)1774=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1775=== CONT TestCacheConfigHandler/no_signing_keys1776=== CONT TestCacheConfigHandler/no_cache_url_configured1777--- PASS: TestCacheConfigHandler (0.00s)1778 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1779 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1780 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1781 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1782=== CONT TestClientErrorHandling/ServerNotAvailable17832026/11/10 08:17:38 INFO Completed upload id=1 objects=6 duration=13.341923ms17842026/11/10 08:17:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17852026/11/10 08:17:38 INFO Completed upload id=2 objects=6 duration=8.434938ms17862026/11/10 08:17:38 INFO Upload complete. (274ms)1787=== NAME TestClientFallsBackToClosures1788 client_pushes_test.go:112: Retrieved narinfo from S3:1789 StorePath: /build/TestClientFallsBackToClosures161027459/001/store/813ay6xyvp8fl9nid6lr4f56sxk4gjpb-shared-dep1790 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1791 Compression: zstd1792 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821793 NarSize: 1361794 References: 1795 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17962026/11/10 08:17:38 WARN Force mode enabled - objects will be deleted immediately without grace period17972026/11/10 08:17:38 INFO Received push request method=POST path=/api/pushes1798 client_pushes_test.go:112: Retrieved narinfo from S3:1799 StorePath: /build/TestClientFallsBackToClosures161027459/001/store/8x1s0cac98qdsdqghls4nsnyx75p3k4x-a1800 URL: nar/0n1sjmkxgz6bpp9kb7bsz402v1wdgz8sra2pr988crwy97kzbsal.nar.zst1801 Compression: zstd1802 NarHash: sha256:0n1sjmkxgz6bpp9kb7bsz402v1wdgz8sra2pr988crwy97kzbsal1803 NarSize: 2161804 References: /build/TestClientFallsBackToClosures161027459/001/store/813ay6xyvp8fl9nid6lr4f56sxk4gjpb-shared-dep1805 CA: text:sha256:0sdhri5ng7kp13ni3p362srdfbwrxnhf7lhmjisbn8aac8wqdnbv1806 client_pushes_test.go:112: Retrieved narinfo from S3:1807 StorePath: /build/TestClientFallsBackToClosures161027459/001/store/z43z7dn1dlkpwvqmvxrg1h1mvyn9b42x-b1808 URL: nar/0n1sjmkxgz6bpp9kb7bsz402v1wdgz8sra2pr988crwy97kzbsal.nar.zst1809 Compression: zstd1810 NarHash: sha256:0n1sjmkxgz6bpp9kb7bsz402v1wdgz8sra2pr988crwy97kzbsal1811 NarSize: 2161812 References: /build/TestClientFallsBackToClosures161027459/001/store/813ay6xyvp8fl9nid6lr4f56sxk4gjpb-shared-dep1813 CA: text:sha256:0sdhri5ng7kp13ni3p362srdfbwrxnhf7lhmjisbn8aac8wqdnbv18142026/11/10 08:17:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18152026/11/10 08:17:38 INFO Uploading qfxgc97kh7ly33rpjl2c983gipaqjn3p-shared-dep (136B)18162026/11/10 08:17:38 INFO Uploading g8m2y8lqaasqxr16wfa459aq0k9f5qmz-top (224B)1817--- PASS: TestClientFallsBackToClosures (1.49s)1818=== CONT TestClientErrorHandling/InvalidAuthToken18192026/11/10 08:17:38 WARN Failed to register uploaded object key=qfxgc97kh7ly33rpjl2c983gipaqjn3p.ls error="server returned 404: 404 page not found\n"18202026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/15ss7ydnn3ipbk17j03w5hxndd961qgqx1z26pw2k0mv39acaq59.nar.zst error="server returned 404: 404 page not found\n"18212026/11/10 08:17:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18222026/11/10 08:17:38 WARN Failed to register uploaded object key=g8m2y8lqaasqxr16wfa459aq0k9f5qmz.ls error="server returned 404: 404 page not found\n"18232026/11/10 08:17:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18242026/11/10 08:17:38 INFO Signed narinfos id=1 count=218252026/11/10 08:17:38 INFO Uploading 2 narinfos18262026/11/10 08:17:38 INFO Received complete push request method=POST path=/api/pushes/1/complete18272026/11/10 08:17:38 WARN Failed to register uploaded object key=g8m2y8lqaasqxr16wfa459aq0k9f5qmz.narinfo error="server returned 404: 404 page not found\n"1828=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18292026/11/10 08:17:38 INFO Received uploads request method=POST path=/1830=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18312026/11/10 08:17:38 INFO Received complete multipart upload request method=POST path=/1832=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18332026/11/10 08:17:38 WARN Failed to register uploaded object key=qfxgc97kh7ly33rpjl2c983gipaqjn3p.narinfo error="server returned 404: 404 page not found\n"18342026/11/10 08:17:38 INFO Received uploads request method=POST path=/1835=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18362026/11/10 08:17:38 INFO Received request for more parts method=POST path=/1837--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1838 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1839 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1840 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1841 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1842=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18432026/11/10 08:17:38 INFO Received uploads request method=POST path=/18442026/11/10 08:17:38 INFO Completed push id=1 objects=6 duration=12.246493ms18452026/11/10 08:17:38 INFO Upload complete. (225ms)1846=== NAME TestClientSharedPathCommittedMidPush1847 client_integration_test.go:727: Retrieved narinfo from S3:1848 StorePath: /build/TestClientSharedPathCommittedMidPush884107707/001/store/qfxgc97kh7ly33rpjl2c983gipaqjn3p-shared-dep1849 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1850 Compression: zstd1851 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821852 NarSize: 1361853 References: 1854 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1855 client_integration_test.go:727: Retrieved narinfo from S3:1856 StorePath: /build/TestClientSharedPathCommittedMidPush884107707/001/store/g8m2y8lqaasqxr16wfa459aq0k9f5qmz-top1857 URL: nar/15ss7ydnn3ipbk17j03w5hxndd961qgqx1z26pw2k0mv39acaq59.nar.zst1858 Compression: zstd1859 NarHash: sha256:15ss7ydnn3ipbk17j03w5hxndd961qgqx1z26pw2k0mv39acaq591860 NarSize: 2241861 References: /build/TestClientSharedPathCommittedMidPush884107707/001/store/qfxgc97kh7ly33rpjl2c983gipaqjn3p-shared-dep1862 CA: text:sha256:1jsz3ysdc1lsxa839lq4dfk48502qnxamynzmlfkhl51a6gqmnyn1863--- PASS: TestClientSharedPathCommittedMidPush (1.58s)1864=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18652026/11/10 08:17:38 INFO Received request for more parts method=POST path=/18662026/11/10 08:17:38 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=018672026/11/10 08:17:38 INFO Vacuumed table table=pending_closures18682026/11/10 08:17:38 INFO Vacuumed table table=pending_objects18692026/11/10 08:17:38 INFO Vacuumed table table=multipart_uploads18702026/11/10 08:17:38 INFO Vacuumed table table=closures18712026/11/10 08:17:38 INFO Vacuumed table table=objects18722026/11/10 08:17:38 INFO Aborted multipart uploads count=0 kept=018732026/11/10 08:17:38 INFO Received uploads request method=POST path=/api/pending_closures1874=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18752026/11/10 08:17:38 INFO Received complete multipart upload request method=POST path=/18762026/11/10 08:17:38 INFO Aborted multipart uploads count=0 kept=01877=== CONT TestIsValidUploadKey/unknown_type1878=== CONT TestIsValidUploadKey/narinfo1879=== CONT TestIsValidUploadKey/traversal1880=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1881=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1882=== CONT TestIsValidUploadKey/traversal_nar1883=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1884=== CONT TestIsValidUploadKey/index.html1885=== CONT TestIsValidUploadKey/empty_key1886=== CONT TestIsValidUploadKey/nix-cache-info1887=== CONT TestIsValidUploadKey/absolute1888=== CONT TestIsValidUploadKey/realisation_plus_in_output1889=== CONT TestIsValidUploadKey/realisation1890=== CONT TestIsValidUploadKey/build_log_equals1891=== CONT TestIsValidUploadKey/listing1892=== CONT TestIsValidUploadKey/build_log1893=== CONT TestIsValidUploadKey/build_log_question_mark1894=== CONT TestIsValidUploadKey/build_log_plus_in_name1895=== CONT TestIsValidUploadKey/nar_zst1896=== CONT TestIsValidUploadKey/build_log_home-manager_file1897=== CONT TestIsValidUploadKey/nar_plain1898=== CONT TestIsValidUploadKey/nar_xz1899--- PASS: TestIsValidUploadKey (0.00s)1900 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1901 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1902 --- PASS: TestIsValidUploadKey/traversal (0.00s)1903 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1904 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1905 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1906 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1907 --- PASS: TestIsValidUploadKey/index.html (0.00s)1908 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1909 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1910 --- PASS: TestIsValidUploadKey/absolute (0.00s)1911 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1912 --- PASS: TestIsValidUploadKey/realisation (0.00s)1913 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1914 --- PASS: TestIsValidUploadKey/listing (0.00s)1915 --- PASS: TestIsValidUploadKey/build_log (0.00s)1916 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1917 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1918 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1919 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1920 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1921 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1922=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed19232026/11/10 08:17:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1924--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.85s)1925=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed19262026/11/10 08:17:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLmRkYWM3NGQ0LTE0ZmItNDhjNS1hOWU4LWVjZWEwZTcxOWQzZngxNzk0Mjk4NjU4NzcwNzczNjQ2 parts=1019272026/11/10 08:17:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19282026/11/10 08:17:39 INFO Completed upload id=1 objects=2 duration=5.315789ms19292026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures19302026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures19312026/11/10 08:17:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19322026/11/10 08:17:39 WARN Found objects in DB but missing from S3, will re-upload count=11933--- PASS: TestService_verifyS3Integrity (0.79s)1934=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1935=== NAME TestOrphanedObjectsGCStressTest1936 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19372026/11/10 08:17:39 WARN Force mode enabled - objects will be deleted immediately without grace period19382026/11/10 08:17:39 WARN Force mode enabled - objects will be deleted immediately without grace period19392026/11/10 08:17:39 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44967/bucket96/?delete=\": context canceled"19402026-11-10 08:17:39.384 UTC [1652] ERROR: canceling statement due to user request19412026-11-10 08:17:39.384 UTC [1652] CONTEXT: PL/pgSQL expression "NULL"1942 PL/pgSQL function object_stats_update() line 16 at RETURN19432026-11-10 08:17:39.384 UTC [1652] STATEMENT: -- name: MarkStaleObjects :execrows1944 WITH RECURSIVE ct AS (1945 SELECT timezone('UTC', now()) AS now1946 ),1947 closure_reach AS (1948 -- Start with all closure keys1949 SELECT o.key, o.refs1950 FROM objects o1951 INNER JOIN closures c ON o.key = c.key1952 UNION1953 -- Recursively add all referenced objects1954 SELECT o.key, o.refs1955 FROM objects o1956 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1957 ),1958 reachable_objects AS (1959 SELECT DISTINCT key FROM closure_reach1960 ),1961 stale_objects AS (1962 SELECT o.key1963 FROM objects AS o, ct1964 WHERE1965 NOT EXISTS (1966 SELECT 11967 FROM reachable_objects ro1968 WHERE ro.key = o.key1969 )1970 AND NOT EXISTS (1971 SELECT 11972 FROM pending_objects AS po1973 WHERE po.key = o.key1974 )1975 AND o.deleted_at IS NULL -- Only mark fresh objects1976 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1977 FOR UPDATE1978 )1979 UPDATE objects1980 SET1981 deleted_at = ct.now,1982 first_deleted_at = COALESCE(first_deleted_at, ct.now)1983 FROM stale_objects, ct1984 WHERE objects.key = stale_objects.key1985 1986=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1987--- PASS: TestGCEndsOnShutdown (0.00s)1988 --- PASS: TestGCEndsOnShutdown/before_the_run (0.34s)1989 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.79s)1990 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.81s)1991=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed19922026/11/10 08:17:39 INFO Received push request method=POST path=/api/pushes19932026/11/10 08:17:39 INFO All 1 paths already cached1994=== NAME TestClientIntegration1995 client_integration_test.go:317: Retrieved narinfo from S3:1996 StorePath: /build/TestClientIntegration3755066943/002/store/gv6bfkcflyydgbygscgbjwvm0is1w3f5-test-file.txt1997 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1998 Compression: zstd1999 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12000 NarSize: 1522001 References: 2002 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk120032026/11/10 08:17:39 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20042026/11/10 08:17:39 INFO Uploading bcsdhnhmw1bbqh0c0k78kxprkd088ipv-shared-dep (136B)20052026/11/10 08:17:39 INFO Uploading w2b89w96srw201hm6x4zacqygh57p2hf-a (216B)2006 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)2007 client_integration_test.go:318: Decompressed .ls content (64 bytes):2008 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}20092026/11/10 08:17:39 WARN Failed to register uploaded object key=w2b89w96srw201hm6x4zacqygh57p2hf.ls error="server returned 404: 404 page not found\n"20102026/11/10 08:17:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20112026/11/10 08:17:39 WARN Failed to register uploaded object key=nar/1x144ba8630b0m4qqiaqsr9103dcwcbdsfnrr8j0qqg5cxprj5ad.nar.zst error="server returned 404: 404 page not found\n"20122026/11/10 08:17:39 WARN Failed to register uploaded object key=n6459rshvl4qrqdl3kb0rzf7ww7xx76x.ls error="server returned 404: 404 page not found\n"20132026/11/10 08:17:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20142026/11/10 08:17:39 WARN Failed to register uploaded object key=bcsdhnhmw1bbqh0c0k78kxprkd088ipv.ls error="server returned 404: 404 page not found\n"20152026/11/10 08:17:39 INFO Signed narinfos id=1 count=320162026/11/10 08:17:39 INFO Uploading 3 narinfos20172026/11/10 08:17:39 WARN Failed to register uploaded object key=n6459rshvl4qrqdl3kb0rzf7ww7xx76x.narinfo error="server returned 404: 404 page not found\n"20182026/11/10 08:17:39 WARN Failed to register uploaded object key=w2b89w96srw201hm6x4zacqygh57p2hf.narinfo error="server returned 404: 404 page not found\n"20192026/11/10 08:17:39 INFO Received complete push request method=POST path=/api/pushes/1/complete20202026/11/10 08:17:39 WARN Failed to register uploaded object key=bcsdhnhmw1bbqh0c0k78kxprkd088ipv.narinfo error="server returned 404: 404 page not found\n"2021=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20222026/11/10 08:17:39 INFO Completed push id=1 objects=8 duration=16.429411ms20232026/11/10 08:17:39 INFO Upload complete. (729ms)2024=== NAME TestClientPushesUseOnePush2025 client_pushes_test.go:97: Retrieved narinfo from S3:2026 StorePath: /build/TestClientPushesUseOnePush1440442555/001/store/bcsdhnhmw1bbqh0c0k78kxprkd088ipv-shared-dep2027 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2028 Compression: zstd2029 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822030 NarSize: 1362031 References: 2032 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2033=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20342026/11/10 08:17:39 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]2035=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2036=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20372026/11/10 08:17:39 WARN Authentication failed token_preview=eyJhbGciOi...ntuv3Ds-Ng token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2038=== CONT TestService_RequireScope_OIDC/builder_may_write2039--- PASS: TestService_AuthMiddleware_OIDC (0.57s)2040 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2041 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2042 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2043 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2044=== NAME TestClientPushesUseOnePush2045 client_pushes_test.go:97: Retrieved narinfo from S3:2046 StorePath: /build/TestClientPushesUseOnePush1440442555/001/store/w2b89w96srw201hm6x4zacqygh57p2hf-a2047 URL: nar/1x144ba8630b0m4qqiaqsr9103dcwcbdsfnrr8j0qqg5cxprj5ad.nar.zst2048 Compression: zstd2049 NarHash: sha256:1x144ba8630b0m4qqiaqsr9103dcwcbdsfnrr8j0qqg5cxprj5ad2050 NarSize: 2162051 References: /build/TestClientPushesUseOnePush1440442555/001/store/bcsdhnhmw1bbqh0c0k78kxprkd088ipv-shared-dep2052 CA: text:sha256:079vrj3yjlqr8hmp3cf2pkvfdzp5dlv8y4v1qs6bhayr6qhm3hmn2053=== CONT TestService_RequireScope_OIDC/reader_may_read2054=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2055=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20562026/11/10 08:17:39 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]2057=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2058=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2059=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2060=== CONT TestService_RequireScope_OIDC/writer_implies_read2061=== CONT TestService_RequireScope_OIDC/reader_may_not_write2062=== CONT TestService_RequireScope_OIDC/static_token_may_write2063=== CONT TestService_RequireScope_OIDC/static_token_may_admin2064=== CONT TestService_RequireScope_OIDC/ops_may_admin2065=== CONT TestService_RequireScope_OIDC/ops_may_not_write2066=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2067--- PASS: TestService_RequireScope_OIDC (1.08s)2068 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2070 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2071 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2072 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2073 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2074 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2078 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2079 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2080 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2082=== NAME TestClientPushesUseOnePush2083 client_pushes_test.go:97: Retrieved narinfo from S3:2084 StorePath: /build/TestClientPushesUseOnePush1440442555/001/store/n6459rshvl4qrqdl3kb0rzf7ww7xx76x-b2085 URL: nar/1x144ba8630b0m4qqiaqsr9103dcwcbdsfnrr8j0qqg5cxprj5ad.nar.zst2086 Compression: zstd2087 NarHash: sha256:1x144ba8630b0m4qqiaqsr9103dcwcbdsfnrr8j0qqg5cxprj5ad2088 NarSize: 2162089 References: /build/TestClientPushesUseOnePush1440442555/001/store/bcsdhnhmw1bbqh0c0k78kxprkd088ipv-shared-dep2090 CA: text:sha256:079vrj3yjlqr8hmp3cf2pkvfdzp5dlv8y4v1qs6bhayr6qhm3hmn2091--- PASS: TestClientPushesUseOnePush (2.67s)20922026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures2093--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2094 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.77s)2095 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.87s)20962026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures20972026/11/10 08:17:39 INFO Aborted multipart uploads count=0 kept=020982026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures20992026/11/10 08:17:39 INFO Aborted multipart uploads count=0 kept=021002026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures21012026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures21022026/11/10 08:17:39 INFO lead: released remote=192.0.2.1:12342103--- PASS: TestLeadElectsOneAndHandsOver (3.05s)2104--- PASS: TestPendingClosureWriteTimeout (2.04s)2105 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2106 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2107 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2108 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.27s)21092026/11/10 08:17:39 WARN Force mode enabled - objects will be deleted immediately without grace period21102026/11/10 08:17:39 WARN Force mode enabled - objects will be deleted immediately without grace period21112026/11/10 08:17:39 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=021122026/11/10 08:17:39 INFO Vacuumed table table=pending_closures2113=== NAME TestOrphanedObjectsGCStressTest2114 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21152026/11/10 08:17:39 INFO Vacuumed table table=pending_objects21162026/11/10 08:17:39 INFO Vacuumed table table=multipart_uploads21172026/11/10 08:17:39 INFO Vacuumed table table=closures21182026/11/10 08:17:39 INFO Vacuumed table table=objects21192026/11/10 08:17:39 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=021202026/11/10 08:17:39 INFO Vacuumed table table=pending_closures21212026/11/10 08:17:39 INFO Vacuumed table table=pending_objects21222026/11/10 08:17:39 INFO Vacuumed table table=multipart_uploads21232026/11/10 08:17:39 INFO Vacuumed table table=closures21242026/11/10 08:17:39 INFO Vacuumed table table=objects21252026/11/10 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures2126--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2127 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.14s)2128 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.20s)2129--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2130 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2131 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)2132 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.54s)21332026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21342026/11/10 08:17:40 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21352026/11/10 08:17:40 WARN Rate limiter enabled after throttle name=s3-test rate=521362026/11/10 08:17:40 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2137=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2138 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102139 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002140--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.31s)21412026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21422026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjNmYmJhM2E1LWUzMTctNGE4OC05ZTY5LWEzY2QwZGZhOGMyMHgxNzk0Mjk4NjU5NTAxODYyNjE1 parts=1021432026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21442026/11/10 08:17:40 INFO Completed upload id=1 objects=3 duration=3.713494ms21452026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21462026/11/10 08:17:40 WARN Request failed, retrying attempt=2 backoff=208.953027ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21472026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21482026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21492026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjI2ODNkZTg4LTI5YWMtNDY1ZC1hMTE2LWM2OGY5NmNjNzFjNHgxNzk0Mjk4NjU5NjEwMjgxNDcy parts=1021502026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLmVlYTA4YmExLTkwZWYtNDZlYS05MGVhLTM5ZDdmN2JlMjhhNXgxNzk0Mjk4NjU5NjM2NDk4NDU0 parts=1021512026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21522026/11/10 08:17:40 INFO Completed upload id=1 objects=3 duration=3.225309ms21532026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21542026/11/10 08:17:40 INFO Completed upload id=1 objects=3 duration=3.045728ms21552026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21562026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21572026/11/10 08:17:40 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21582026/11/10 08:17:40 WARN Found objects in DB but missing from S3, will re-upload count=121592026/11/10 08:17:40 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21602026/11/10 08:17:40 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21612026/11/10 08:17:40 WARN Request failed, retrying attempt=3 backoff=432.050638ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21622026/11/10 08:17:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021632026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21642026/11/10 08:17:40 INFO Received create pin request method=POST path=/api/pins/myapp21652026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2166=== NAME TestOrphanedObjectsGCStressTest2167 orphaned_objects_gc_test.go:503: Stress test completed successfully:2168 orphaned_objects_gc_test.go:504: - Active objects preserved: 202169 orphaned_objects_gc_test.go:505: - Objects deleted: 2102170 orphaned_objects_gc_test.go:506: - Total GC'd: 2102171--- PASS: TestOrphanedObjectsGCStressTest (5.26s)21722026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjg2YjVhNTYzLTY3MzEtNGI3MS05NzQyLTRmMmYxZjhiMjIxMHgxNzk0Mjk4NjU5OTA4NDk0MDE3 parts=1021732026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjFjYzY2NzM0LWMwMWEtNDgzYi04Yzk0LWFmZDg4YzdhNzI1Y3gxNzk0Mjk4NjYwNDA2Mjk0NDM4 parts=1021742026/11/10 08:17:40 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1067130628/001/store/8jr7cdzxv20phy05am5gv0fcazv53ww2-pinned-file.txt narinfo_key=8jr7cdzxv20phy05am5gv0fcazv53ww2.narinfo21752026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21762026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21772026/11/10 08:17:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21782026/11/10 08:17:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures21792026/11/10 08:17:40 INFO Completed upload id=1 objects=3 duration=4.892685ms21802026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21812026/11/10 08:17:40 INFO Completed upload id=1 objects=3 duration=4.790064ms21822026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21832026/11/10 08:17:40 INFO Garbage collection started21842026/11/10 08:17:40 INFO Aborted multipart uploads count=0 kept=021852026/11/10 08:17:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjI4MmMwMzFmLWFkYjUtNDA2Zi1hYjZkLWM1ZjA5NTBiNmQzNXgxNzk0Mjk4NjYwNDkyNTQxNTUy parts=1021862026/11/10 08:17:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21872026/11/10 08:17:40 INFO Completed upload id=2 objects=3 duration=4.513302ms21882026/11/10 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures21892026/11/10 08:17:40 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21902026/11/10 08:17:40 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo21912026/11/10 08:17:41 WARN Request failed, retrying attempt=4 backoff=840.967511ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21922026/11/10 08:17:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21932026/11/10 08:17:41 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MDIwY2UzNWUtM2UxYS00ZmU0LTgwNzEtMjIzNTdlMTk5OGQzLjJlYzJkZjIxLTY4NDMtNDM1Yy05MjY0LWYwYjIyNWY1M2UzZXgxNzk0Mjk4NjYwODU1NTM1NzMy parts=1021942026/11/10 08:17:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21952026/11/10 08:17:41 INFO Completed upload id=2 objects=3 duration=2.034418ms21962026/11/10 08:17:41 INFO Received uploads request method=POST path=/api/pending_closures21972026/11/10 08:17:41 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21982026/11/10 08:17:41 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2199--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2200 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (1.61s)2201 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (1.43s)2202 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (1.46s)2203 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.71s)2204 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.99s)22052026/11/10 08:17:41 WARN Request failed, retrying attempt=5 backoff=1.719281666s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2206--- PASS: TestConnectWaitsForAPeerMigration (5.30s)22072026/11/10 08:17:42 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2208--- PASS: TestDeleteClosuresRacingPins (4.97s)22092026/11/10 08:17:42 INFO Garbage collection progress phase=cleanup_pending_uploads failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=022102026/11/10 08:17:43 INFO Aborted multipart uploads count=1 kept=022112026/11/10 08:17:43 INFO Received cleanup request method=DELETE path=/api/pending_closures22122026/11/10 08:17:43 INFO Aborted multipart uploads count=1 kept=02213--- PASS: TestPendingCleanupUsesOneCutoff (6.86s)22142026/11/10 08:17:44 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22152026/11/10 08:17:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22162026/11/10 08:17:44 WARN Force mode enabled - objects will be deleted immediately without grace period22172026/11/10 08:17:44 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=022182026/11/10 08:17:44 INFO Vacuumed table table=pending_closures22192026/11/10 08:17:44 INFO Vacuumed table table=pending_objects22202026/11/10 08:17:44 INFO Vacuumed table table=multipart_uploads22212026/11/10 08:17:44 INFO Vacuumed table table=closures22222026/11/10 08:17:44 INFO Vacuumed table table=objects22232026/11/10 08:17:44 WARN Request failed, retrying attempt=2 backoff=187.981856ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22242026/11/10 08:17:44 WARN Request failed, retrying attempt=3 backoff=372.915958ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/11/10 08:17:44 INFO Received push request method=POST path=/api/pushes22262026/11/10 08:17:44 INFO Object in database but missing from S3 key=gv6bfkcflyydgbygscgbjwvm0is1w3f5.ls22272026/11/10 08:17:44 WARN Found objects in DB but missing from S3, will re-upload count=122282026/11/10 08:17:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22292026/11/10 08:17:44 INFO Received complete push request method=POST path=/api/pushes/2/complete22302026/11/10 08:17:44 WARN Failed to register uploaded object key=gv6bfkcflyydgbygscgbjwvm0is1w3f5.ls error="server returned 404: 404 page not found\n"22312026/11/10 08:17:44 INFO Completed push id=2 objects=3 duration=6.418619ms22322026/11/10 08:17:44 INFO Upload complete. (4.841s)2233=== NAME TestClientIntegration2234 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)2235 client_integration_test.go:335: Decompressed .ls content (49 bytes):2236 {"version":1,"root":{"type":"regular","size":39}}22372026/11/10 08:17:44 WARN Request failed, retrying attempt=4 backoff=754.806087ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22382026/11/10 08:17:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=02239=== NAME TestPinProtectsFromGC2240 client_integration_test.go:887: Pin successfully protected closure from garbage collection2241--- PASS: TestPinProtectsFromGC (7.91s)22422026/11/10 08:17:45 WARN Request failed, retrying attempt=5 backoff=1.568252255s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22432026/11/10 08:17:46 INFO Received push request method=POST path=/api/pushes22442026/11/10 08:17:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)22452026/11/10 08:17:46 INFO Received complete push request method=POST path=/api/pushes/3/complete22462026/11/10 08:17:46 WARN Failed to register uploaded object key=gv6bfkcflyydgbygscgbjwvm0is1w3f5.ls error="server returned 404: 404 page not found\n"22472026/11/10 08:17:46 INFO Completed push id=3 objects=3 duration=11.733928ms22482026/11/10 08:17:46 INFO Upload complete. (1.626s)2249=== NAME TestClientIntegration2250 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2251 client_integration_test.go:352: Decompressed .ls content (49 bytes):2252 {"version":1,"root":{"type":"regular","size":39}}2253 client_integration_test.go:363: Testing garbage collection...22542026/11/10 08:17:47 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"22552026/11/10 08:17:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22562026/11/10 08:17:47 WARN Request failed, retrying attempt=2 backoff=210.385418ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22572026/11/10 08:17:47 WARN Request failed, retrying attempt=3 backoff=385.737506ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22582026/11/10 08:17:47 WARN Request failed, retrying attempt=4 backoff=849.222599ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/11/10 08:17:48 WARN Request failed, retrying attempt=5 backoff=1.551340643s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2260=== NAME TestClientCADerivations2261 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2262 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2263 error: binary cache 's3://bucket72?endpoint=http://localhost:44967®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1795572512/001/store'2264 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 122652026/11/10 08:17:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures22662026/11/10 08:17:48 INFO Garbage collection started2267--- PASS: TestClientCADerivations (11.53s)22682026/11/10 08:17:49 INFO Aborted multipart uploads count=0 kept=022692026/11/10 08:17:49 WARN Force mode enabled - objects will be deleted immediately without grace period22702026/11/10 08:17:49 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=022712026/11/10 08:17:49 INFO Vacuumed table table=pending_closures22722026/11/10 08:17:49 INFO Vacuumed table table=pending_objects22732026/11/10 08:17:49 INFO Vacuumed table table=multipart_uploads22742026/11/10 08:17:49 INFO Vacuumed table table=closures22752026/11/10 08:17:49 INFO Vacuumed table table=objects22762026/11/10 08:17:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22772026/11/10 08:17:50 WARN Request failed, retrying attempt=2 backoff=217.230196ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22782026/11/10 08:17:50 WARN Request failed, retrying attempt=3 backoff=386.723031ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22792026/11/10 08:17:50 WARN Request failed, retrying attempt=4 backoff=820.014898ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22802026/11/10 08:17:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02281=== NAME TestClientIntegration2282 client_integration_test.go:370: Objects in database after GC:2283 client_integration_test.go:370: Successfully deleted all objects with GC --force2284--- PASS: TestClientIntegration (12.97s)22852026/11/10 08:17:51 WARN Request failed, retrying attempt=5 backoff=1.573549805s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2286--- PASS: TestClientErrorHandling (0.00s)2287 --- PASS: TestClientErrorHandling/InvalidStorePath (1.07s)2288 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.20s)2289 --- PASS: TestClientErrorHandling/ServerNotAvailable (14.50s)2290PASS22912026-11-10 08:17:53.772 UTC [133] LOG: received smart shutdown request22922026-11-10 08:17:53.793 UTC [133] LOG: background worker "logical replication launcher" (PID 149) exited with exit code 122932026-11-10 08:17:53.804 UTC [144] LOG: shutting down22942026-11-10 08:17:53.805 UTC [144] LOG: checkpoint starting: shutdown immediate22952026-11-10 08:17:54.492 UTC [144] LOG: checkpoint complete: wrote 11026 buffers (67.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.375 s, sync=0.272 s, total=0.688 s; sync files=36061, longest=0.015 s, average=0.001 s; distance=521367 kB, estimate=521367 kB; lsn=0/2148B900, redo lsn=0/2148B90022962026-11-10 08:17:54.775 UTC [133] LOG: database system is shut down2297Running OIDC tests...2298=== RUN TestAudienceForIssuer2299=== PAUSE TestAudienceForIssuer2300=== RUN TestGlobMatch2301=== PAUSE TestGlobMatch2302=== RUN TestValidateToken_ValidToken2303=== PAUSE TestValidateToken_ValidToken2304=== RUN TestValidateToken_WrongAudience2305=== PAUSE TestValidateToken_WrongAudience2306=== RUN TestValidateToken_Expired2307=== PAUSE TestValidateToken_Expired2308=== RUN TestValidateToken_BoundClaimsMismatch2309=== PAUSE TestValidateToken_BoundClaimsMismatch2310=== RUN TestValidateToken_BoundSubjectMismatch2311=== PAUSE TestValidateToken_BoundSubjectMismatch2312=== RUN TestValidateToken_MultipleProviders2313=== PAUSE TestValidateToken_MultipleProviders2314=== RUN TestValidateToken_NoMatchingProvider2315=== PAUSE TestValidateToken_NoMatchingProvider2316=== RUN TestValidateToken_KubernetesServiceAccount2317=== PAUSE TestValidateToken_KubernetesServiceAccount2318=== RUN TestNewValidator_KubernetesRequiresCA2319=== PAUSE TestNewValidator_KubernetesRequiresCA2320=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2321=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2322=== RUN TestPins_ReservedForMatchingRule2323=== PAUSE TestPins_ReservedForMatchingRule2324=== RUN TestPins_TopLevelShorthand2325=== PAUSE TestPins_TopLevelShorthand2326=== RUN TestPins_ConfigValidation2327=== PAUSE TestPins_ConfigValidation2328=== RUN TestScopes_LegacyProviderDefaultsToWrite2329=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2330=== RUN TestScopes_Rules2331=== PAUSE TestScopes_Rules2332=== RUN TestScopes_ConfigValidation2333=== PAUSE TestScopes_ConfigValidation2334=== CONT TestAudienceForIssuer2335--- PASS: TestAudienceForIssuer (0.00s)2336=== CONT TestScopes_ConfigValidation2337--- PASS: TestScopes_ConfigValidation (0.00s)2338=== CONT TestScopes_Rules2339=== CONT TestScopes_LegacyProviderDefaultsToWrite2340=== CONT TestPins_ConfigValidation2341--- PASS: TestPins_ConfigValidation (0.00s)2342=== CONT TestPins_TopLevelShorthand2343=== CONT TestPins_ReservedForMatchingRule2344=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2345=== CONT TestNewValidator_KubernetesRequiresCA2346=== CONT TestValidateToken_KubernetesServiceAccount2347=== CONT TestValidateToken_NoMatchingProvider2348=== CONT TestValidateToken_MultipleProviders2349=== CONT TestValidateToken_BoundSubjectMismatch2350=== CONT TestValidateToken_BoundClaimsMismatch2351=== CONT TestValidateToken_Expired2352=== CONT TestValidateToken_WrongAudience2353=== CONT TestValidateToken_ValidToken2354=== CONT TestGlobMatch2355=== RUN TestGlobMatch/foo_foo2356=== PAUSE TestGlobMatch/foo_foo2357=== RUN TestGlobMatch/foo_bar2358=== PAUSE TestGlobMatch/foo_bar2359=== RUN TestGlobMatch/*_2360=== PAUSE TestGlobMatch/*_2361=== RUN TestGlobMatch/*_anything2362=== PAUSE TestGlobMatch/*_anything2363=== RUN TestGlobMatch/foo*_foo2364=== PAUSE TestGlobMatch/foo*_foo2365=== RUN TestGlobMatch/foo*_foobar2366=== PAUSE TestGlobMatch/foo*_foobar2367=== RUN TestGlobMatch/foo*_bar2368=== PAUSE TestGlobMatch/foo*_bar2369=== RUN TestGlobMatch/*bar_bar2370=== PAUSE TestGlobMatch/*bar_bar2371=== RUN TestGlobMatch/*bar_foobar2372=== PAUSE TestGlobMatch/*bar_foobar2373=== RUN TestGlobMatch/*bar_foo2374=== PAUSE TestGlobMatch/*bar_foo2375=== RUN TestGlobMatch/foo*bar_foobar2376=== PAUSE TestGlobMatch/foo*bar_foobar2377=== RUN TestGlobMatch/foo*bar_foo123bar2378=== PAUSE TestGlobMatch/foo*bar_foo123bar2379=== RUN TestGlobMatch/foo*bar_foobarbaz2380=== PAUSE TestGlobMatch/foo*bar_foobarbaz2381=== RUN TestGlobMatch/*/*_foo/bar2382=== PAUSE TestGlobMatch/*/*_foo/bar2383=== RUN TestGlobMatch/*/*_foo2384=== PAUSE TestGlobMatch/*/*_foo2385=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2386=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2387=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02388=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02389=== RUN TestGlobMatch/refs/*/main_refs/heads/main2390=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2391=== RUN TestGlobMatch/fo?_foo2392=== PAUSE TestGlobMatch/fo?_foo2393=== RUN TestGlobMatch/fo?_fo2394=== PAUSE TestGlobMatch/fo?_fo2395=== RUN TestGlobMatch/fo?_fooo2396=== PAUSE TestGlobMatch/fo?_fooo2397=== RUN TestGlobMatch/?oo_foo2398=== PAUSE TestGlobMatch/?oo_foo2399=== RUN TestGlobMatch/?oo_boo2400=== PAUSE TestGlobMatch/?oo_boo2401=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2402=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2403=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2404=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2405=== CONT TestGlobMatch/foo_foo2406=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2407=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2408=== CONT TestGlobMatch/?oo_boo2409=== CONT TestGlobMatch/?oo_foo2410=== CONT TestGlobMatch/fo?_fooo24112026/11/10 08:17:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43475/oidc2412=== CONT TestGlobMatch/fo?_fo2413=== CONT TestGlobMatch/fo?_foo2414=== CONT TestGlobMatch/refs/*/main_refs/heads/main2415=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02416=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2417=== CONT TestGlobMatch/*/*_foo2418=== CONT TestGlobMatch/*/*_foo/bar2419=== CONT TestGlobMatch/foo*bar_foobarbaz2420=== CONT TestGlobMatch/foo*bar_foo123bar2421=== CONT TestGlobMatch/foo*bar_foobar2422=== CONT TestGlobMatch/*bar_foo2423=== CONT TestGlobMatch/*bar_foobar2424=== CONT TestGlobMatch/*bar_bar2425=== CONT TestGlobMatch/foo*_bar2426=== CONT TestGlobMatch/foo*_foobar2427=== CONT TestGlobMatch/foo*_foo2428=== CONT TestGlobMatch/*_anything2429=== CONT TestGlobMatch/*_2430=== CONT TestGlobMatch/foo_bar2431--- PASS: TestGlobMatch (0.00s)2432 --- PASS: TestGlobMatch/foo_foo (0.00s)2433 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2434 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2435 --- PASS: TestGlobMatch/?oo_boo (0.00s)2436 --- PASS: TestGlobMatch/?oo_foo (0.00s)2437 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2438 --- PASS: TestGlobMatch/fo?_fo (0.00s)2439 --- PASS: TestGlobMatch/fo?_foo (0.00s)2440 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2441 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2442 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2443 --- PASS: TestGlobMatch/*/*_foo (0.00s)2444 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2445 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2446 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2447 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2448 --- PASS: TestGlobMatch/*bar_foo (0.00s)2449 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2450 --- PASS: TestGlobMatch/*bar_bar (0.00s)2451 --- PASS: TestGlobMatch/foo*_bar (0.00s)2452 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2453 --- PASS: TestGlobMatch/foo*_foo (0.00s)2454 --- PASS: TestGlobMatch/*_anything (0.00s)2455 --- PASS: TestGlobMatch/*_ (0.00s)2456 --- PASS: TestGlobMatch/foo_bar (0.00s)24572026/11/10 08:17:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42729/oidc24582026/11/10 08:17:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41693/oidc24592026/11/10 08:17:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40823/oidc2460--- PASS: TestPins_TopLevelShorthand (2.35s)2461--- PASS: TestScopes_LegacyProviderDefaultsToWrite (2.49s)2462--- PASS: TestPins_ReservedForMatchingRule (2.47s)24632026/11/10 08:17:59 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:366012464--- PASS: TestScopes_Rules (2.57s)2465--- PASS: TestValidateToken_KubernetesServiceAccount (2.51s)24662026/11/10 08:17:59 http: TLS handshake error from 127.0.0.1:50958: remote error: tls: bad certificate2467--- PASS: TestNewValidator_KubernetesRequiresCA (2.54s)24682026/11/10 08:17:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43721/oidc2469--- PASS: TestValidateToken_Expired (1.47s)24702026/11/10 08:18:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40137/oidc2471--- PASS: TestValidateToken_ValidToken (0.34s)24722026/11/10 08:18:00 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232473--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (2.70s)24742026/11/10 08:18:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33049/oidc2475--- PASS: TestValidateToken_BoundSubjectMismatch (2.50s)24762026/11/10 08:18:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35925/oidc24772026/11/10 08:18:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38691/oidc2478--- PASS: TestValidateToken_MultipleProviders (2.69s)24792026/11/10 08:18:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37369/oidc2480--- PASS: TestValidateToken_BoundClaimsMismatch (1.63s)24812026/11/10 08:18:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34175/oidc2482--- PASS: TestValidateToken_NoMatchingProvider (2.82s)24832026/11/10 08:18:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35889/oidc2484--- PASS: TestValidateToken_WrongAudience (0.54s)2485PASS2486Running hook tests...2487=== RUN TestSendPathsEmpty2488=== PAUSE TestSendPathsEmpty2489=== RUN TestQueueEnqueueAndFetch2490=== PAUSE TestQueueEnqueueAndFetch2491=== RUN TestQueueDeduplication2492=== PAUSE TestQueueDeduplication2493=== RUN TestQueueRemove2494=== PAUSE TestQueueRemove2495=== RUN TestQueueFetchBatchLimit2496=== PAUSE TestQueueFetchBatchLimit2497=== RUN TestQueueRetryMovesToBack2498=== PAUSE TestQueueRetryMovesToBack2499=== RUN TestQueueFetchRemoveLifecycle2500=== PAUSE TestQueueFetchRemoveLifecycle2501=== RUN TestQueueConcurrentWriters2502=== PAUSE TestQueueConcurrentWriters2503=== RUN TestQueueRemoveLargeClosure2504=== PAUSE TestQueueRemoveLargeClosure2505=== RUN TestServerClientIntegration2506--- PASS: TestServerClientIntegration (0.00s)2507=== RUN TestServerQueueError25082026/11/10 08:18:00 ERROR Failed to queue paths error="permission denied" count=12509--- PASS: TestServerQueueError (0.00s)2510=== RUN TestGetListenerSocketActivation2511 server_test.go:218: === RUN TestGetListenerSocketActivation2512 --- PASS: TestGetListenerSocketActivation (0.00s)2513 PASS2514 2515--- PASS: TestGetListenerSocketActivation (0.06s)2516=== RUN TestServerStalledClientDoesNotBlockShutdown2517=== PAUSE TestServerStalledClientDoesNotBlockShutdown2518=== RUN TestServerBacksOffOnAcceptErrors2519=== PAUSE TestServerBacksOffOnAcceptErrors2520=== RUN TestDrainIsolatesPoisonPath2521=== PAUSE TestDrainIsolatesPoisonPath2522=== RUN TestRunNotBlockedByPoisonHead2523=== PAUSE TestRunNotBlockedByPoisonHead2524=== RUN TestDrainGivesUpWhenServerDown2525=== PAUSE TestDrainGivesUpWhenServerDown2526=== RUN TestFailedPathPrunedByLaterClosure2527=== PAUSE TestFailedPathPrunedByLaterClosure2528=== RUN TestWorkerUploadsAndRemoves2529=== PAUSE TestWorkerUploadsAndRemoves2530=== RUN TestWorkerSkipsGCdPaths2531=== PAUSE TestWorkerSkipsGCdPaths2532=== RUN TestWorkerPrunesClosureDeps2533=== PAUSE TestWorkerPrunesClosureDeps2534=== RUN TestDrainTimeout2535=== PAUSE TestDrainTimeout2536=== RUN TestWorkerRemoveFailureIsNotProgress2537=== PAUSE TestWorkerRemoveFailureIsNotProgress2538=== RUN TestWorkerKeepsPathItCannotStat2539=== PAUSE TestWorkerKeepsPathItCannotStat2540=== CONT TestSendPathsEmpty2541=== CONT TestWorkerKeepsPathItCannotStat2542--- PASS: TestSendPathsEmpty (0.00s)2543=== CONT TestServerStalledClientDoesNotBlockShutdown2544=== CONT TestQueueRemoveLargeClosure2545=== CONT TestServerBacksOffOnAcceptErrors2546=== CONT TestQueueConcurrentWriters25472026/11/10 08:18:00 ERROR Accept failed error="too many open files"2548=== CONT TestQueueFetchRemoveLifecycle2549=== CONT TestQueueRetryMovesToBack2550=== CONT TestQueueFetchBatchLimit2551=== CONT TestQueueRemove2552=== CONT TestQueueDeduplication2553=== CONT TestQueueEnqueueAndFetch2554=== CONT TestWorkerUploadsAndRemoves25552026/11/10 08:18:00 ERROR Accept failed error="too many open files"2556=== CONT TestWorkerRemoveFailureIsNotProgress2557=== CONT TestDrainTimeout2558=== CONT TestWorkerPrunesClosureDeps2559=== CONT TestWorkerSkipsGCdPaths2560=== CONT TestDrainGivesUpWhenServerDown2561=== CONT TestFailedPathPrunedByLaterClosure2562=== CONT TestRunNotBlockedByPoisonHead2563=== CONT TestDrainIsolatesPoisonPath25642026/11/10 08:18:00 ERROR Accept failed error="too many open files"25652026/11/10 08:18:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1970148106/002/nonexistent25662026/11/10 08:18:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125672026/11/10 08:18:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1970148106/002/nonexistent25682026/11/10 08:18:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125692026/11/10 08:18:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1970148106/002/nonexistent25702026/11/10 08:18:00 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125712026/11/10 08:18:00 ERROR Drain finished with paths left in queue remaining=125722026/11/10 08:18:00 INFO Upload queue status pending=225732026/11/10 08:18:00 INFO Uploading batch count=225742026/11/10 08:18:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa: permission denied"25752026/11/10 08:18:00 INFO Upload queue status pending=325762026/11/10 08:18:00 INFO Uploading batch count=125772026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=12578--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25792026/11/10 08:18:00 INFO Upload queue status pending=225802026/11/10 08:18:00 INFO Uploading batch count=125812026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=12582--- PASS: TestQueueRetryMovesToBack (0.03s)25832026/11/10 08:18:00 INFO Uploading batch count=12584--- PASS: TestQueueEnqueueAndFetch (0.02s)25852026/11/10 08:18:00 INFO Uploading batch count=125862026/11/10 08:18:00 ERROR Accept failed error="too many open files"25872026/11/10 08:18:00 INFO Uploading batch count=225882026/11/10 08:18:00 INFO Upload queue status pending=225892026/11/10 08:18:00 INFO Uploading batch count=125902026/11/10 08:18:00 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1731025132/002/nonexistent2591--- PASS: TestQueueFetchRemoveLifecycle (0.11s)25922026/11/10 08:18:00 INFO Uploading batch count=125932026/11/10 08:18:00 INFO Uploading batch count=225942026/11/10 08:18:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa: permission denied"25952026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=225962026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/a25972026/11/10 08:18:00 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4105150203/002/locked/aaa: permission denied"2598--- PASS: TestFailedPathPrunedByLaterClosure (0.11s)25992026/11/10 08:18:00 ERROR Drain finished with paths left in queue remaining=12600--- PASS: TestQueueFetchBatchLimit (0.11s)2601--- PASS: TestWorkerUploadsAndRemoves (0.11s)26022026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/b26032026/11/10 08:18:00 INFO Uploading batch count=226042026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=22605--- PASS: TestWorkerKeepsPathItCannotStat (0.12s)2606--- PASS: TestQueueDeduplication (0.12s)26072026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/c26082026/11/10 08:18:00 INFO Uploading batch count=426092026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=426102026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/d26112026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1457044075/002/bbb26122026/11/10 08:18:00 INFO Uploading batch count=226132026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=226142026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/e26152026/11/10 08:18:00 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown125071324/002/f26162026/11/10 08:18:00 ERROR Drain finished with paths left in queue remaining=102617--- PASS: TestDrainGivesUpWhenServerDown (0.12s)2618--- PASS: TestWorkerSkipsGCdPaths (0.13s)2619--- PASS: TestWorkerPrunesClosureDeps (0.13s)26202026/11/10 08:18:00 ERROR Accept failed error="too many open files"26212026/11/10 08:18:00 ERROR Failed to decode request error="read unix /build/hook4107532389/test.sock->@: i/o timeout"26222026/11/10 08:18:00 ERROR Failed to write response error="write unix /build/hook4107532389/test.sock->@: i/o timeout"2623--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26242026/11/10 08:18:00 ERROR Upload failed error="context deadline exceeded" count=226252026/11/10 08:18:00 ERROR Drain finished with paths left in queue remaining=42626--- PASS: TestDrainTimeout (0.22s)26272026/11/10 08:18:00 ERROR Accept failed error="too many open files"26282026/11/10 08:18:00 INFO Uploading batch count=126292026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=126302026/11/10 08:18:00 INFO Uploading batch count=126312026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=12632--- PASS: TestQueueRemove (0.35s)26332026/11/10 08:18:00 INFO Uploading batch count=126342026/11/10 08:18:00 ERROR Upload failed error="upload failed" count=126352026/11/10 08:18:00 ERROR Drain finished with paths left in queue remaining=12636--- PASS: TestDrainIsolatesPoisonPath (0.34s)26372026/11/10 08:18:00 ERROR Accept failed error="too many open files"2638--- PASS: TestQueueRemoveLargeClosure (0.45s)2639--- PASS: TestQueueConcurrentWriters (0.46s)26402026/11/10 08:18:01 ERROR Accept failed error="too many open files"2641--- PASS: TestServerBacksOffOnAcceptErrors (0.71s)26422026/11/10 08:18:01 INFO Uploading batch count=126432026/11/10 08:18:01 INFO Uploading batch count=126442026/11/10 08:18:01 INFO Uploading batch count=126452026/11/10 08:18:01 ERROR Upload failed error="upload failed" count=126462026/11/10 08:18:01 INFO Uploading batch count=126472026/11/10 08:18:01 ERROR Upload failed error="upload failed" count=126482026/11/10 08:18:01 INFO Uploading batch count=126492026/11/10 08:18:01 ERROR Upload failed error="upload failed" count=126502026/11/10 08:18:01 INFO Uploading batch count=126512026/11/10 08:18:01 ERROR Upload failed error="upload failed" count=126522026/11/10 08:18:01 ERROR Drain finished with paths left in queue remaining=12653--- PASS: TestRunNotBlockedByPoisonHead (1.13s)2654PASS2655Running signing tests...2656=== RUN TestExternalSigner2657=== PAUSE TestExternalSigner2658=== RUN TestExternalSignerWrongPublicKey2659=== PAUSE TestExternalSignerWrongPublicKey2660=== RUN TestExternalSignerErrors2661=== PAUSE TestExternalSignerErrors2662=== RUN TestExternalSignerRestartsAfterCrash2663=== PAUSE TestExternalSignerRestartsAfterCrash2664=== RUN TestExternalSignerProgramErrorKeepsProcess2665=== PAUSE TestExternalSignerProgramErrorKeepsProcess2666=== RUN TestExternalSignerClose2667=== PAUSE TestExternalSignerClose2668=== RUN TestExternalSignerRejectsInvalidPublicKey2669=== PAUSE TestExternalSignerRejectsInvalidPublicKey2670=== RUN TestExternalSignerCancellation2671=== PAUSE TestExternalSignerCancellation2672=== RUN TestGenerateFingerprint2673=== PAUSE TestGenerateFingerprint2674=== RUN TestParseSigningKey2675=== PAUSE TestParseSigningKey2676=== RUN TestSign2677=== PAUSE TestSign2678=== RUN TestSignBatch2679=== PAUSE TestSignBatch2680=== RUN TestNilKeyPublicKey2681=== PAUSE TestNilKeyPublicKey2682=== RUN TestSignErrors2683=== PAUSE TestSignErrors2684=== CONT TestExternalSigner2685=== CONT TestExternalSignerProgramErrorKeepsProcess2686=== CONT TestExternalSignerRejectsInvalidPublicKey2687=== RUN TestExternalSignerRejectsInvalidPublicKey/#002688=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002689=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2690=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2691=== CONT TestExternalSignerCancellation2692=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2693=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2694=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2695=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2696=== CONT TestExternalSignerClose2697=== CONT TestExternalSignerWrongPublicKey2698=== CONT TestSignBatch2699=== CONT TestSignErrors2700=== CONT TestNilKeyPublicKey2701--- PASS: TestNilKeyPublicKey (0.00s)2702=== CONT TestParseSigningKey2703=== RUN TestParseSigningKey/valid_32-byte_key2704=== PAUSE TestParseSigningKey/valid_32-byte_key2705=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2706=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2707=== RUN TestParseSigningKey/no_colon2708=== PAUSE TestParseSigningKey/no_colon2709=== RUN TestParseSigningKey/empty_name2710=== PAUSE TestParseSigningKey/empty_name2711=== RUN TestParseSigningKey/invalid_base642712=== PAUSE TestParseSigningKey/invalid_base642713=== RUN TestParseSigningKey/wrong_length2714=== PAUSE TestParseSigningKey/wrong_length2715=== CONT TestSign2716=== CONT TestGenerateFingerprint2717=== RUN TestGenerateFingerprint/basic_with_references2718=== PAUSE TestGenerateFingerprint/basic_with_references2719=== RUN TestGenerateFingerprint/no_references2720=== PAUSE TestGenerateFingerprint/no_references2721=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2722=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2723=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2724=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2725=== RUN TestGenerateFingerprint/invalid_nar_hash_length2726=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2727=== RUN TestGenerateFingerprint/invalid_store_path_prefix2728=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2729=== CONT TestExternalSignerRestartsAfterCrash2730=== CONT TestExternalSignerErrors2731=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2732=== CONT TestParseSigningKey/valid_32-byte_key2733=== CONT TestParseSigningKey/wrong_length2734=== CONT TestParseSigningKey/invalid_base642735=== RUN TestExternalSignerErrors/exit_on_request2736=== PAUSE TestExternalSignerErrors/exit_on_request2737=== RUN TestGenerateFingerprint/invalid_reference_prefix2738=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2739=== CONT TestGenerateFingerprint/basic_with_references2740=== CONT TestParseSigningKey/no_colon2741=== CONT TestGenerateFingerprint/invalid_nar_hash_length2742=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2743=== CONT TestParseSigningKey/empty_name2744=== RUN TestExternalSignerErrors/program_error2745=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2746=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2747=== CONT TestGenerateFingerprint/no_references2748=== CONT TestGenerateFingerprint/invalid_reference_prefix2749=== CONT TestGenerateFingerprint/invalid_store_path_prefix2750--- PASS: TestGenerateFingerprint (0.00s)2751 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2752 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2753 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2754 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2755 --- PASS: TestGenerateFingerprint/no_references (0.00s)2756 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2757 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2758=== PAUSE TestExternalSignerErrors/program_error2759=== RUN TestExternalSignerErrors/null_signatures2760=== PAUSE TestExternalSignerErrors/null_signatures2761=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2762=== CONT TestExternalSignerRejectsInvalidPublicKey/#002763=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2764=== RUN TestExternalSignerErrors/wrong_signatures_shape2765=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2766=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2767=== RUN TestExternalSignerErrors/exit_at_startup2768=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2769=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2770--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2771 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2772 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2773 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2774 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2775 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2776=== PAUSE TestExternalSignerErrors/exit_at_startup2777=== RUN TestExternalSignerErrors/invalid_JSON2778=== PAUSE TestExternalSignerErrors/invalid_JSON2779=== RUN TestExternalSignerErrors/null2780=== PAUSE TestExternalSignerErrors/null2781=== RUN TestExternalSignerErrors/wrong_id2782=== PAUSE TestExternalSignerErrors/wrong_id2783=== RUN TestExternalSignerErrors/missing_signatures2784=== PAUSE TestExternalSignerErrors/missing_signatures2785=== RUN TestExternalSignerErrors/too_few_signatures2786=== PAUSE TestExternalSignerErrors/too_few_signatures2787=== RUN TestExternalSignerErrors/missing_signature_name2788=== PAUSE TestExternalSignerErrors/missing_signature_name2789=== RUN TestExternalSignerErrors/wrong_signature_name2790=== PAUSE TestExternalSignerErrors/wrong_signature_name2791=== RUN TestExternalSignerErrors/wrong_shape2792=== PAUSE TestExternalSignerErrors/wrong_shape2793=== RUN TestExternalSignerErrors/unrequested_key2794=== PAUSE TestExternalSignerErrors/unrequested_key2795=== RUN TestExternalSignerErrors/invalid_signature_base642796=== PAUSE TestExternalSignerErrors/invalid_signature_base642797=== RUN TestExternalSignerErrors/wrong_signature_length2798=== PAUSE TestExternalSignerErrors/wrong_signature_length2799=== CONT TestExternalSignerErrors/exit_on_request2800=== CONT TestExternalSignerErrors/missing_signature_name2801=== CONT TestExternalSignerErrors/missing_signatures2802=== CONT TestExternalSignerErrors/wrong_signature_length2803=== CONT TestExternalSignerErrors/wrong_signature_name2804=== RUN TestSignErrors/nil_key2805=== CONT TestExternalSignerErrors/wrong_shape2806=== CONT TestExternalSignerErrors/unrequested_key2807=== CONT TestExternalSignerErrors/null_signatures2808=== CONT TestExternalSignerErrors/program_error2809--- PASS: TestSign (0.00s)2810=== CONT TestExternalSignerErrors/exit_at_startup2811=== CONT TestExternalSignerErrors/null2812=== CONT TestExternalSignerErrors/invalid_JSON2813=== CONT TestExternalSignerErrors/wrong_id2814=== PAUSE TestSignErrors/nil_key2815=== CONT TestExternalSignerErrors/invalid_signature_base642816=== CONT TestExternalSignerErrors/wrong_signatures_shape2817=== CONT TestExternalSignerErrors/too_few_signatures2818--- PASS: TestParseSigningKey (0.00s)2819 --- PASS: TestParseSigningKey/wrong_length (0.00s)2820 --- PASS: TestParseSigningKey/no_colon (0.00s)2821 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2822 --- PASS: TestParseSigningKey/empty_name (0.00s)2823 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2824 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2825=== RUN TestSignErrors/nil_narinfo2826--- PASS: TestSignBatch (0.00s)2827=== PAUSE TestSignErrors/nil_narinfo2828=== RUN TestSignErrors/invalid_narinfo2829=== PAUSE TestSignErrors/invalid_narinfo2830=== RUN TestSignErrors/canceled2831=== PAUSE TestSignErrors/canceled2832=== CONT TestSignErrors/nil_key2833=== CONT TestSignErrors/invalid_narinfo2834=== CONT TestSignErrors/nil_narinfo2835=== CONT TestSignErrors/canceled2836--- PASS: TestSignErrors (0.00s)2837 --- PASS: TestSignErrors/nil_key (0.00s)2838 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2839 --- PASS: TestSignErrors/nil_narinfo (0.00s)2840 --- PASS: TestSignErrors/canceled (0.00s)2841--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2842--- PASS: TestExternalSignerWrongPublicKey (0.01s)2843--- PASS: TestExternalSignerClose (0.01s)2844--- PASS: TestExternalSigner (0.02s)2845--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2846--- PASS: TestExternalSignerErrors (0.00s)2847 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2848 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2849 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2850 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2851 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2852 --- PASS: TestExternalSignerErrors/null (0.02s)2853 --- PASS: TestExternalSignerErrors/null_signatures (0.02s)2854 --- PASS: TestExternalSignerErrors/wrong_id (0.02s)2855 --- PASS: TestExternalSignerErrors/unrequested_key (0.02s)2856 --- PASS: TestExternalSignerErrors/exit_at_startup (0.02s)2857 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.02s)2858 --- PASS: TestExternalSignerErrors/missing_signature_name (0.02s)2859 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.02s)2860 --- PASS: TestExternalSignerErrors/too_few_signatures (0.02s)2861 --- PASS: TestExternalSignerErrors/program_error (0.02s)2862 --- PASS: TestExternalSignerErrors/wrong_shape (0.02s)2863--- PASS: TestExternalSignerCancellation (0.02s)2864PASS2865Running OpenBao signer tests...2866=== RUN TestSign2867=== PAUSE TestSign2868=== RUN TestSignErrors2869=== PAUSE TestSignErrors2870=== RUN TestServe2871=== PAUSE TestServe2872=== RUN TestServeRejectsGarbage2873=== PAUSE TestServeRejectsGarbage2874=== CONT TestSign2875=== CONT TestServe2876=== CONT TestServeRejectsGarbage2877--- PASS: TestServeRejectsGarbage (0.00s)2878=== CONT TestSignErrors2879=== RUN TestSignErrors/http_error2880=== PAUSE TestSignErrors/http_error2881=== RUN TestSignErrors/invalid_json2882=== PAUSE TestSignErrors/invalid_json2883=== RUN TestSignErrors/no_prefix2884=== PAUSE TestSignErrors/no_prefix2885=== RUN TestSignErrors/invalid_base642886=== PAUSE TestSignErrors/invalid_base642887=== CONT TestSignErrors/http_error2888--- PASS: TestServe (0.00s)2889=== CONT TestSignErrors/invalid_base642890=== CONT TestSignErrors/no_prefix2891=== CONT TestSignErrors/invalid_json2892--- PASS: TestSign (0.01s)2893--- PASS: TestSignErrors (0.00s)2894 --- PASS: TestSignErrors/invalid_json (0.01s)2895 --- PASS: TestSignErrors/http_error (0.01s)2896 --- PASS: TestSignErrors/no_prefix (0.01s)2897 --- PASS: TestSignErrors/invalid_base64 (0.01s)2898PASS