niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #472
· 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.04s)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 TestEncodeNixBase32WithRealHash115--- PASS: TestEncodeNixBase32WithRealHash (0.00s)116=== CONT TestUploadMultipart_ReturnsAfterDroppedBody117=== CONT TestRetryTimeoutOutlastsMaxRetries118=== CONT TestScriptTokenEmptyCommand119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestStreamPushReportsSkippedPaths121=== CONT TestScriptTokenScriptFails122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing128--- PASS: TestStreamPushReportsSkippedPaths (0.00s)129=== CONT TestParsePathInfoJSON130=== RUN TestParsePathInfoJSON/Nix_format131=== CONT TestFileTokenReadsAndCaches132=== CONT TestUploadMultipart_PartsInParallel133=== PAUSE TestParsePathInfoJSON/Nix_format134=== CONT TestStaticToken135=== CONT TestSetClientTLSErrors136=== CONT TestEncodeNixBase32137=== CONT TestSetClientTLSDoesNotMutateDefaultTransport138=== CONT TestDumpPathWriterError139=== CONT TestSetClientTLS140=== CONT TestDumpPathSingleFile141=== CONT TestStreamPushStopsWhenCanceled142=== CONT TestDumpPathMatchesNix143=== CONT TestPartSizeForNAR144=== CONT TestClientSignaturesByStorePath145--- PASS: TestFileTokenMissing (0.00s)146=== CONT TestPathInfoCACompatibility147=== RUN TestPathInfoCACompatibility/null_ca_field148=== PAUSE TestPathInfoCACompatibility/null_ca_field149=== RUN TestParsePathInfoJSON/Lix_format150=== CONT TestStreamPushReportsSignatures151=== RUN TestPathInfoCACompatibility/old_string_format_-_text152=== PAUSE TestParsePathInfoJSON/Lix_format153=== RUN TestParsePathInfoJSON/empty_input154=== PAUSE TestParsePathInfoJSON/empty_input155=== RUN TestParsePathInfoJSON/whitespace_only156--- PASS: TestFileTokenEmpty (0.00s)157--- PASS: TestScriptTokenScriptFails (0.00s)158=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1592026/11/09 12:01:10 ERROR Upload failed error=boom count=1160=== CONT TestStreamPushRequestLine161=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive162--- PASS: TestStreamPushReportsSignatures (0.00s)163--- PASS: TestScriptTokenBadJSON (0.01s)1642026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:43269165--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)166=== PAUSE TestParsePathInfoJSON/whitespace_only167=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== RUN TestPathInfoCACompatibility/new_structured_format_-_text169=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text170=== CONT TestPathInfoHashCompatibility171=== CONT TestStreamPushBatchesUnderLoad172=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false173=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false174=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true175=== RUN TestEncodeNixBase32/test_string_hash176=== PAUSE TestEncodeNixBase32/test_string_hash1772026/11/09 12:01:10 ERROR Upload failed error=boom count=1178=== RUN TestEncodeNixBase32/empty_input179=== PAUSE TestEncodeNixBase32/empty_input180=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)181=== CONT TestShellSplit182=== CONT TestStreamPushReportsEveryPath183=== CONT TestShellSplitErrors184=== CONT TestConvertHashToNix32185=== RUN TestConvertHashToNix32/SRI_format_to_Nix32186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer188=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)189=== RUN TestConvertHashToNix32/already_Nix32_format190=== PAUSE TestConvertHashToNix32/already_Nix32_format191=== CONT TestDoWithRetry_FinalResponseBodyReadable192=== RUN TestParsePathInfoJSON/invalid_JSON193=== PAUSE TestParsePathInfoJSON/invalid_JSON194=== CONT TestResolveStorePath195=== RUN TestSetClientTLSErrors/missing_cert_file196=== PAUSE TestSetClientTLSErrors/missing_cert_file197=== CONT TestStreamPushGivesUpOnDeadServer198=== CONT TestGetStorePathHash199=== CONT TestStreamPushIsolatesFailures200=== CONT TestParsePathInfoJSONMultiplePaths201--- PASS: TestClientSignaturesByStorePath (0.00s)202=== RUN TestPartSizeForNAR/zero_stays_at_minimum203=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method204=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true205=== CONT TestRegisterUploadedObject_OutlivesPush206=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2072026/11/09 12:01:10 ERROR Upload failed error="connection refused" count=20208=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2092026/11/09 12:01:10 ERROR Server seems unavailable, giving up on batch untried=17210=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2112026/11/09 12:01:10 ERROR Upload failed error="bad path" count=3212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method213=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2142026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:43269215=== CONT TestRegisterUploadedObjectReusesConnections216=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun217=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2182026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=server-test rate=5219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum2222026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35591223=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum224=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum225=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts226=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts227=== CONT TestFilterOversizedClosures228=== CONT TestDoWithRetry_BodyReplayedViaGetBody2292026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=server-test rate=5230=== RUN TestPartSizeForNAR/1_TiB231=== PAUSE TestPartSizeForNAR/1_TiB232=== RUN TestPartSizeForNAR/5_TiB_S3_max_object233=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object234=== RUN TestPartSizeForNAR/capped_at_5_GiB235=== PAUSE TestPartSizeForNAR/capped_at_5_GiB2362026/11/09 12:01:10 WARN Rate limiter backed off name=server-test rate=5237=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths238=== CONT TestCaseHackSuffix2392026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=server-test rate=5240=== RUN TestSetClientTLS/rejects_connection_without_client_cert2412026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39293242=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert243=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestGetStorePathHash/valid_store_path245=== PAUSE TestGetStorePathHash/valid_store_path246=== RUN TestGetStorePathHash/basename_without_hyphen_should_error247=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error2482026/11/09 12:01:10 INFO Garbage collection started249=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error250=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error251=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error2522026/11/09 12:01:10 INFO Garbage collection started253=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2542026/11/09 12:01:10 WARN Rate limiter backed off name=server-test rate=52552026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:392932562026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:43269257=== CONT TestEncodeNixBase32/test_string_hash258=== CONT TestParsePathInfoJSON/Nix_format259=== RUN TestConvertHashToNix32/invalid_format260=== PAUSE TestConvertHashToNix32/invalid_format261=== CONT TestEncodeNixBase32/empty_input262=== CONT TestParsePathInfoJSON/invalid_JSON263=== CONT TestParsePathInfoJSON/empty_input264=== CONT TestParsePathInfoJSON/Lix_format265=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method266=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true267=== RUN TestSetClientTLSErrors/missing_key_file268=== PAUSE TestSetClientTLSErrors/missing_key_file269=== RUN TestSetClientTLSErrors/missing_ca_file270=== PAUSE TestSetClientTLSErrors/missing_ca_file271=== RUN TestSetClientTLSErrors/invalid_ca_file272=== PAUSE TestSetClientTLSErrors/invalid_ca_file273=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false274=== RUN TestFilterOversizedClosures/no_limit_keeps_everything275=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything276=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped277=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped278=== RUN TestFilterOversizedClosures/all_closures_skipped279=== PAUSE TestFilterOversizedClosures/all_closures_skipped280=== CONT TestPathInfoCACompatibility/new_structured_format_-_text281=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry282=== CONT TestRateLimiterFeedback283=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA284=== CONT TestPathInfoCACompatibility/null_ca_field285=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestPartSizeForNAR/zero_stays_at_minimum287=== CONT TestPartSizeForNAR/1_TiB288=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum289=== CONT TestPartSizeForNAR/small_stays_at_minimum290=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2912026/11/09 12:01:10 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=0292=== CONT TestPartSizeForNAR/capped_at_5_GiB293=== CONT TestGetStorePathHash/valid_store_path2942026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:43269295=== CONT TestConvertHashToNix32/SRI_format_to_Nix32296=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error297=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error298=== CONT TestGetStorePathHash/basename_without_hyphen_should_error299=== CONT TestConvertHashToNix32/already_Nix32_format300=== CONT TestSetClientTLSErrors/missing_cert_file301=== CONT TestPartSizeForNAR/5_TiB_S3_max_object302=== CONT TestFilterOversizedClosures/no_limit_keeps_everything303=== CONT TestSetClientTLSErrors/invalid_ca_file304--- PASS: TestStaticToken (0.00s)305--- PASS: TestStreamPushStopsWhenCanceled (0.00s)306--- PASS: TestDoServerRequestAttachesToken (0.02s)307=== CONT TestConvertHashToNix32/invalid_format308=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths309=== CONT TestParsePathInfoJSON/whitespace_only310=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon311=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon312=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI313=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI314=== CONT TestPathInfoCACompatibility/old_string_format_-_text315=== CONT TestSetClientTLSErrors/missing_key_file316=== RUN TestSetClientTLS/preserves_debug_logging_transport317=== PAUSE TestSetClientTLS/preserves_debug_logging_transport318=== CONT TestSetClientTLS/rejects_connection_without_client_cert319=== RUN TestRateLimiterFeedback/429_enables_limiter320=== PAUSE TestRateLimiterFeedback/429_enables_limiter321=== RUN TestRateLimiterFeedback/503_enables_limiter322=== PAUSE TestRateLimiterFeedback/503_enables_limiter323=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts324--- PASS: TestShellSplit (0.00s)325--- PASS: TestStreamPushReportsEveryPath (0.00s)326--- PASS: TestFileTokenReadsAndCaches (0.02s)327--- PASS: TestShellSplitErrors (0.00s)328--- PASS: TestScriptTokenEmptyToken (0.02s)329--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.02s)330--- PASS: TestStreamPushIsolatesFailures (0.00s)331--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)332--- PASS: TestResolveStorePath (0.00s)333--- PASS: TestRegisterUploadedObject_OutlivesPush (0.00s)334--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)335=== CONT TestFilterOversizedClosures/all_closures_skipped3362026/11/09 12:01:10 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=503372026/11/09 12:01:10 WARN Garbage collection finished on another replica. Its statistics are not available here338=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA339=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3402026/11/09 12:01:10 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=20003412026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:43269342=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512343=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512344=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)345=== CONT TestSetClientTLS/preserves_debug_logging_transport346=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI347=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512348=== CONT TestSetClientTLSErrors/missing_ca_file3492026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=s3-test rate=5350=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3512026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46167352--- PASS: TestEncodeNixBase32 (0.02s)353 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)354 --- PASS: TestEncodeNixBase32/empty_input (0.00s)355--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)356--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)357=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter358--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)359--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)360--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)361--- PASS: TestFilterOversizedClosures (0.00s)362 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)363 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)364 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)365--- PASS: TestPartSizeForNAR (0.00s)366 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)367 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)368 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)373--- PASS: TestGetStorePathHash (0.00s)374 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)376 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)377 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)378=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter379=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter380=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter381=== CONT TestRateLimiterFeedback/429_enables_limiter382=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter383--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)384=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter385=== CONT TestRateLimiterFeedback/503_enables_limiter3862026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:432693872026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=server-test rate=5388--- PASS: TestSetClientTLSErrors (0.02s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)392 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3932026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:46261394--- PASS: TestStreamPushBatchesUnderLoad (0.00s)395 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)396 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)397--- PASS: TestConvertHashToNix32 (0.00s)398 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)399 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)400 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)401--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)402 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)403 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)4042026/11/09 12:01:10 WARN Rate limiter enabled after throttle name=server-test rate=5405--- PASS: TestParsePathInfoJSON (0.02s)406 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)407 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)408 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)409 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)410 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)4112026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:41271412--- PASS: TestPathInfoCACompatibility (0.02s)413 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)414 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)415 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)416 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)417 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)418--- PASS: TestPathInfoHashCompatibility (0.01s)419 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)420 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)421 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)4232026/11/09 12:01:10 WARN Rate limiter backed off name=server-test rate=54242026/11/09 12:01:10 WARN Rate limiter backed off name=server-test rate=5425--- PASS: TestRateLimiterFeedback (0.00s)426 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)427 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)428 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)429 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)4302026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:432694312026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:432694322026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:432694332026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:432694342026/11/09 12:01:10 http: TLS handshake error from 127.0.0.1:39718: remote error: tls: bad certificate435--- PASS: TestSetClientTLS (0.01s)436 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)437 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)438 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4392026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:432694402026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:432694412026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:432694422026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:432694432026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:432694442026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:432694452026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:43269446--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4472026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:43269448--- PASS: TestStreamPushRequestLine (0.03s)4492026/11/09 12:01:10 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:43269450--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)451--- PASS: TestDumpPathSingleFile (0.03s)452--- PASS: TestCaseHackSuffix (0.03s)453--- PASS: TestDumpPathWriterError (0.06s)454--- PASS: TestDumpPathMatchesNix (0.11s)4552026/11/09 12:01:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:38261/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:38261/api/uploads/complete4562026/11/09 12:01:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4572026/11/09 12:01:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:38261/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:38261/api/uploads/complete4582026/11/09 12:01:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4592026/11/09 12:01:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:38261/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:38261/api/uploads/complete4602026/11/09 12:01:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"461--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.10s)462--- PASS: TestUploadMultipart_PartsInParallel (0.64s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)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/postgres2853015909/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/postgres2853015909/data -l logfile start492493/build/postgres2853015909:5432 - no response4942026-11-09 12:01:12.450 UTC [129] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4952026-11-09 12:01:12.450 UTC [129] LOG: listening on Unix socket "/build/postgres2853015909/.s.PGSQL.5432"4962026-11-09 12:01:12.455 UTC [136] LOG: database system was shut down at 2026-11-09 12:01:12 UTC4972026-11-09 12:01:12.458 UTC [129] LOG: database system is ready to accept connections498/build/postgres2853015909:5432 - accepting connections499{"timestamp":"2026-11-09T12:01:12.651321728Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6920ea27-b8cf-4f01-aa4b-67f9263b8bf8","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(200)"}500=== RUN TestAbortSucceeded501=== PAUSE TestAbortSucceeded502=== RUN TestService_AuthMiddleware503=== PAUSE TestService_AuthMiddleware504=== RUN TestService_AuthMiddleware_MTLSProxyHeader505=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader506=== RUN TestService_AuthMiddleware_MTLSBoundSubjects507=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects508=== RUN TestService_ReadAuthMiddleware509=== PAUSE TestService_ReadAuthMiddleware510=== RUN TestService_AuthMiddleware_OIDC511=== PAUSE TestService_AuthMiddleware_OIDC512=== RUN TestService_RequireScope_OIDC513=== PAUSE TestService_RequireScope_OIDC514=== RUN TestService_ReadScope_PublicByDefault515=== PAUSE TestService_ReadScope_PublicByDefault516=== RUN TestCacheConfigHandler517=== PAUSE TestCacheConfigHandler518=== RUN TestCacheStatsHandler519=== PAUSE TestCacheStatsHandler520=== RUN TestClientCADerivations521=== PAUSE TestClientCADerivations522=== RUN TestClientErrorHandling523=== PAUSE TestClientErrorHandling524=== RUN TestClientIntegration525=== PAUSE TestClientIntegration526=== RUN TestClientMultipleUploads527=== PAUSE TestClientMultipleUploads528=== RUN TestClientWithDependencies529=== PAUSE TestClientWithDependencies530=== RUN TestClientSharedPathCommittedMidPush531=== PAUSE TestClientSharedPathCommittedMidPush532=== RUN TestPinProtectsFromGC533=== PAUSE TestPinProtectsFromGC534=== RUN TestClientPushesUseOnePush535=== PAUSE TestClientPushesUseOnePush536=== RUN TestClientFallsBackToClosures537=== PAUSE TestClientFallsBackToClosures538=== RUN TestDeleteClosuresRacingPins539=== PAUSE TestDeleteClosuresRacingPins540=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock542=== RUN TestRetryableCompletionError543=== PAUSE TestRetryableCompletionError544=== RUN TestCompleteMultipartUploadRetriesTransientFailure545=== PAUSE TestCompleteMultipartUploadRetriesTransientFailure546=== RUN TestResolveDBConnectionString547=== PAUSE TestResolveDBConnectionString548=== RUN TestConnectWaitsForAPeerMigration549=== PAUSE TestConnectWaitsForAPeerMigration550=== RUN TestLeadElectsOneAndHandsOver551=== PAUSE TestLeadElectsOneAndHandsOver552=== RUN TestLeadIncumbentWinsAfterRestart5532026/11/09 12:01:12 INFO lead: acquired remote=192.0.2.1:12345542026/11/09 12:01:13 INFO lead: released remote=192.0.2.1:12345552026/11/09 12:01:13 INFO lead: acquired remote=192.0.2.1:12345562026/11/09 12:01:14 INFO lead: released remote=192.0.2.1:1234557--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)558=== RUN TestLeadIncumbentAnnouncesAtOnce559=== PAUSE TestLeadIncumbentAnnouncesAtOnce560=== RUN TestLeadEndsOnShutdown561=== PAUSE TestLeadEndsOnShutdown562=== RUN TestLeadEndsWhenItsConnectionHangs5632026/11/09 12:01:14 INFO lead: acquired remote=192.0.2.1:12345642026-11-09 12:01:16.144 UTC [381] FATAL: terminating connection due to administrator command5652026/11/09 12:01:16 INFO lead: acquired remote=192.0.2.1:12345662026/11/09 12:01:17 WARN lead: lock connection lost error="timeout: context deadline exceeded"5672026/11/09 12:01:17 INFO lead: released remote=192.0.2.1:12345682026/11/09 12:01:17 INFO lead: released remote=192.0.2.1:1234569--- PASS: TestLeadEndsWhenItsConnectionHangs (2.90s)570=== RUN TestGCAdvisoryLockBlocksConcurrentRun571=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun572=== RUN TestGCBugBareHashReferences573=== PAUSE TestGCBugBareHashReferences574=== RUN TestGCMetrics575=== PAUSE TestGCMetrics576=== RUN TestPushDedupSurvivesConcurrentGC577=== PAUSE TestPushDedupSurvivesConcurrentGC578=== RUN TestDeduplicatedObjectsRecordedAsPending579=== PAUSE TestDeduplicatedObjectsRecordedAsPending580=== RUN TestGCSweepSkipsPendingObjects581=== PAUSE TestGCSweepSkipsPendingObjects582=== RUN TestTombstonedObjectOfferedWithoutWaiting583=== PAUSE TestTombstonedObjectOfferedWithoutWaiting584=== RUN TestGCSweepDeliversEachKeyOnce585=== PAUSE TestGCSweepDeliversEachKeyOnce586=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection587=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection588=== RUN TestForceGCDuringPushOffersSweptObject589=== PAUSE TestForceGCDuringPushOffersSweptObject590=== RUN TestFailedS3DeleteKeepsTombstone591=== PAUSE TestFailedS3DeleteKeepsTombstone592=== RUN TestSweepSkipsRowsLockedByPush593=== PAUSE TestSweepSkipsRowsLockedByPush594=== RUN TestRegisterCompletedObjectNeedsPendingRow595=== PAUSE TestRegisterCompletedObjectNeedsPendingRow596=== RUN TestGetExistingObjectsLocksRows597=== PAUSE TestGetExistingObjectsLocksRows598=== RUN TestSweepRechecksPendingAfterLocking599=== PAUSE TestSweepRechecksPendingAfterLocking600=== RUN TestPushWaitsForSweepHoldingRow601=== PAUSE TestPushWaitsForSweepHoldingRow602=== RUN TestCommitRacingPendingCleanupKeepsObjects603=== PAUSE TestCommitRacingPendingCleanupKeepsObjects604=== RUN TestGCEndsOnShutdown605=== PAUSE TestGCEndsOnShutdown606=== RUN TestGCTaskStore_StartNew607=== PAUSE TestGCTaskStore_StartNew608=== RUN TestGCTaskStore_DeduplicateSameParams609=== PAUSE TestGCTaskStore_DeduplicateSameParams610=== RUN TestGCTaskStore_ConflictDifferentParams611=== PAUSE TestGCTaskStore_ConflictDifferentParams612=== RUN TestGCTaskStore_GetEmpty613=== PAUSE TestGCTaskStore_GetEmpty614=== RUN TestGCTaskStore_GetReturnsLatest615=== PAUSE TestGCTaskStore_GetReturnsLatest616=== RUN TestGCTaskStore_CompletedAllowsNewTask617=== PAUSE TestGCTaskStore_CompletedAllowsNewTask618=== RUN TestGCTaskStore_PhaseUpdates619=== PAUSE TestGCTaskStore_PhaseUpdates620=== RUN TestGCTaskStore_Fail621=== PAUSE TestGCTaskStore_Fail622=== RUN TestGracefulShutdownDrainsInflight623=== PAUSE TestGracefulShutdownDrainsInflight624=== RUN TestService_healthCheckHandler625=== PAUSE TestService_healthCheckHandler626=== RUN TestService_readinessHandler627=== PAUSE TestService_readinessHandler628=== RUN TestGenerateLandingPage629=== PAUSE TestGenerateLandingPage630=== RUN TestEnsureAbortUploadsRule631=== PAUSE TestEnsureAbortUploadsRule632=== RUN TestCacheConfigHandlerMaxNarSize633=== PAUSE TestCacheConfigHandlerMaxNarSize634=== RUN TestCreatePendingClosureRejectsOversizedNAR635=== PAUSE TestCreatePendingClosureRejectsOversizedNAR636=== RUN TestNARDeduplicationMetadataUploadBug637=== PAUSE TestNARDeduplicationMetadataUploadBug638=== RUN TestMetricsInventory639=== PAUSE TestMetricsInventory640=== RUN TestMetricsCommit641=== PAUSE TestMetricsCommit642=== RUN TestService_NativeMTLS643=== PAUSE TestService_NativeMTLS644=== RUN TestServerTLSConfig645=== PAUSE TestServerTLSConfig646=== RUN TestMultipartCleanup647=== PAUSE TestMultipartCleanup648=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded649=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded650=== RUN TestPendingCleanupUsesOneCutoff651=== PAUSE TestPendingCleanupUsesOneCutoff652=== RUN TestObjectStatsTrigger653=== PAUSE TestObjectStatsTrigger654=== RUN TestObjectStatsUpdatedOncePerCommit655=== PAUSE TestObjectStatsUpdatedOncePerCommit656=== RUN TestOrphanedObjectsGC657=== PAUSE TestOrphanedObjectsGC658=== RUN TestOrphanedObjectsGCStressTest659=== PAUSE TestOrphanedObjectsGCStressTest660=== RUN TestCreatePin_ReservedPins661=== PAUSE TestCreatePin_ReservedPins662=== RUN TestPresentReportsOnlyClosureRoots663=== PAUSE TestPresentReportsOnlyClosureRoots664=== RUN TestPresentRefreshesOnlyStaleClosures665=== PAUSE TestPresentRefreshesOnlyStaleClosures666=== RUN TestPresentNotReportedWhileGCDeletesClosure667=== PAUSE TestPresentNotReportedWhileGCDeletesClosure668=== RUN TestParseSingleRange669=== PAUSE TestParseSingleRange670=== RUN TestProxyHeadersOnlyTrustedOnSocket6712026/11/09 12:01:17 INFO Starting HTTP server address=127.0.0.1:463676722026/11/09 12:01:17 INFO Starting HTTP server address=proxy.sock6732026/11/09 12:01:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6742026/11/09 12:01:17 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)676=== RUN TestIsValidCachePath677=== PAUSE TestIsValidCachePath678=== RUN TestReadProxyNarinfo679=== PAUSE TestReadProxyNarinfo680=== RUN TestReadProxyNarinfoAlreadyDecompressed681=== PAUSE TestReadProxyNarinfoAlreadyDecompressed682=== RUN TestReadProxyContentNegotiation683=== PAUSE TestReadProxyContentNegotiation684=== RUN TestReadProxyNarStreaming685=== PAUSE TestReadProxyNarStreaming686=== RUN TestReadProxy404687=== PAUSE TestReadProxy404688=== RUN TestReadProxyInvalidPath689=== PAUSE TestReadProxyInvalidPath690=== RUN TestReadProxyHead691=== PAUSE TestReadProxyHead692=== RUN TestReadProxyOutlastsServerWriteTimeout693=== PAUSE TestReadProxyOutlastsServerWriteTimeout694=== RUN TestReadProxyConditionalGet695=== PAUSE TestReadProxyConditionalGet696=== RUN TestReadProxyRootRedirectsToIndexHTML697=== PAUSE TestReadProxyRootRedirectsToIndexHTML698=== RUN TestReadProxyDisabled699=== PAUSE TestReadProxyDisabled700=== RUN TestReadRedirectNar701=== PAUSE TestReadRedirectNar702=== RUN TestReadRedirectKeepsNarinfoProxied703=== PAUSE TestReadRedirectKeepsNarinfoProxied704=== RUN TestReadProxyRangeRequest705=== PAUSE TestReadProxyRangeRequest706=== RUN TestReadRedirectUsesPublicS3URL707=== PAUSE TestReadRedirectUsesPublicS3URL708=== RUN TestPush_OverlappingRootsStoreOneRowPerKey709=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey710=== RUN TestPush_CompleteCommitsEveryRoot711=== PAUSE TestPush_CompleteCommitsEveryRoot712=== RUN TestPush_RepeatedRootCommitsOnce713=== PAUSE TestPush_RepeatedRootCommitsOnce714=== RUN TestPush_CompleteWaitsForCleanupOfThePush715=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush716=== RUN TestPush_RootsAreLockedInByteOrder717=== PAUSE TestPush_RootsAreLockedInByteOrder718=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit719=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit720=== RUN TestPush_RejectsBadRequests721=== PAUSE TestPush_RejectsBadRequests722=== RUN TestPush_SignsNarinfosOfItsPendingObjects723=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects724=== RUN TestSharedNarBothUploadsComplete725=== PAUSE TestSharedNarBothUploadsComplete726=== RUN TestCompleteMultipartUpload_ErrorButObjectExists727=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists728=== RUN TestCompletedNarNotReofferedAcrossClosures729=== PAUSE TestCompletedNarNotReofferedAcrossClosures730=== RUN TestPresignedUploadRegisteredBeforeCommit731=== PAUSE TestPresignedUploadRegisteredBeforeCommit732=== RUN TestService_Rustfstest733=== PAUSE TestService_Rustfstest734=== RUN TestParseSize735=== PAUSE TestParseSize736=== RUN TestSkippedUploadsHandler737=== PAUSE TestSkippedUploadsHandler738=== RUN TestSystemdListenerNotActivated739--- PASS: TestSystemdListenerNotActivated (0.00s)740=== RUN TestWatchdogBeatsWhenHealthy741--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)742=== RUN TestWatchdogSkipsWhenUnhealthy7432026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/09 12:01:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"753--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)754=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle755=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle756=== RUN TestProxyWriteTimeout757=== PAUSE TestProxyWriteTimeout758=== RUN TestPendingClosureWriteTimeout759=== PAUSE TestPendingClosureWriteTimeout760=== RUN TestIsValidUploadKey761=== PAUSE TestIsValidUploadKey762=== RUN TestUploadHandlersRejectInvalidKeys763=== PAUSE TestUploadHandlersRejectInvalidKeys764=== RUN TestUploadHandlersRejectOversizedBody765=== PAUSE TestUploadHandlersRejectOversizedBody766=== RUN TestService_cleanupPendingClosuresHandler767=== PAUSE TestService_cleanupPendingClosuresHandler768=== RUN TestService_createPendingClosureHandler769=== PAUSE TestService_createPendingClosureHandler770=== RUN TestService_verifyS3Integrity771=== PAUSE TestService_verifyS3Integrity772=== RUN TestService_verifyS3ReuploadsStaleNarinfo773=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo774=== RUN TestCompleteMultipartUnregistered775=== PAUSE TestCompleteMultipartUnregistered776=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT777=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT778=== CONT TestSkippedUploadsHandler779=== CONT TestPush_RootsAreLockedInByteOrder780=== CONT TestAbortSucceeded781--- PASS: TestAbortSucceeded (0.00s)782=== CONT TestService_verifyS3Integrity783=== CONT TestReadProxyRangeRequest7842026/11/09 12:01:17 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000785=== CONT TestParseSize786--- PASS: TestParseSize (0.00s)787=== CONT TestReadRedirectKeepsNarinfoProxied788=== CONT TestService_Rustfstest789=== CONT TestPresignedUploadRegisteredBeforeCommit790=== CONT TestCompletedNarNotReofferedAcrossClosures791=== CONT TestCompleteMultipartUpload_ErrorButObjectExists792=== CONT TestSharedNarBothUploadsComplete793=== CONT TestService_cleanupPendingClosuresHandler794=== CONT TestPush_SignsNarinfosOfItsPendingObjects795=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT796=== CONT TestPush_RejectsBadRequests797=== CONT TestCompleteMultipartUnregistered798=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit799=== CONT TestService_verifyS3ReuploadsStaleNarinfo800=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed801=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed802=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed803=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed804=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost805=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost806=== CONT TestService_createPendingClosureHandler807=== CONT TestGCTaskStore_GetEmpty808=== CONT TestPush_CompleteWaitsForCleanupOfThePush809=== CONT TestPush_RepeatedRootCommitsOnce810=== CONT TestPush_CompleteCommitsEveryRoot811=== CONT TestPush_OverlappingRootsStoreOneRowPerKey812=== CONT TestReadRedirectUsesPublicS3URL813--- PASS: TestSkippedUploadsHandler (0.00s)814=== CONT TestReadRedirectNar815--- PASS: TestGCTaskStore_GetEmpty (0.00s)816=== CONT TestReadProxyDisabled817=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed818=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed819=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed820=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed821=== CONT TestReadProxyRootRedirectsToIndexHTML8222026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures8232026/11/09 12:01:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8242026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures825--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.31s)826=== CONT TestReadProxyConditionalGet827--- PASS: TestReadProxyRangeRequest (0.32s)828=== CONT TestReadProxyOutlastsServerWriteTimeout8292026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures8302026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes831--- PASS: TestService_Rustfstest (0.36s)832=== CONT TestReadProxyHead8332026-11-09 12:01:18.250 UTC [498] ERROR: could not obtain lock on row in relation "closures"8342026-11-09 12:01:18.250 UTC [498] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8352026-11-09 12:01:18.250 UTC [498] ERROR: could not obtain lock on row in relation "closures"8362026-11-09 12:01:18.250 UTC [498] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8372026-11-09 12:01:18.251 UTC [498] ERROR: could not obtain lock on row in relation "closures"8382026-11-09 12:01:18.251 UTC [498] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8392026-11-09 12:01:18.251 UTC [498] ERROR: could not obtain lock on row in relation "closures"8402026-11-09 12:01:18.251 UTC [498] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8412026-11-09 12:01:18.251 UTC [498] ERROR: could not obtain lock on row in relation "closures"8422026-11-09 12:01:18.251 UTC [498] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8432026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures844--- PASS: TestPush_RootsAreLockedInByteOrder (0.38s)845=== CONT TestReadProxyInvalidPath8462026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8472026/11/09 12:01:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjBiYWFmOGYzLWZkZmItNDY0MS1hNjY4LWFlZTBkYzJjOGZjZXgxNzk0MjI1Njc4MjYxNTQwODk08482026/11/09 12:01:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjBiYWFmOGYzLWZkZmItNDY0MS1hNjY4LWFlZTBkYzJjOGZjZXgxNzk0MjI1Njc4MjYxNTQwODk0 parts=1849--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.42s)850=== CONT TestIsValidUploadKey851=== RUN TestIsValidUploadKey/narinfo852=== PAUSE TestIsValidUploadKey/narinfo853=== RUN TestIsValidUploadKey/nar_zst854=== PAUSE TestIsValidUploadKey/nar_zst855=== RUN TestIsValidUploadKey/nar_xz856=== PAUSE TestIsValidUploadKey/nar_xz857=== RUN TestIsValidUploadKey/nar_plain858=== PAUSE TestIsValidUploadKey/nar_plain859=== RUN TestIsValidUploadKey/listing860=== PAUSE TestIsValidUploadKey/listing861=== RUN TestIsValidUploadKey/build_log862=== PAUSE TestIsValidUploadKey/build_log863=== RUN TestIsValidUploadKey/build_log_home-manager_file864=== PAUSE TestIsValidUploadKey/build_log_home-manager_file865=== RUN TestIsValidUploadKey/build_log_plus_in_name866=== PAUSE TestIsValidUploadKey/build_log_plus_in_name867=== RUN TestIsValidUploadKey/build_log_question_mark868=== PAUSE TestIsValidUploadKey/build_log_question_mark869=== RUN TestIsValidUploadKey/build_log_equals870=== PAUSE TestIsValidUploadKey/build_log_equals871=== RUN TestIsValidUploadKey/realisation872=== PAUSE TestIsValidUploadKey/realisation873=== RUN TestIsValidUploadKey/realisation_plus_in_output874=== PAUSE TestIsValidUploadKey/realisation_plus_in_output875=== RUN TestIsValidUploadKey/nix-cache-info876=== PAUSE TestIsValidUploadKey/nix-cache-info877=== RUN TestIsValidUploadKey/index.html878=== PAUSE TestIsValidUploadKey/index.html879=== RUN TestIsValidUploadKey/narinfo_key,_nar_type880=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type881=== RUN TestIsValidUploadKey/nar_key,_narinfo_type882=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type883=== RUN TestIsValidUploadKey/listing_key,_narinfo_type884=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type885=== RUN TestIsValidUploadKey/traversal886=== PAUSE TestIsValidUploadKey/traversal887=== RUN TestIsValidUploadKey/traversal_nar888=== PAUSE TestIsValidUploadKey/traversal_nar889=== RUN TestIsValidUploadKey/absolute890=== PAUSE TestIsValidUploadKey/absolute891=== RUN TestIsValidUploadKey/empty_key892=== PAUSE TestIsValidUploadKey/empty_key893=== RUN TestIsValidUploadKey/unknown_type894=== PAUSE TestIsValidUploadKey/unknown_type895=== CONT TestUploadHandlersRejectOversizedBody896--- PASS: TestReadRedirectKeepsNarinfoProxied (0.42s)897=== CONT TestReadProxy4048982026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures8992026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes9002026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9012026/11/09 12:01:18 INFO Signed narinfos id=1 count=19022026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9032026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9042026/11/09 12:01:18 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9052026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9062026/11/09 12:01:18 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9072026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9082026/11/09 12:01:18 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19092026/11/09 12:01:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9102026/11/09 12:01:18 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo911--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.46s)912=== CONT TestUploadHandlersRejectInvalidKeys913=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info914=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info915=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal916=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal917=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key918=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key919=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key920=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key921=== CONT TestReadProxyNarStreaming9222026/11/09 12:01:18 INFO Received cleanup request method=DELETE path=/api/pending_closures9232026/11/09 12:01:18 INFO Aborted multipart uploads count=0 kept=09242026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9252026/11/09 12:01:18 INFO Received cleanup request method=DELETE path=/api/pending_closures9262026/11/09 12:01:18 INFO Aborted multipart uploads count=1 kept=09272026/11/09 12:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9282026-11-09 12:01:18.360 UTC [468] ERROR: Closure does not exist: id=19292026-11-09 12:01:18.360 UTC [468] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9302026-11-09 12:01:18.360 UTC [468] STATEMENT: -- name: CommitPendingClosure :one931 SELECT commit_pending_closure($1::bigint)::bigint932 933--- PASS: TestService_cleanupPendingClosuresHandler (0.49s)934=== CONT TestReadProxyContentNegotiation9352026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes9362026/11/09 12:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete937--- PASS: TestReadProxyDisabled (0.51s)938=== CONT TestService_NativeMTLS9392026/11/09 12:01:18 INFO Completed push id=1 objects=4 duration=10.04395ms9402026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes941--- PASS: TestReadRedirectUsesPublicS3URL (0.55s)942=== CONT TestServerTLSConfig943=== RUN TestServerTLSConfig/no_client_CA944=== PAUSE TestServerTLSConfig/no_client_CA945=== RUN TestServerTLSConfig/missing_CA_file946=== PAUSE TestServerTLSConfig/missing_CA_file947=== RUN TestServerTLSConfig/not_a_PEM_file948=== PAUSE TestServerTLSConfig/not_a_PEM_file949=== CONT TestMetricsCommit950--- PASS: TestReadRedirectNar (0.56s)951=== CONT TestMetricsInventory952=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart953=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart954=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts955=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts956=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure957=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure958=== CONT TestReadProxyNarinfoAlreadyDecompressed959=== RUN TestPush_RejectsBadRequests/no_objects960=== PAUSE TestPush_RejectsBadRequests/no_objects961=== RUN TestPush_RejectsBadRequests/bad_root962=== PAUSE TestPush_RejectsBadRequests/bad_root963=== RUN TestPush_RejectsBadRequests/root_not_in_objects964=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects965=== RUN TestPush_RejectsBadRequests/no_roots966=== PAUSE TestPush_RejectsBadRequests/no_roots967=== CONT TestNARDeduplicationMetadataUploadBug9682026/11/09 12:01:18 INFO Aborted multipart uploads count=0 kept=09692026/11/09 12:01:18 WARN Force mode enabled - objects will be deleted immediately without grace period9702026/11/09 12:01:18 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=09712026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes9722026/11/09 12:01:18 INFO Vacuumed table table=pending_closures9732026/11/09 12:01:18 INFO Vacuumed table table=pending_objects9742026/11/09 12:01:18 INFO Vacuumed table table=multipart_uploads9752026/11/09 12:01:18 INFO Vacuumed table table=closures9762026/11/09 12:01:18 INFO Vacuumed table table=objects9772026/11/09 12:01:18 INFO Received complete push request method=POST path=/api/pushes/2/complete9782026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9792026/11/09 12:01:18 INFO Completed push id=2 objects=4 duration=9.728188ms980--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.62s)981=== CONT TestReadProxyNarinfo9822026/11/09 12:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete9832026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9842026/11/09 12:01:18 INFO Completed push id=1 objects=4 duration=10.591035ms985--- PASS: TestPush_RepeatedRootCommitsOnce (0.63s)986=== CONT TestCreatePendingClosureRejectsOversizedNAR9872026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures988--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)989=== CONT TestOrphanedObjectsGC9902026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes9912026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes992--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.68s)993=== CONT TestCacheConfigHandlerMaxNarSize994--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)995=== CONT TestObjectStatsUpdatedOncePerCommit9962026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9972026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9982026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures9992026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10002026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes10012026/11/09 12:01:18 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjQyMTJkMGMyLTgyZjQtNDNhNS1hNTgyLWE2NGFmY2Q5NThhZngxNzk0MjI1Njc4MjA1OTMxMDU0 parts=1210022026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.72s)1004=== CONT TestEnsureAbortUploadsRule10052026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10062026/11/09 12:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete10072026/11/09 12:01:18 INFO Completed push id=1 objects=6 duration=10.272233ms1008--- PASS: TestPush_CompleteCommitsEveryRoot (0.74s)1009=== CONT TestObjectStatsTrigger1010--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.74s)1011=== CONT TestGenerateLandingPage1012--- PASS: TestGenerateLandingPage (0.00s)1013=== CONT TestPendingCleanupUsesOneCutoff10142026/11/09 12:01:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjZhN2U3ZDA3LTNhM2MtNGJkNC1iZDYyLTAwMTI4NmM1YjZjNngxNzk0MjI1Njc4MzA0NTk1MTAx parts=1010152026/11/09 12:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10162026/11/09 12:01:18 INFO Completed upload id=1 objects=2 duration=3.194709ms10172026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures10182026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures10192026/11/09 12:01:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10202026/11/09 12:01:18 WARN Found objects in DB but missing from S3, will re-upload count=11021--- PASS: TestService_verifyS3Integrity (0.76s)1022=== CONT TestOrphanedObjectsGCStressTest10232026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures1024--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.77s)1025=== CONT TestService_readinessHandler10262026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10272026/11/09 12:01:18 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1028--- PASS: TestCompleteMultipartUnregistered (0.78s)1029=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1030--- PASS: TestReadProxyConditionalGet (0.51s)1031=== CONT TestIsValidCachePath1032=== RUN TestIsValidCachePath/narinfo1033=== PAUSE TestIsValidCachePath/narinfo1034=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1035=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1036=== RUN TestIsValidCachePath/nar_zst1037=== PAUSE TestIsValidCachePath/nar_zst1038=== RUN TestIsValidCachePath/nar_xz1039=== PAUSE TestIsValidCachePath/nar_xz1040=== RUN TestIsValidCachePath/nar_bz21041=== PAUSE TestIsValidCachePath/nar_bz21042=== RUN TestIsValidCachePath/nar_uncompressed1043=== PAUSE TestIsValidCachePath/nar_uncompressed1044=== RUN TestIsValidCachePath/ls1045=== PAUSE TestIsValidCachePath/ls1046=== RUN TestIsValidCachePath/log1047=== PAUSE TestIsValidCachePath/log1048=== RUN TestIsValidCachePath/realisation1049=== PAUSE TestIsValidCachePath/realisation1050=== RUN TestIsValidCachePath/nix-cache-info1051=== PAUSE TestIsValidCachePath/nix-cache-info1052=== RUN TestIsValidCachePath/index.html1053=== PAUSE TestIsValidCachePath/index.html1054=== RUN TestIsValidCachePath/traversal_parent1055=== PAUSE TestIsValidCachePath/traversal_parent1056=== RUN TestIsValidCachePath/traversal_in_middle1057=== PAUSE TestIsValidCachePath/traversal_in_middle1058=== RUN TestIsValidCachePath/invalid_char_e1059=== PAUSE TestIsValidCachePath/invalid_char_e1060=== RUN TestIsValidCachePath/invalid_char_u1061=== PAUSE TestIsValidCachePath/invalid_char_u1062=== RUN TestIsValidCachePath/random_path1063=== PAUSE TestIsValidCachePath/random_path1064=== RUN TestIsValidCachePath/empty1065=== PAUSE TestIsValidCachePath/empty1066=== RUN TestIsValidCachePath/leading_slash1067=== PAUSE TestIsValidCachePath/leading_slash1068=== RUN TestIsValidCachePath/wrong_extension1069=== PAUSE TestIsValidCachePath/wrong_extension1070=== RUN TestIsValidCachePath/short_hash1071=== PAUSE TestIsValidCachePath/short_hash1072=== CONT TestMultipartCleanup1073--- PASS: TestReadProxyHead (0.51s)1074=== CONT TestParseSingleRange1075=== RUN TestParseSingleRange/none1076=== PAUSE TestParseSingleRange/none1077=== RUN TestParseSingleRange/unknown_unit1078=== PAUSE TestParseSingleRange/unknown_unit1079=== RUN TestParseSingleRange/multi-range_ignored1080=== PAUSE TestParseSingleRange/multi-range_ignored1081=== RUN TestParseSingleRange/malformed_no_dash1082=== PAUSE TestParseSingleRange/malformed_no_dash1083=== RUN TestParseSingleRange/malformed_both_empty1084=== PAUSE TestParseSingleRange/malformed_both_empty1085=== RUN TestParseSingleRange/malformed_end_before_start1086=== PAUSE TestParseSingleRange/malformed_end_before_start1087=== RUN TestParseSingleRange/closed1088=== PAUSE TestParseSingleRange/closed1089=== RUN TestParseSingleRange/open-ended1090=== PAUSE TestParseSingleRange/open-ended1091=== RUN TestParseSingleRange/end_clamped_to_size1092=== PAUSE TestParseSingleRange/end_clamped_to_size1093=== RUN TestParseSingleRange/suffix1094=== PAUSE TestParseSingleRange/suffix1095=== RUN TestParseSingleRange/suffix_exceeds_size1096=== PAUSE TestParseSingleRange/suffix_exceeds_size1097=== RUN TestParseSingleRange/single_byte1098=== PAUSE TestParseSingleRange/single_byte1099=== RUN TestParseSingleRange/start_past_EOF1100=== PAUSE TestParseSingleRange/start_past_EOF1101=== RUN TestParseSingleRange/start_far_past_EOF1102=== PAUSE TestParseSingleRange/start_far_past_EOF1103=== CONT TestService_healthCheckHandler1104--- PASS: TestReadProxyInvalidPath (0.51s)1105=== CONT TestPresentNotReportedWhileGCDeletesClosure1106=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1107=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1108=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1109=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1110=== CONT TestGCTaskStore_PhaseUpdates1111--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1112=== CONT TestGCTaskStore_CompletedAllowsNewTask1113--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1114=== CONT TestPresentRefreshesOnlyStaleClosures1115--- PASS: TestReadProxyNarStreaming (0.48s)1116=== CONT TestGCTaskStore_GetReturnsLatest1117--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1118=== CONT TestPresentReportsOnlyClosureRoots1119--- PASS: TestReadProxy404 (0.53s)1120=== CONT TestCreatePin_ReservedPins11212026-11-09 12:01:18.833 UTC [539] ERROR: Push does not exist: id=111222026-11-09 12:01:18.833 UTC [539] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11232026-11-09 12:01:18.833 UTC [539] STATEMENT: SELECT commit_push($1)1124--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.96s)1125=== CONT TestProxyWriteTimeout1126=== RUN TestProxyWriteTimeout/narinfo1127=== PAUSE TestProxyWriteTimeout/narinfo1128=== RUN TestProxyWriteTimeout/1_GiB_nar1129=== PAUSE TestProxyWriteTimeout/1_GiB_nar1130=== RUN TestProxyWriteTimeout/10_GiB_nar1131=== PAUSE TestProxyWriteTimeout/10_GiB_nar1132=== RUN TestProxyWriteTimeout/unknown_size1133=== PAUSE TestProxyWriteTimeout/unknown_size1134=== CONT TestGracefulShutdownDrainsInflight11352026/11/09 12:01:18 INFO Starting HTTP server address=127.0.0.1:4493311362026/11/09 12:01:18 INFO Shutdown signal received, draining in-flight requests timeout=10s11372026/11/09 12:01:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11382026/11/09 12:01:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1139--- PASS: TestService_NativeMTLS (0.46s)1140=== CONT TestPendingClosureWriteTimeout1141=== RUN TestPendingClosureWriteTimeout/empty1142=== PAUSE TestPendingClosureWriteTimeout/empty1143=== RUN TestPendingClosureWriteTimeout/400_objects1144=== PAUSE TestPendingClosureWriteTimeout/400_objects1145=== RUN TestPendingClosureWriteTimeout/670k_objects1146=== PAUSE TestPendingClosureWriteTimeout/670k_objects1147=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1148=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1149=== CONT TestGCTaskStore_Fail1150--- PASS: TestGCTaskStore_Fail (0.00s)1151=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11522026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11532026/11/09 12:01:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11542026/11/09 12:01:18 INFO Received push request method=POST path=/api/pushes11552026/11/09 12:01:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjU4YzljMTY5LTdiNWMtNGRkNS04ZTFlLWRlYjQ4YmI1NzQ2OHgxNzk0MjI1Njc4NTAwNDE4ODM5 parts=1211562026/11/09 12:01:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LmE0MGVjYzg3LWRhOTEtNGJlYS1iZDI4LWE5OTkzOGRlMWE2OXgxNzk0MjI1Njc4NTcwMTQzOTg2 parts=1011572026/11/09 12:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11582026/11/09 12:01:18 INFO Completed upload id=1 objects=2 duration=3.028347ms11592026/11/09 12:01:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001160--- PASS: TestReadProxyContentNegotiation (0.52s)1161=== CONT TestLeadElectsOneAndHandsOver11622026/11/09 12:01:18 INFO Received uploads request method=POST path=/api/pending_closures11632026/11/09 12:01:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures11642026/11/09 12:01:18 INFO Received complete push request method=POST path=/api/pushes/1/complete11652026/11/09 12:01:18 INFO Aborted multipart uploads count=0 kept=01166--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1167=== CONT TestGCTaskStore_ConflictDifferentParams1168--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1169=== CONT TestClientMultipleUploads11702026/11/09 12:01:18 INFO Completed push id=1 objects=4 duration=10.551814ms11712026/11/09 12:01:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11722026/11/09 12:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33141/oidc1173--- PASS: TestMetricsInventory (0.47s)1174=== CONT TestForceGCDuringPushOffersSweptObject1175=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1176=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1177=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1178=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1179=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11802026/11/09 12:01:18 INFO Completed upload id=2 objects=2 duration=1.412513ms11812026/11/09 12:01:18 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=01182--- PASS: TestMetricsCommit (0.49s)1183=== CONT TestConnectWaitsForAPeerMigration11842026/11/09 12:01:18 INFO Vacuumed table table=pending_closures11852026/11/09 12:01:18 INFO Vacuumed table table=pending_objects11862026/11/09 12:01:18 INFO Vacuumed table table=multipart_uploads11872026/11/09 12:01:18 INFO Vacuumed table table=closures11882026/11/09 12:01:18 INFO Vacuumed table table=objects1189--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1190=== CONT TestGCSweepDeliversEachKeyOnce11912026/11/09 12:01:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001192--- PASS: TestService_createPendingClosureHandler (1.06s)1193=== CONT TestGCTaskStore_DeduplicateSameParams1194--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1195=== CONT TestResolveDBConnectionString1196=== RUN TestResolveDBConnectionString/flag_wins1197=== PAUSE TestResolveDBConnectionString/flag_wins1198=== RUN TestResolveDBConnectionString/file_when_flag_empty1199=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1200=== RUN TestResolveDBConnectionString/missing_file_is_an_error1201=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1202=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1203=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1204=== RUN TestResolveDBConnectionString/nothing_configured1205=== PAUSE TestResolveDBConnectionString/nothing_configured1206=== CONT TestGCTaskStore_StartNew1207--- PASS: TestGCTaskStore_StartNew (0.00s)1208=== CONT TestTombstonedObjectOfferedWithoutWaiting1209=== NAME TestNARDeduplicationMetadataUploadBug1210 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug241202316/001/store/qdr24hlqmsf129l2pf7wqy0i3wwimc9w-file1.txt12112026/11/09 12:01:19 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1212--- PASS: TestReadProxyNarinfo (0.70s)1213=== CONT TestGCEndsOnShutdown1214=== RUN TestGCEndsOnShutdown/before_the_run1215=== PAUSE TestGCEndsOnShutdown/before_the_run1216=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1217=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1218=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1219=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1220=== CONT TestCompleteMultipartUploadRetriesTransientFailure12212026/11/09 12:01:19 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket43 days=21222--- PASS: TestObjectStatsUpdatedOncePerCommit (0.64s)1223=== CONT TestGCSweepSkipsPendingObjects1224--- PASS: TestEnsureAbortUploadsRule (0.61s)1225=== CONT TestCommitRacingPendingCleanupKeepsObjects12262026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures12272026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes12282026/11/09 12:01:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12292026/11/09 12:01:19 INFO Uploading qdr24hlqmsf129l2pf7wqy0i3wwimc9w-file1.txt (160B)12302026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures12312026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12322026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12332026/11/09 12:01:19 WARN Failed to register uploaded object key=qdr24hlqmsf129l2pf7wqy0i3wwimc9w.ls error="server returned 404: 404 page not found\n"12342026/11/09 12:01:19 INFO Signed narinfos id=1 count=112352026/11/09 12:01:19 INFO Uploading 1 narinfos12362026/11/09 12:01:19 INFO Received cleanup request method=DELETE path=/api/pending_closures12372026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/1/complete12382026/11/09 12:01:19 WARN Failed to register uploaded object key=qdr24hlqmsf129l2pf7wqy0i3wwimc9w.narinfo error="server returned 404: 404 page not found\n"12392026/11/09 12:01:19 INFO Completed push id=1 objects=3 duration=6.293696ms12402026/11/09 12:01:19 INFO Upload complete. (64ms)1241=== NAME TestNARDeduplicationMetadataUploadBug1242 metadata_upload_test.go:54: Retrieved narinfo from S3:1243 StorePath: /build/TestNARDeduplicationMetadataUploadBug241202316/001/store/qdr24hlqmsf129l2pf7wqy0i3wwimc9w-file1.txt1244 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1245 Compression: zstd1246 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1247 NarSize: 1601248 References: 1249 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1250 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1251 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1252 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1253--- PASS: TestObjectStatsTrigger (0.63s)1254=== CONT TestClientPushesUseOnePush12552026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures1256=== NAME TestNARDeduplicationMetadataUploadBug1257 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug241202316/001/store/b9dh6a3hsm81q7kdb3af8dmxpi13kkrl-file2.txt1258--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.63s)1259=== CONT TestDeduplicatedObjectsRecordedAsPending12602026/11/09 12:01:19 WARN readiness check failed error="closed pool"1261--- PASS: TestService_readinessHandler (0.65s)1262=== CONT TestPushWaitsForSweepHoldingRow12632026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures1264=== NAME TestOrphanedObjectsGC1265 orphaned_objects_gc_test.go:287: GC Test Summary:1266 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1267 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1268 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1269 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1270 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1271--- PASS: TestOrphanedObjectsGC (0.81s)1272=== CONT TestPinProtectsFromGC1273--- PASS: TestService_healthCheckHandler (0.60s)1274=== CONT TestPushDedupSurvivesConcurrentGC12752026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes12762026/11/09 12:01:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12772026/11/09 12:01:19 WARN Failed to register uploaded object key=b9dh6a3hsm81q7kdb3af8dmxpi13kkrl.ls error="server returned 404: 404 page not found\n"12782026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12792026/11/09 12:01:19 INFO Signed narinfos id=2 count=112802026/11/09 12:01:19 INFO Uploading 1 narinfos12812026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/2/complete12822026/11/09 12:01:19 WARN Failed to register uploaded object key=b9dh6a3hsm81q7kdb3af8dmxpi13kkrl.narinfo error="server returned 404: 404 page not found\n"12832026/11/09 12:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/11/09 12:01:19 INFO Completed push id=2 objects=3 duration=9.437445ms12852026/11/09 12:01:19 INFO Upload complete. (61ms)1286=== NAME TestNARDeduplicationMetadataUploadBug1287 metadata_upload_test.go:76: Retrieved narinfo from S3:1288 StorePath: /build/TestNARDeduplicationMetadataUploadBug241202316/001/store/b9dh6a3hsm81q7kdb3af8dmxpi13kkrl-file2.txt1289 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1290 Compression: zstd1291 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1292 NarSize: 1601293 References: 1294 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1295 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1296 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1297 {"version":1,"root":{"type":"regular","size":44}}1298--- PASS: TestPresentRefreshesOnlyStaleClosures (0.61s)1299=== CONT TestSweepRechecksPendingAfterLocking1300--- PASS: TestNARDeduplicationMetadataUploadBug (0.93s)1301=== CONT TestClientSharedPathCommittedMidPush13022026/11/09 12:01:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjRlNGE0MjQyLTAyMzktNDUyMS1iZWFlLWVjZTM4ZWYxYzkzM3gxNzk0MjI1Njc4NTA3OTk3Mzg3 parts=121303--- PASS: TestSharedNarBothUploadsComplete (1.51s)1304=== CONT TestGCMetrics1305--- PASS: TestPresentReportsOnlyClosureRoots (0.58s)1306=== CONT TestGetExistingObjectsLocksRows13072026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures13082026/11/09 12:01:19 INFO lead: acquired remote=192.0.2.1:123413092026/11/09 12:01:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13102026/11/09 12:01:19 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket49/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13112026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=113122026/11/09 12:01:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13132026/11/09 12:01:19 INFO Aborted multipart uploads count=1 kept=01314--- PASS: TestMultipartCleanup (0.76s)1315=== CONT TestGCBugBareHashReferences13162026/11/09 12:01:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13172026/11/09 12:01:19 WARN Refused reserved pin name=worker-x86_64-linux13182026/11/09 12:01:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13192026/11/09 12:01:19 INFO Received create pin request method=POST path=/api/pins/my-app13202026/11/09 12:01:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1321--- PASS: TestCreatePin_ReservedPins (0.64s)1322=== CONT TestClientWithDependencies13232026/11/09 12:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13242026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures1325=== NAME TestClientMultipleUploads1326 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads2213470423/001/store/8qcz8519hf04gn9hd46d6i93fzvhk42q-test-file-0.txt13272026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures1328--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.61s)1329=== CONT TestGCAdvisoryLockBlocksConcurrentRun13302026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=013312026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period1332=== NAME TestClientMultipleUploads1333 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads2213470423/001/store/bjcayyfg8fwrv1qf0bi1nv3q5ds2d9gb-test-file-1.txt13342026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures13352026/11/09 12:01:19 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=013362026/11/09 12:01:19 INFO Vacuumed table table=pending_closures13372026/11/09 12:01:19 INFO Vacuumed table table=pending_objects13382026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads13392026/11/09 12:01:19 INFO Vacuumed table table=closures13402026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures13412026/11/09 12:01:19 INFO Vacuumed table table=objects1342--- PASS: TestGCSweepDeliversEachKeyOnce (0.67s)1343=== CONT TestRegisterCompletedObjectNeedsPendingRow1344=== NAME TestClientMultipleUploads1345 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads2213470423/001/store/mfilp3af3sfb6apdws5qsz74ppf1d35j-test-file-2.txt13462026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=013472026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period13482026/11/09 12:01:19 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=013492026/11/09 12:01:19 INFO Vacuumed table table=pending_closures13502026/11/09 12:01:19 INFO Vacuumed table table=pending_objects13512026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads13522026/11/09 12:01:19 INFO Vacuumed table table=closures13532026/11/09 12:01:19 INFO Vacuumed table table=objects13542026/11/09 12:01:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1355--- PASS: TestGCSweepSkipsPendingObjects (0.44s)1356=== CONT TestLeadEndsOnShutdown13572026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=013582026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period13592026/11/09 12:01:19 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=013602026/11/09 12:01:19 INFO Vacuumed table table=pending_closures13612026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures13622026/11/09 12:01:19 INFO Vacuumed table table=pending_objects13632026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads13642026/11/09 12:01:19 INFO Vacuumed table table=closures13652026/11/09 12:01:19 INFO Vacuumed table table=objects13662026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes1367--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.47s)1368=== CONT TestSweepSkipsRowsLockedByPush13692026/11/09 12:01:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13702026/11/09 12:01:19 INFO Uploading 8qcz8519hf04gn9hd46d6i93fzvhk42q-test-file-0.txt (160B)13712026/11/09 12:01:19 INFO Uploading bjcayyfg8fwrv1qf0bi1nv3q5ds2d9gb-test-file-1.txt (160B)13722026/11/09 12:01:19 INFO Uploading mfilp3af3sfb6apdws5qsz74ppf1d35j-test-file-2.txt (160B)13732026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures13742026/11/09 12:01:19 WARN Failed to register uploaded object key=8qcz8519hf04gn9hd46d6i93fzvhk42q.ls error="server returned 404: 404 page not found\n"13752026/11/09 12:01:19 WARN Failed to register uploaded object key=bjcayyfg8fwrv1qf0bi1nv3q5ds2d9gb.ls error="server returned 404: 404 page not found\n"13762026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13772026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13782026/11/09 12:01:19 WARN Failed to register uploaded object key=mfilp3af3sfb6apdws5qsz74ppf1d35j.ls error="server returned 404: 404 page not found\n"13792026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13802026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13812026/11/09 12:01:19 INFO Signed narinfos id=1 count=313822026/11/09 12:01:19 INFO Uploading 3 narinfos13832026/11/09 12:01:19 WARN Failed to register uploaded object key=bjcayyfg8fwrv1qf0bi1nv3q5ds2d9gb.narinfo error="server returned 404: 404 page not found\n"13842026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/1/complete13852026/11/09 12:01:19 WARN Failed to register uploaded object key=mfilp3af3sfb6apdws5qsz74ppf1d35j.narinfo error="server returned 404: 404 page not found\n"13862026/11/09 12:01:19 WARN Failed to register uploaded object key=8qcz8519hf04gn9hd46d6i93fzvhk42q.narinfo error="server returned 404: 404 page not found\n"1387--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.39s)1388=== CONT TestLeadIncumbentAnnouncesAtOnce13892026/11/09 12:01:19 INFO Completed push id=1 objects=9 duration=12.779795ms13902026/11/09 12:01:19 INFO Upload complete. (65ms)1391=== NAME TestClientMultipleUploads1392 client_integration_test.go:416: Uploaded 3 paths in 99.329132ms13932026/11/09 12:01:19 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccc0100000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjMxOGUwOTk5LThiODItNDA0Yi1hOWM5LWEwMGRmNzBmOGE0MXgxNzk0MjI1Njc5NTczNTY2NzM5 parts=21394--- PASS: TestCompleteMultipartUploadRetriesTransientFailure (0.50s)1395=== CONT TestService_ReadScope_PublicByDefault1396--- PASS: TestClientMultipleUploads (0.80s)1397=== CONT TestFailedS3DeleteKeepsTombstone1398--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.81s)1399=== CONT TestClientCADerivations14002026/11/09 12:01:19 INFO Received uploads request method=POST path=/api/pending_closures14012026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=01402=== NAME TestPinProtectsFromGC1403 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3051231808/001/store/axbxhsfsvz3435il5svi75vq6yq2g97p-pinned-file.txt1404 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3051231808/001/store/5lncdcnibazaflbv44r6scwkz6n4i61k-unpinned-file.txt14052026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period14062026/11/09 12:01:19 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=014072026/11/09 12:01:19 INFO Vacuumed table table=pending_closures14082026/11/09 12:01:19 INFO Vacuumed table table=pending_objects14092026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads14102026/11/09 12:01:19 INFO Vacuumed table table=closures14112026/11/09 12:01:19 INFO Vacuumed table table=objects1412--- PASS: TestSweepRechecksPendingAfterLocking (0.43s)1413=== CONT TestClientIntegration14142026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=014152026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period14162026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes14172026/11/09 12:01:19 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=014182026/11/09 12:01:19 INFO Vacuumed table table=pending_closures14192026/11/09 12:01:19 INFO Vacuumed table table=pending_objects14202026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads14212026/11/09 12:01:19 INFO Vacuumed table table=closures14222026/11/09 12:01:19 INFO Vacuumed table table=objects14232026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=014242026/11/09 12:01:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14252026/11/09 12:01:19 INFO Uploading llcbrd4qy22y2zdkk4l36pd2559i4r17-a (208B)14262026/11/09 12:01:19 INFO Uploading dvn72kifkf7ha2qpibhzj424qxn337xf-shared-dep (136B)1427--- PASS: TestGCMetrics (0.45s)1428=== CONT TestClientErrorHandling1429=== RUN TestClientErrorHandling/InvalidStorePath1430=== PAUSE TestClientErrorHandling/InvalidStorePath1431=== RUN TestClientErrorHandling/InvalidAuthToken1432=== PAUSE TestClientErrorHandling/InvalidAuthToken1433=== RUN TestClientErrorHandling/ServerNotAvailable1434=== PAUSE TestClientErrorHandling/ServerNotAvailable1435=== CONT TestClientFallsBackToClosures14362026/11/09 12:01:19 WARN Failed to register uploaded object key=g0sslk6w4w4jp912kk7pq811vh265v1f.ls error="server returned 404: 404 page not found\n"14372026/11/09 12:01:19 WARN Failed to register uploaded object key=llcbrd4qy22y2zdkk4l36pd2559i4r17.ls error="server returned 404: 404 page not found\n"14382026/11/09 12:01:19 WARN Failed to register uploaded object key=dvn72kifkf7ha2qpibhzj424qxn337xf.ls error="server returned 404: 404 page not found\n"14392026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14402026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14412026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/00137sdk5filfwvf8qcnz6291s6baghzskrpcx8s6ddvn4ssighb.nar.zst error="server returned 404: 404 page not found\n"14422026/11/09 12:01:19 INFO Signed narinfos id=1 count=314432026/11/09 12:01:19 INFO Uploading 3 narinfos14442026/11/09 12:01:19 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=014452026/11/09 12:01:19 WARN Failed to register uploaded object key=llcbrd4qy22y2zdkk4l36pd2559i4r17.narinfo error="server returned 404: 404 page not found\n"14462026/11/09 12:01:19 WARN Failed to register uploaded object key=dvn72kifkf7ha2qpibhzj424qxn337xf.narinfo error="server returned 404: 404 page not found\n"14472026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14482026/11/09 12:01:19 WARN Failed to register uploaded object key=g0sslk6w4w4jp912kk7pq811vh265v1f.narinfo error="server returned 404: 404 page not found\n"14492026/11/09 12:01:19 INFO Vacuumed table table=pending_closures1450--- PASS: TestGetExistingObjectsLocksRows (0.45s)1451=== CONT TestDeleteClosuresRacingPins14522026/11/09 12:01:19 INFO Vacuumed table table=pending_objects14532026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads14542026/11/09 12:01:19 INFO Vacuumed table table=closures14552026/11/09 12:01:19 INFO Completed push id=1 objects=8 duration=8.101573ms14562026/11/09 12:01:19 INFO Upload complete. (63ms)14572026/11/09 12:01:19 INFO Vacuumed table table=objects1458=== NAME TestClientPushesUseOnePush1459 client_pushes_test.go:97: Retrieved narinfo from S3:1460 StorePath: /build/TestClientPushesUseOnePush617509498/001/store/dvn72kifkf7ha2qpibhzj424qxn337xf-shared-dep1461 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1462 Compression: zstd1463 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821464 NarSize: 1361465 References: 1466 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14672026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=01468 client_pushes_test.go:97: Retrieved narinfo from S3:1469 StorePath: /build/TestClientPushesUseOnePush617509498/001/store/llcbrd4qy22y2zdkk4l36pd2559i4r17-a1470 URL: nar/00137sdk5filfwvf8qcnz6291s6baghzskrpcx8s6ddvn4ssighb.nar.zst1471 Compression: zstd1472 NarHash: sha256:00137sdk5filfwvf8qcnz6291s6baghzskrpcx8s6ddvn4ssighb1473 NarSize: 2081474 References: /build/TestClientPushesUseOnePush617509498/001/store/dvn72kifkf7ha2qpibhzj424qxn337xf-shared-dep1475 CA: text:sha256:14ykkbnbnglgpbc89qhlv9risjdmlbs7c7sgnyrqsgkfvbhihjq114762026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period14772026/11/09 12:01:19 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=01478 client_pushes_test.go:97: Retrieved narinfo from S3:1479 StorePath: /build/TestClientPushesUseOnePush617509498/001/store/g0sslk6w4w4jp912kk7pq811vh265v1f-b1480 URL: nar/00137sdk5filfwvf8qcnz6291s6baghzskrpcx8s6ddvn4ssighb.nar.zst1481 Compression: zstd1482 NarHash: sha256:00137sdk5filfwvf8qcnz6291s6baghzskrpcx8s6ddvn4ssighb1483 NarSize: 2081484 References: /build/TestClientPushesUseOnePush617509498/001/store/dvn72kifkf7ha2qpibhzj424qxn337xf-shared-dep1485 CA: text:sha256:14ykkbnbnglgpbc89qhlv9risjdmlbs7c7sgnyrqsgkfvbhihjq114862026/11/09 12:01:19 INFO Vacuumed table table=pending_closures1487--- PASS: TestClientPushesUseOnePush (0.61s)1488=== CONT TestCacheStatsHandler14892026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes14902026/11/09 12:01:19 INFO Vacuumed table table=pending_objects14912026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads14922026/11/09 12:01:19 INFO Vacuumed table table=closures14932026/11/09 12:01:19 INFO Vacuumed table table=objects14942026/11/09 12:01:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14952026/11/09 12:01:19 INFO Uploading axbxhsfsvz3435il5svi75vq6yq2g97p-pinned-file.txt (128B)1496--- PASS: TestPushDedupSurvivesConcurrentGC (0.52s)1497=== CONT TestRetryableCompletionError1498=== RUN TestRetryableCompletionError/access_denied1499=== PAUSE TestRetryableCompletionError/access_denied1500=== RUN TestRetryableCompletionError/throttled1501=== PAUSE TestRetryableCompletionError/throttled1502=== RUN TestRetryableCompletionError/deadline_exceeded1503=== PAUSE TestRetryableCompletionError/deadline_exceeded1504=== RUN TestRetryableCompletionError/degraded_quorum1505=== PAUSE TestRetryableCompletionError/degraded_quorum1506=== RUN TestRetryableCompletionError/transport_failure1507=== PAUSE TestRetryableCompletionError/transport_failure1508=== RUN TestRetryableCompletionError/no_such_upload1509=== PAUSE TestRetryableCompletionError/no_such_upload1510=== RUN TestRetryableCompletionError/invalid_part1511=== PAUSE TestRetryableCompletionError/invalid_part1512=== RUN TestRetryableCompletionError/context_canceled1513=== PAUSE TestRetryableCompletionError/context_canceled1514=== RUN TestRetryableCompletionError/nil1515=== PAUSE TestRetryableCompletionError/nil1516=== RUN TestRetryableCompletionError/bad_gateway1517=== PAUSE TestRetryableCompletionError/bad_gateway1518=== CONT TestCacheConfigHandler1519=== RUN TestCacheConfigHandler/full_config,_no_issuer1520=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1521=== RUN TestCacheConfigHandler/no_cache_url_configured1522=== PAUSE TestCacheConfigHandler/no_cache_url_configured1523=== RUN TestCacheConfigHandler/no_signing_keys1524=== PAUSE TestCacheConfigHandler/no_signing_keys1525=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1526=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1527=== CONT TestService_ReadAuthMiddleware15282026/11/09 12:01:19 WARN Failed to register uploaded object key=axbxhsfsvz3435il5svi75vq6yq2g97p.ls error="server returned 404: 404 page not found\n"15292026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15302026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15312026/11/09 12:01:19 INFO Signed narinfos id=1 count=115322026/11/09 12:01:19 INFO Uploading 1 narinfos15332026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15342026/11/09 12:01:19 WARN Failed to register uploaded object key=axbxhsfsvz3435il5svi75vq6yq2g97p.narinfo error="server returned 404: 404 page not found\n"15352026/11/09 12:01:19 INFO Completed push id=1 objects=3 duration=11.182ms15362026/11/09 12:01:19 INFO Upload complete. (66ms)15372026/11/09 12:01:19 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"1538--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.35s)1539=== CONT TestService_RequireScope_OIDC1540--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.33s)1541=== CONT TestService_AuthMiddleware_MTLSProxyHeader15422026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes15432026/11/09 12:01:19 INFO lead: acquired remote=192.0.2.1:123415442026/11/09 12:01:19 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15452026/11/09 12:01:19 INFO Uploading sw2nry82jndalfvc1nxvi559vnvc5hhs-top (224B)15462026/11/09 12:01:19 INFO Uploading 807as3igxh3zr4ilbv3jnk2qh1ghwrfz-shared-dep (136B)15472026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15482026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15492026/11/09 12:01:19 WARN Failed to register uploaded object key=sw2nry82jndalfvc1nxvi559vnvc5hhs.ls error="server returned 404: 404 page not found\n"15502026/11/09 12:01:19 WARN Failed to register uploaded object key=807as3igxh3zr4ilbv3jnk2qh1ghwrfz.ls error="server returned 404: 404 page not found\n"15512026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/1fqc0w04072jvyz7ipyl5q89nj5fyyw3fps5alr06l9hdncj8srf.nar.zst error="server returned 404: 404 page not found\n"15522026/11/09 12:01:19 INFO Signed narinfos id=1 count=215532026/11/09 12:01:19 INFO Uploading 2 narinfos15542026/11/09 12:01:19 INFO Received push request method=POST path=/api/pushes15552026/11/09 12:01:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15562026/11/09 12:01:19 INFO Uploading 5lncdcnibazaflbv44r6scwkz6n4i61k-unpinned-file.txt (128B)15572026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15582026/11/09 12:01:19 WARN Failed to register uploaded object key=807as3igxh3zr4ilbv3jnk2qh1ghwrfz.narinfo error="server returned 404: 404 page not found\n"15592026/11/09 12:01:19 WARN Failed to register uploaded object key=sw2nry82jndalfvc1nxvi559vnvc5hhs.narinfo error="server returned 404: 404 page not found\n"15602026/11/09 12:01:19 WARN Failed to register uploaded object key=5lncdcnibazaflbv44r6scwkz6n4i61k.ls error="server returned 404: 404 page not found\n"15612026/11/09 12:01:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15622026/11/09 12:01:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15632026/11/09 12:01:19 INFO Signed narinfos id=2 count=115642026/11/09 12:01:19 INFO Uploading 1 narinfos15652026/11/09 12:01:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38689/oidc15662026/11/09 12:01:19 INFO Completed push id=1 objects=6 duration=5.309768ms15672026/11/09 12:01:19 INFO Upload complete. (63ms)1568=== NAME TestClientSharedPathCommittedMidPush1569 client_integration_test.go:727: Retrieved narinfo from S3:1570 StorePath: /build/TestClientSharedPathCommittedMidPush325863180/001/store/807as3igxh3zr4ilbv3jnk2qh1ghwrfz-shared-dep1571 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1572 Compression: zstd1573 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821574 NarSize: 1361575 References: 1576 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1577=== NAME TestClientWithDependencies1578 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies814128239/001/store/gwr68np7w3js8cg5pcz9rl61l48ial72-test-script15792026/11/09 12:01:19 INFO Received complete push request method=POST path=/api/pushes/2/complete15802026/11/09 12:01:19 WARN Failed to register uploaded object key=5lncdcnibazaflbv44r6scwkz6n4i61k.narinfo error="server returned 404: 404 page not found\n"1581=== NAME TestClientSharedPathCommittedMidPush1582 client_integration_test.go:727: Retrieved narinfo from S3:1583 StorePath: /build/TestClientSharedPathCommittedMidPush325863180/001/store/sw2nry82jndalfvc1nxvi559vnvc5hhs-top1584 URL: nar/1fqc0w04072jvyz7ipyl5q89nj5fyyw3fps5alr06l9hdncj8srf.nar.zst1585 Compression: zstd1586 NarHash: sha256:1fqc0w04072jvyz7ipyl5q89nj5fyyw3fps5alr06l9hdncj8srf1587 NarSize: 2241588 References: /build/TestClientSharedPathCommittedMidPush325863180/001/store/807as3igxh3zr4ilbv3jnk2qh1ghwrfz-shared-dep1589 CA: text:sha256:1nin39ky7n9d8vr0ypvmpd74ll6rvvqh53f103w4cfd3lmrjqhyd15902026/11/09 12:01:19 INFO Completed push id=2 objects=3 duration=2.780645ms15912026/11/09 12:01:19 INFO Upload complete. (44ms)1592--- PASS: TestClientSharedPathCommittedMidPush (0.59s)1593=== CONT TestService_AuthMiddleware_OIDC15942026/11/09 12:01:19 INFO lead: acquired remote=192.0.2.1:123415952026/11/09 12:01:19 INFO lead: released remote=192.0.2.1:12341596--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.30s)1597=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15982026/11/09 12:01:19 INFO Aborted multipart uploads count=0 kept=015992026/11/09 12:01:19 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/11/09 12:01:19 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=01601=== NAME TestClientWithDependencies1602 client_integration_test.go:662: Found 1 dependencies (including self)16032026/11/09 12:01:19 INFO Vacuumed table table=pending_closures16042026/11/09 12:01:19 INFO Vacuumed table table=pending_objects16052026/11/09 12:01:19 INFO Vacuumed table table=multipart_uploads16062026/11/09 12:01:19 INFO Vacuumed table table=closures16072026/11/09 12:01:19 INFO Vacuumed table table=objects16082026/11/09 12:01:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures16092026/11/09 12:01:19 INFO Garbage collection started16102026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=016112026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures16122026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period16132026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=016142026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period16152026/11/09 12:01:20 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=016162026/11/09 12:01:20 INFO Vacuumed table table=pending_closures1617--- PASS: TestService_ReadScope_PublicByDefault (0.33s)1618=== CONT TestService_AuthMiddleware16192026/11/09 12:01:20 INFO Vacuumed table table=pending_objects16202026/11/09 12:01:20 INFO Vacuumed table table=multipart_uploads16212026/11/09 12:01:20 INFO Vacuumed table table=closures16222026/11/09 12:01:20 INFO Vacuumed table table=objects1623--- PASS: TestSweepSkipsRowsLockedByPush (0.36s)1624=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock16252026/11/09 12:01:20 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=016262026/11/09 12:01:20 INFO Vacuumed table table=pending_closures16272026/11/09 12:01:20 INFO Vacuumed table table=pending_objects16282026/11/09 12:01:20 INFO Vacuumed table table=multipart_uploads16292026/11/09 12:01:20 INFO Vacuumed table table=closures16302026/11/09 12:01:20 INFO Vacuumed table table=objects16312026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes16322026/11/09 12:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16332026/11/09 12:01:20 INFO Uploading gwr68np7w3js8cg5pcz9rl61l48ial72-test-script (136B)16342026/11/09 12:01:20 WARN Failed to register uploaded object key=gwr68np7w3js8cg5pcz9rl61l48ial72.ls error="server returned 404: 404 page not found\n"16352026/11/09 12:01:20 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16362026/11/09 12:01:20 WARN Failed to register uploaded object key=log/a8b5s0xjsv9bmxndrfdlvh7zkkz098s7-test-script.drv error="server returned 404: 404 page not found\n"16372026/11/09 12:01:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16382026/11/09 12:01:20 INFO Signed narinfos id=1 count=116392026/11/09 12:01:20 INFO Uploading 1 narinfos16402026/11/09 12:01:20 INFO Received complete push request method=POST path=/api/pushes/1/complete16412026/11/09 12:01:20 WARN Failed to register uploaded object key=gwr68np7w3js8cg5pcz9rl61l48ial72.narinfo error="server returned 404: 404 page not found\n"16422026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=01643--- PASS: TestGCBugBareHashReferences (0.64s)1644=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16452026/11/09 12:01:20 INFO Completed push id=1 objects=4 duration=7.055724ms16462026/11/09 12:01:20 INFO Upload complete. (62ms)16472026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period1648=== NAME TestClientWithDependencies1649 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies814128239/001/store) requires matching store prefix1650--- PASS: TestClientWithDependencies (0.62s)1651=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed16522026/11/09 12:01:20 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16532026/11/09 12:01:20 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1654--- PASS: TestFailedS3DeleteKeepsTombstone (0.39s)1655=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed16562026/11/09 12:01:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41925/oidc1657=== NAME TestClientIntegration1658 client_integration_test.go:291: Created store path: /build/TestClientIntegration2755109527/002/store/0rqbsf53c4px0754clxddq9x5g7hpybh-test-file.txt1659=== NAME TestClientCADerivations1660 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations599332687/001/store/hpkcx424is7159f7ahqkhx3iy2w1iy3f-ca-test1661--- PASS: TestCacheStatsHandler (0.30s)1662=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1663--- PASS: TestPushWaitsForSweepHoldingRow (0.86s)1664=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1665--- PASS: TestService_ReadAuthMiddleware (0.30s)1666=== CONT TestIsValidUploadKey/narinfo1667=== CONT TestIsValidUploadKey/traversal1668=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1669=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1670=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1671=== CONT TestIsValidUploadKey/index.html1672=== CONT TestIsValidUploadKey/traversal_nar1673=== CONT TestIsValidUploadKey/nix-cache-info1674=== CONT TestIsValidUploadKey/realisation_plus_in_output1675=== CONT TestIsValidUploadKey/realisation1676=== CONT TestIsValidUploadKey/build_log_equals1677=== CONT TestIsValidUploadKey/build_log_question_mark1678=== CONT TestIsValidUploadKey/build_log_plus_in_name1679=== CONT TestIsValidUploadKey/build_log_home-manager_file1680=== CONT TestIsValidUploadKey/build_log1681=== CONT TestIsValidUploadKey/listing1682=== CONT TestIsValidUploadKey/nar_plain1683=== CONT TestIsValidUploadKey/nar_xz1684=== CONT TestIsValidUploadKey/nar_zst1685=== CONT TestIsValidUploadKey/unknown_type1686=== CONT TestIsValidUploadKey/absolute1687=== CONT TestIsValidUploadKey/empty_key1688--- PASS: TestIsValidUploadKey (0.00s)1689 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1690 --- PASS: TestIsValidUploadKey/traversal (0.00s)1691 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1692 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1693 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1694 --- PASS: TestIsValidUploadKey/index.html (0.00s)1695 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1696 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1697 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1698 --- PASS: TestIsValidUploadKey/realisation (0.00s)1699 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1700 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1701 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1702 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1703 --- PASS: TestIsValidUploadKey/build_log (0.00s)1704 --- PASS: TestIsValidUploadKey/listing (0.00s)1705 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1706 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1707 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1708 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1709 --- PASS: TestIsValidUploadKey/absolute (0.00s)1710 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1711=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17122026/11/09 12:01:20 INFO Received uploads request method=POST path=/1713=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17142026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/1715=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17162026/11/09 12:01:20 INFO Received request for more parts method=POST path=/1717=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17182026/11/09 12:01:20 INFO Received uploads request method=POST path=/1719--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1720 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1721 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1722 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1723 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1724=== CONT TestServerTLSConfig/no_client_CA1725=== CONT TestServerTLSConfig/not_a_PEM_file1726=== NAME TestClientCADerivations1727 client_ca_test.go:139: Found 1 dependencies (including self)1728=== CONT TestServerTLSConfig/missing_CA_file1729=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17302026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/1731--- PASS: TestServerTLSConfig (0.00s)1732 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1733 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1734 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1735--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1736=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17372026/11/09 12:01:20 INFO Received uploads request method=POST path=/17382026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes17392026/11/09 12:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17402026/11/09 12:01:20 INFO Uploading 0rqbsf53c4px0754clxddq9x5g7hpybh-test-file.txt (152B)17412026/11/09 12:01:20 WARN Failed to register uploaded object key=0rqbsf53c4px0754clxddq9x5g7hpybh.ls error="server returned 404: 404 page not found\n"17422026/11/09 12:01:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17432026/11/09 12:01:20 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17442026/11/09 12:01:20 INFO Signed narinfos id=1 count=117452026/11/09 12:01:20 INFO Uploading 1 narinfos17462026/11/09 12:01:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17472026/11/09 12:01:20 WARN Failed to register uploaded object key=0rqbsf53c4px0754clxddq9x5g7hpybh.narinfo error="server returned 404: 404 page not found\n"17482026/11/09 12:01:20 INFO Completed push id=1 objects=3 duration=6.6683ms17492026/11/09 12:01:20 INFO Upload complete. (60ms)1750=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17512026/11/09 12:01:20 INFO Received request for more parts method=POST path=/1752=== RUN TestService_RequireScope_OIDC/builder_may_write1753=== PAUSE TestService_RequireScope_OIDC/builder_may_write1754=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1755=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1756=== RUN TestService_RequireScope_OIDC/ops_may_admin1757=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1758=== RUN TestService_RequireScope_OIDC/ops_may_not_write1759=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1760=== RUN TestService_RequireScope_OIDC/reader_may_not_write1761=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1762=== RUN TestService_RequireScope_OIDC/static_token_may_admin1763=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1764=== RUN TestService_RequireScope_OIDC/static_token_may_write1765=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1766=== RUN TestService_RequireScope_OIDC/reader_may_read1767=== PAUSE TestService_RequireScope_OIDC/reader_may_read1768=== RUN TestService_RequireScope_OIDC/writer_implies_read1769=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1770=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1771=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1772=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1773=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1774=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1775=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1776=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1777=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1778=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1779=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1780=== CONT TestPush_RejectsBadRequests/no_objects17812026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes1782=== CONT TestPush_RejectsBadRequests/root_not_in_objects17832026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes1784=== CONT TestPush_RejectsBadRequests/no_roots17852026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes1786=== CONT TestPush_RejectsBadRequests/bad_root17872026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes1788=== CONT TestIsValidCachePath/narinfo1789--- PASS: TestPush_RejectsBadRequests (0.57s)1790 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1791 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1792 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1793 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1794=== CONT TestIsValidCachePath/short_hash1795=== CONT TestIsValidCachePath/wrong_extension1796=== CONT TestIsValidCachePath/leading_slash17972026/11/09 12:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"1798=== CONT TestIsValidCachePath/empty17992026/11/09 12:01:20 WARN mTLS auth: bound subjects configured but subject DN unavailable1800=== CONT TestIsValidCachePath/random_path18012026/11/09 12:01:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1802=== CONT TestIsValidCachePath/invalid_char_u1803--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1804=== CONT TestIsValidCachePath/invalid_char_e1805=== CONT TestIsValidCachePath/traversal_parent1806=== CONT TestIsValidCachePath/index.html1807=== CONT TestIsValidCachePath/nix-cache-info1808=== CONT TestIsValidCachePath/realisation1809=== CONT TestIsValidCachePath/log1810=== CONT TestIsValidCachePath/ls1811=== CONT TestIsValidCachePath/nar_uncompressed1812=== CONT TestIsValidCachePath/traversal_in_middle1813=== CONT TestIsValidCachePath/nar_bz21814=== CONT TestIsValidCachePath/nar_zst1815=== CONT TestIsValidCachePath/nar_xz1816=== CONT TestParseSingleRange/none1817=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1818--- PASS: TestIsValidCachePath (0.00s)1819 --- PASS: TestIsValidCachePath/narinfo (0.00s)1820 --- PASS: TestIsValidCachePath/short_hash (0.00s)1821 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1822 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1823 --- PASS: TestIsValidCachePath/empty (0.00s)1824 --- PASS: TestIsValidCachePath/random_path (0.00s)1825 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1826 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1827 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1828 --- PASS: TestIsValidCachePath/index.html (0.00s)1829 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1830 --- PASS: TestIsValidCachePath/realisation (0.00s)1831 --- PASS: TestIsValidCachePath/log (0.00s)1832 --- PASS: TestIsValidCachePath/ls (0.00s)1833 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1834 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1835 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1836 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1837 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1838 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1839=== CONT TestParseSingleRange/open-ended1840=== CONT TestParseSingleRange/start_past_EOF1841=== CONT TestParseSingleRange/single_byte1842=== CONT TestParseSingleRange/suffix_exceeds_size1843=== CONT TestParseSingleRange/suffix1844=== CONT TestParseSingleRange/start_far_past_EOF1845=== CONT TestParseSingleRange/malformed_both_empty1846=== CONT TestParseSingleRange/closed1847=== CONT TestParseSingleRange/end_clamped_to_size1848=== CONT TestParseSingleRange/unknown_unit1849=== CONT TestParseSingleRange/malformed_end_before_start1850=== CONT TestParseSingleRange/multi-range_ignored1851=== CONT TestParseSingleRange/malformed_no_dash1852--- PASS: TestParseSingleRange (0.00s)1853 --- PASS: TestParseSingleRange/none (0.00s)1854 --- PASS: TestParseSingleRange/open-ended (0.00s)1855 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1856 --- PASS: TestParseSingleRange/single_byte (0.00s)1857 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1858 --- PASS: TestParseSingleRange/suffix (0.00s)1859 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1860 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1861 --- PASS: TestParseSingleRange/closed (0.00s)1862 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1863 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1864 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1865 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1866 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1867=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1868=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18692026/11/09 12:01:20 INFO All 1 paths already cached1870=== NAME TestClientIntegration1871 client_integration_test.go:317: Retrieved narinfo from S3:1872 StorePath: /build/TestClientIntegration2755109527/002/store/0rqbsf53c4px0754clxddq9x5g7hpybh-test-file.txt1873 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1874 Compression: zstd1875 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11876 NarSize: 1521877 References: 1878 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11879 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1880 client_integration_test.go:318: Decompressed .ls content (64 bytes):1881 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}18822026/11/09 12:01:20 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1883--- PASS: TestService_AuthMiddleware (0.23s)1884=== CONT TestProxyWriteTimeout/narinfo1885=== CONT TestProxyWriteTimeout/10_GiB_nar1886=== CONT TestProxyWriteTimeout/1_GiB_nar1887=== CONT TestProxyWriteTimeout/unknown_size1888--- PASS: TestProxyWriteTimeout (0.00s)1889 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1890 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1891 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1892 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1893=== CONT TestPendingClosureWriteTimeout/empty1894=== CONT TestPendingClosureWriteTimeout/670k_objects1895=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18962026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes18972026/11/09 12:01:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18982026/11/09 12:01:20 INFO Uploading hpkcx424is7159f7ahqkhx3iy2w1iy3f-ca-test (144B)18992026/11/09 12:01:20 WARN Failed to register uploaded object key=hpkcx424is7159f7ahqkhx3iy2w1iy3f.ls error="server returned 404: 404 page not found\n"19002026/11/09 12:01:20 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19012026/11/09 12:01:20 WARN Failed to register uploaded object key=log/zfslmvpa58a670c2q9mb53ziq3mn0z3k-ca-test.drv error="server returned 404: 404 page not found\n"19022026/11/09 12:01:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1903=== CONT TestPendingClosureWriteTimeout/400_objects1904=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19052026/11/09 12:01:20 INFO Signed narinfos id=1 count=119062026/11/09 12:01:20 INFO Uploading 1 narinfos19072026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures19082026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures19092026/11/09 12:01:20 INFO Received complete push request method=POST path=/api/pushes/1/complete19102026/11/09 12:01:20 WARN Failed to register uploaded object key=hpkcx424is7159f7ahqkhx3iy2w1iy3f.narinfo error="server returned 404: 404 page not found\n"19112026/11/09 12:01:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19122026/11/09 12:01:20 INFO Uploading 1h4wqhlsahw9hc7wjg7vr0zqsnhqdffb-a (216B)19132026/11/09 12:01:20 INFO Uploading qkschzbs6dd19hhfjc5k2bzjkyn8g3qm-shared-dep (136B)19142026/11/09 12:01:20 INFO Completed push id=1 objects=4 duration=7.400647ms19152026/11/09 12:01:20 INFO Upload complete. (100ms)19162026/11/09 12:01:20 WARN Failed to register uploaded object key=1h4wqhlsahw9hc7wjg7vr0zqsnhqdffb.ls error="server returned 404: 404 page not found\n"19172026/11/09 12:01:20 WARN Failed to register uploaded object key=hcn356h7ld4l38gbay717saswlggw8df.ls error="server returned 404: 404 page not found\n"19182026/11/09 12:01:20 WARN Failed to register uploaded object key=nar/018x4w4i7rjqn4nhl64dn2wsy1mzgzmx1kh993dyizhxxh1739yp.nar.zst error="server returned 404: 404 page not found\n"19192026/11/09 12:01:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19202026/11/09 12:01:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19212026/11/09 12:01:20 WARN Failed to register uploaded object key=qkschzbs6dd19hhfjc5k2bzjkyn8g3qm.ls error="server returned 404: 404 page not found\n"19222026/11/09 12:01:20 INFO Signed narinfos id=1 count=219232026/11/09 12:01:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19242026/11/09 12:01:20 INFO Signed narinfos id=2 count=219252026/11/09 12:01:20 INFO Uploading 4 narinfos1926=== NAME TestClientCADerivations1927 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations599332687/001/store/hpkcx424is7159f7ahqkhx3iy2w1iy3f-ca-test1928 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1929 Compression: zstd1930 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1931 NarSize: 1441932 References: 1933 Deriver: /build/TestClientCADerivations599332687/001/store/zfslmvpa58a670c2q9mb53ziq3mn0z3k-ca-test.drv1934 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1935 client_ca_test.go:185: Checking for realisation files in S3...1936 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1937 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19382026/11/09 12:01:20 WARN Failed to register uploaded object key=1h4wqhlsahw9hc7wjg7vr0zqsnhqdffb.narinfo error="server returned 404: 404 page not found\n"19392026/11/09 12:01:20 WARN Failed to register uploaded object key=hcn356h7ld4l38gbay717saswlggw8df.narinfo error="server returned 404: 404 page not found\n"19402026/11/09 12:01:20 WARN Failed to register uploaded object key=qkschzbs6dd19hhfjc5k2bzjkyn8g3qm.narinfo error="server returned 404: 404 page not found\n"19412026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures19422026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19432026/11/09 12:01:20 WARN Failed to register uploaded object key=qkschzbs6dd19hhfjc5k2bzjkyn8g3qm.narinfo error="server returned 404: 404 page not found\n"19442026/11/09 12:01:20 INFO Completed upload id=2 objects=6 duration=8.270534ms19452026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19462026/11/09 12:01:20 INFO Completed upload id=1 objects=6 duration=2.567383ms19472026/11/09 12:01:20 INFO Upload complete. (82ms)1948=== NAME TestClientFallsBackToClosures1949 client_pushes_test.go:112: Retrieved narinfo from S3:1950 StorePath: /build/TestClientFallsBackToClosures1270302591/001/store/qkschzbs6dd19hhfjc5k2bzjkyn8g3qm-shared-dep1951 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1952 Compression: zstd1953 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821954 NarSize: 1361955 References: 1956 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1957 client_pushes_test.go:112: Retrieved narinfo from S3:1958 StorePath: /build/TestClientFallsBackToClosures1270302591/001/store/1h4wqhlsahw9hc7wjg7vr0zqsnhqdffb-a1959 URL: nar/018x4w4i7rjqn4nhl64dn2wsy1mzgzmx1kh993dyizhxxh1739yp.nar.zst1960 Compression: zstd1961 NarHash: sha256:018x4w4i7rjqn4nhl64dn2wsy1mzgzmx1kh993dyizhxxh1739yp1962 NarSize: 2161963 References: /build/TestClientFallsBackToClosures1270302591/001/store/qkschzbs6dd19hhfjc5k2bzjkyn8g3qm-shared-dep1964 CA: text:sha256:141szk1f39qc7j3f7sa1knikpa04225clg788wsk2qgq3gjywq0m1965 client_pushes_test.go:112: Retrieved narinfo from S3:1966 StorePath: /build/TestClientFallsBackToClosures1270302591/001/store/hcn356h7ld4l38gbay717saswlggw8df-b1967 URL: nar/018x4w4i7rjqn4nhl64dn2wsy1mzgzmx1kh993dyizhxxh1739yp.nar.zst1968 Compression: zstd1969 NarHash: sha256:018x4w4i7rjqn4nhl64dn2wsy1mzgzmx1kh993dyizhxxh1739yp1970 NarSize: 2161971 References: /build/TestClientFallsBackToClosures1270302591/001/store/qkschzbs6dd19hhfjc5k2bzjkyn8g3qm-shared-dep1972 CA: text:sha256:141szk1f39qc7j3f7sa1knikpa04225clg788wsk2qgq3gjywq0m19732026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures1974--- PASS: TestClientFallsBackToClosures (0.51s)1975=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19762026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes19772026/11/09 12:01:20 INFO Object in database but missing from S3 key=0rqbsf53c4px0754clxddq9x5g7hpybh.ls19782026/11/09 12:01:20 WARN Found objects in DB but missing from S3, will re-upload count=119792026/11/09 12:01:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19802026/11/09 12:01:20 INFO Received complete push request method=POST path=/api/pushes/2/complete19812026/11/09 12:01:20 WARN Failed to register uploaded object key=0rqbsf53c4px0754clxddq9x5g7hpybh.ls error="server returned 404: 404 page not found\n"19822026/11/09 12:01:20 INFO Completed push id=2 objects=3 duration=2.24656ms19832026/11/09 12:01:20 INFO Upload complete. (51ms)1984=== NAME TestClientIntegration1985 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1986 client_integration_test.go:335: Decompressed .ls content (49 bytes):1987 {"version":1,"root":{"type":"regular","size":39}}19882026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures1989=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1990=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1991=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1992=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1993=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1994=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1995=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1996=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1997=== CONT TestResolveDBConnectionString/flag_wins1998=== CONT TestResolveDBConnectionString/missing_file_is_an_error1999=== CONT TestResolveDBConnectionString/file_when_flag_empty2000=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2001=== CONT TestResolveDBConnectionString/nothing_configured2002=== CONT TestGCEndsOnShutdown/before_the_run2003--- PASS: TestResolveDBConnectionString (0.00s)2004 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2005 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2006 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2007 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2008 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2009=== NAME TestClientCADerivations2010 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2011 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2012 error: binary cache 's3://bucket81?endpoint=http://localhost:43301®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations599332687/001/store'2013 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12014--- PASS: TestClientCADerivations (0.68s)2015=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark20162026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures20172026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures20182026/11/09 12:01:20 INFO Received push request method=POST path=/api/pushes20192026/11/09 12:01:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20202026/11/09 12:01:20 INFO Received complete push request method=POST path=/api/pushes/3/complete20212026/11/09 12:01:20 WARN Failed to register uploaded object key=0rqbsf53c4px0754clxddq9x5g7hpybh.ls error="server returned 404: 404 page not found\n"20222026/11/09 12:01:20 INFO Completed push id=3 objects=3 duration=2.2113ms20232026/11/09 12:01:20 INFO Upload complete. (49ms)2024=== NAME TestClientIntegration2025 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2026 client_integration_test.go:352: Decompressed .ls content (49 bytes):2027 {"version":1,"root":{"type":"regular","size":39}}2028 client_integration_test.go:363: Testing garbage collection...20292026/11/09 12:01:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures20302026/11/09 12:01:20 INFO Garbage collection started20312026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=020322026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures20332026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures20352026/11/09 12:01:20 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=020362026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=020372026/11/09 12:01:20 INFO Vacuumed table table=pending_closures20382026/11/09 12:01:20 INFO Vacuumed table table=pending_objects20392026/11/09 12:01:20 INFO Vacuumed table table=multipart_uploads20402026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period20412026/11/09 12:01:20 INFO Vacuumed table table=closures20422026/11/09 12:01:20 INFO Vacuumed table table=objects2043--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.52s)2044=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20452026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures20462026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=020472026/11/09 12:01:20 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=020482026/11/09 12:01:20 INFO Vacuumed table table=pending_closures20492026/11/09 12:01:20 INFO Vacuumed table table=pending_objects20502026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/11/09 12:01:20 INFO Vacuumed table table=multipart_uploads20522026/11/09 12:01:20 INFO Vacuumed table table=closures20532026/11/09 12:01:20 INFO Vacuumed table table=objects20542026/11/09 12:01:20 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=020552026/11/09 12:01:20 INFO Vacuumed table table=pending_closures2056=== CONT TestClientErrorHandling/InvalidStorePath20572026/11/09 12:01:20 INFO Vacuumed table table=pending_objects20582026/11/09 12:01:20 INFO Vacuumed table table=multipart_uploads20592026/11/09 12:01:20 INFO Vacuumed table table=closures20602026/11/09 12:01:20 INFO Vacuumed table table=objects2061=== CONT TestClientErrorHandling/ServerNotAvailable2062--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2063 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.26s)2064 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.31s)2065=== CONT TestClientErrorHandling/InvalidAuthToken20662026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20672026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20682026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LmJiMTIzNGIyLTVkMTAtNDI1NS1hN2FhLTQ2NWFhNTkyZGFjM3gxNzk0MjI1NjgwMzIyMDc2OTQy parts=1020692026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=020702026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period20712026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20722026/11/09 12:01:20 INFO Completed upload id=1 objects=3 duration=3.696513ms20732026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjA2OTkyMjgwLWY1MmYtNDc1ZS1iNTY0LTdkNTI0ZjNhMjQ2MHgxNzk0MjI1NjgwMzM4MDgyMDQ2 parts=1020742026-11-09 12:01:20.654 UTC [1843] ERROR: canceling statement due to user request20752026-11-09 12:01:20.654 UTC [1843] CONTEXT: SQL statement "UPDATE object_stats s2076 SET object_count = s.object_count + n.n - o.n,2077 total_bytes = s.total_bytes + n.bytes - o.bytes2078 FROM (2079 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2080 FROM new_rows WHERE deleted_at IS NULL2081 ) AS n,2082 (2083 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2084 FROM old_rows WHERE deleted_at IS NULL2085 ) AS o2086 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2087 PL/pgSQL function object_stats_update() line 3 at SQL statement20882026-11-09 12:01:20.654 UTC [1843] STATEMENT: -- name: MarkStaleObjects :execrows2089 WITH RECURSIVE ct AS (2090 SELECT timezone('UTC', now()) AS now2091 ),2092 closure_reach AS (2093 -- Start with all closure keys2094 SELECT o.key, o.refs2095 FROM objects o2096 INNER JOIN closures c ON o.key = c.key2097 UNION2098 -- Recursively add all referenced objects2099 SELECT o.key, o.refs2100 FROM objects o2101 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2102 ),2103 reachable_objects AS (2104 SELECT DISTINCT key FROM closure_reach2105 ),2106 stale_objects AS (2107 SELECT o.key2108 FROM objects AS o, ct2109 WHERE2110 NOT EXISTS (2111 SELECT 12112 FROM reachable_objects ro2113 WHERE ro.key = o.key2114 )2115 AND NOT EXISTS (2116 SELECT 12117 FROM pending_objects AS po2118 WHERE po.key = o.key2119 )2120 AND o.deleted_at IS NULL -- Only mark fresh objects2121 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2122 FOR UPDATE2123 )2124 UPDATE objects2125 SET2126 deleted_at = ct.now,2127 first_deleted_at = COALESCE(first_deleted_at, ct.now)2128 FROM stale_objects, ct2129 WHERE objects.key = stale_objects.key2130 21312026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2132=== CONT TestRetryableCompletionError/access_denied2133=== CONT TestRetryableCompletionError/no_such_upload2134=== CONT TestRetryableCompletionError/bad_gateway2135=== CONT TestRetryableCompletionError/nil2136=== CONT TestRetryableCompletionError/context_canceled2137=== CONT TestRetryableCompletionError/invalid_part2138=== CONT TestRetryableCompletionError/degraded_quorum2139=== CONT TestRetryableCompletionError/transport_failure2140=== CONT TestRetryableCompletionError/deadline_exceeded2141=== CONT TestRetryableCompletionError/throttled2142--- PASS: TestRetryableCompletionError (0.00s)2143 --- PASS: TestRetryableCompletionError/access_denied (0.00s)2144 --- PASS: TestRetryableCompletionError/no_such_upload (0.00s)2145 --- PASS: TestRetryableCompletionError/bad_gateway (0.00s)2146 --- PASS: TestRetryableCompletionError/nil (0.00s)2147 --- PASS: TestRetryableCompletionError/context_canceled (0.00s)2148 --- PASS: TestRetryableCompletionError/invalid_part (0.00s)2149 --- PASS: TestRetryableCompletionError/degraded_quorum (0.00s)2150 --- PASS: TestRetryableCompletionError/transport_failure (0.00s)2151 --- PASS: TestRetryableCompletionError/deadline_exceeded (0.00s)2152 --- PASS: TestRetryableCompletionError/throttled (0.00s)2153=== CONT TestCacheConfigHandler/full_config,_no_issuer2154=== CONT TestCacheConfigHandler/no_signing_keys2155=== CONT TestCacheConfigHandler/no_cache_url_configured2156=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2157--- PASS: TestCacheConfigHandler (0.00s)2158 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2159 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2160 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2161 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2162=== CONT TestService_RequireScope_OIDC/builder_may_write2163=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2164=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21652026/11/09 12:01:20 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]2166=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2167=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2168=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2169=== CONT TestService_RequireScope_OIDC/writer_implies_read2170=== CONT TestService_RequireScope_OIDC/reader_may_read2171=== CONT TestService_RequireScope_OIDC/static_token_may_write2172=== CONT TestService_RequireScope_OIDC/static_token_may_admin2173=== CONT TestService_RequireScope_OIDC/reader_may_not_write2174=== CONT TestService_RequireScope_OIDC/ops_may_not_write2175=== CONT TestService_RequireScope_OIDC/ops_may_admin2176=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2177=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21782026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2179--- PASS: TestService_RequireScope_OIDC (0.33s)2180 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2181 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2182 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2183 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2184 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2185 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2186 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2187 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2188 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2189 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2190 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2191 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2192 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2193 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21942026/11/09 12:01:20 INFO Completed upload id=1 objects=3 duration=2.992987ms21952026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures2196=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2197=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21982026/11/09 12:01:20 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]2199=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22002026/11/09 12:01:20 WARN Authentication failed token_preview=eyJhbGciOi...oBjyU3DHag token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2201--- PASS: TestService_AuthMiddleware_OIDC (0.41s)2202 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2203 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2204 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2205 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)22062026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjM5ZGYzMjc5LTBkNGYtNDU2My1iZjhlLThiMzg2Y2ExNDJjNXgxNzk0MjI1NjgwMzYyMDg0MTIx parts=1022072026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22082026/11/09 12:01:20 INFO lead: released remote=192.0.2.1:123422092026/11/09 12:01:20 INFO Completed upload id=1 objects=3 duration=3.515492ms22102026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures22112026/11/09 12:01:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst22122026/11/09 12:01:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo22132026/11/09 12:01:20 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/present22142026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22152026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures22162026/11/09 12:01:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst22172026/11/09 12:01:20 WARN Found objects in DB but missing from S3, will re-upload count=122182026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjVhZTU5ZDA2LWNiYTctNDE1Mi1iNjg1LWU2YmYxYjNkOTBhNngxNzk0MjI1NjgwNDA3OTg5OTM0 parts=1022192026/11/09 12:01:20 INFO Aborted multipart uploads count=0 kept=022202026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22212026/11/09 12:01:20 INFO Completed upload id=1 objects=3 duration=2.876125ms22222026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures22232026/11/09 12:01:20 WARN Force mode enabled - objects will be deleted immediately without grace period22242026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22252026/11/09 12:01:20 INFO lead: acquired remote=192.0.2.1:123422262026/11/09 12:01:20 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43301/bucket105/?delete=\": context canceled"2227--- PASS: TestGCEndsOnShutdown (0.00s)2228 --- PASS: TestGCEndsOnShutdown/before_the_run (0.19s)2229 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.26s)2230 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.18s)22312026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjI3Mzg0ODg2LWE0NzEtNDA5My1hOWJlLTJkNTIzMjg0ZDUwYXgxNzk0MjI1NjgwNDM4NDUzMjQ3 parts=1022322026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22332026/11/09 12:01:20 INFO Completed upload id=1 objects=3 duration=2.590244ms22342026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures22352026/11/09 12:01:20 WARN Request failed, retrying attempt=2 backoff=188.712966ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22362026/11/09 12:01:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22372026/11/09 12:01:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2238=== NAME TestOrphanedObjectsGCStressTest2239 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2240 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22412026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22422026/11/09 12:01:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjkxMWE3YTY5LTE3MjAtNGY5MC05MTJkLTZjZjdjNTZkYWE5M3gxNzk0MjI1NjgwNjY5NDU0NTIy parts=1022432026/11/09 12:01:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22442026/11/09 12:01:20 INFO Completed upload id=2 objects=3 duration=1.378953ms22452026/11/09 12:01:20 INFO Received uploads request method=POST path=/api/pending_closures22462026/11/09 12:01:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22472026/11/09 12:01:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo22482026/11/09 12:01:20 WARN Request failed, retrying attempt=3 backoff=427.072857ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2249--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2250 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.73s)2251 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.75s)22522026/11/09 12:01:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22532026/11/09 12:01:21 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NzA1M2QyNjEtZTg5Mi00ZWE1LWFjZTUtN2EwOWM5Y2M2YWE0LjYwYTI3NDQzLTBhOTMtNGE2OS1hOWYzLTZmZjA2ZjU4ZmNlOXgxNzk0MjI1NjgwNzMwMDIyMzY2 parts=1022542026/11/09 12:01:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22552026/11/09 12:01:21 INFO Completed upload id=2 objects=3 duration=1.386492ms22562026/11/09 12:01:21 INFO Received uploads request method=POST path=/api/pending_closures22572026/11/09 12:01:21 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22582026/11/09 12:01:21 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo22592026/11/09 12:01:21 INFO lead: released remote=192.0.2.1:12342260--- PASS: TestLeadEndsOnShutdown (1.40s)2261--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2262 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2263 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)2264 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.85s)2265--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2266 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.61s)2267 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.62s)2268 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.59s)2269 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (0.89s)2270 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (0.88s)2271--- PASS: TestDeleteClosuresRacingPins (1.44s)2272--- PASS: TestPendingClosureWriteTimeout (0.00s)2273 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2274 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2275 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2276 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)22772026/11/09 12:01:21 WARN Request failed, retrying attempt=4 backoff=777.791374ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2278=== NAME TestOrphanedObjectsGCStressTest2279 orphaned_objects_gc_test.go:503: Stress test completed successfully:2280 orphaned_objects_gc_test.go:504: - Active objects preserved: 202281 orphaned_objects_gc_test.go:505: - Objects deleted: 2102282 orphaned_objects_gc_test.go:506: - Total GC'd: 2102283--- PASS: TestOrphanedObjectsGCStressTest (2.89s)22842026/11/09 12:01:21 INFO lead: released remote=192.0.2.1:12342285--- PASS: TestLeadElectsOneAndHandsOver (2.90s)22862026/11/09 12:01:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022872026/11/09 12:01:21 INFO Received create pin request method=POST path=/api/pins/myapp22882026/11/09 12:01:22 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3051231808/001/store/axbxhsfsvz3435il5svi75vq6yq2g97p-pinned-file.txt narinfo_key=axbxhsfsvz3435il5svi75vq6yq2g97p.narinfo22892026/11/09 12:01:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures22902026/11/09 12:01:22 INFO Garbage collection started22912026/11/09 12:01:22 INFO Aborted multipart uploads count=0 kept=022922026/11/09 12:01:22 WARN Force mode enabled - objects will be deleted immediately without grace period22932026/11/09 12:01:22 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=022942026/11/09 12:01:22 INFO Vacuumed table table=pending_closures22952026/11/09 12:01:22 INFO Vacuumed table table=pending_objects22962026/11/09 12:01:22 INFO Vacuumed table table=multipart_uploads22972026/11/09 12:01:22 INFO Vacuumed table table=closures22982026/11/09 12:01:22 INFO Vacuumed table table=objects22992026/11/09 12:01:22 WARN Request failed, retrying attempt=5 backoff=1.454888189s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23002026/11/09 12:01:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02301=== NAME TestClientIntegration2302 client_integration_test.go:370: Objects in database after GC:2303 client_integration_test.go:370: Successfully deleted all objects with GC --force2304--- PASS: TestClientIntegration (2.69s)2305--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.73s)23062026/11/09 12:01:23 WARN Rate limiter enabled after throttle name=s3-test rate=523072026/11/09 12:01:23 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2308=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2309 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102310 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002311--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.55s)23122026/11/09 12:01:23 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-config23132026/11/09 12:01:23 WARN Request failed, retrying attempt=2 backoff=197.017425ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23142026/11/09 12:01:23 WARN Request failed, retrying attempt=3 backoff=370.159221ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2315=== NAME TestPinProtectsFromGC2316 client_integration_test.go:887: Pin successfully protected closure from garbage collection2317--- PASS: TestPinProtectsFromGC (4.69s)2318--- PASS: TestConnectWaitsForAPeerMigration (5.28s)23192026/11/09 12:01:24 WARN Request failed, retrying attempt=4 backoff=777.789697ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23202026/11/09 12:01:25 WARN Request failed, retrying attempt=5 backoff=1.484744453s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23212026/11/09 12:01:25 INFO Aborted multipart uploads count=1 kept=023222026/11/09 12:01:25 INFO Received cleanup request method=DELETE path=/api/pending_closures23232026/11/09 12:01:25 INFO Aborted multipart uploads count=1 kept=02324--- PASS: TestPendingCleanupUsesOneCutoff (6.63s)23252026/11/09 12:01:26 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"23262026/11/09 12:01:26 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-config23272026/11/09 12:01:26 WARN Request failed, retrying attempt=2 backoff=203.275871ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23282026/11/09 12:01:26 WARN Request failed, retrying attempt=3 backoff=401.331471ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23292026/11/09 12:01:27 WARN Request failed, retrying attempt=4 backoff=790.83956ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23302026/11/09 12:01:28 WARN Request failed, retrying attempt=5 backoff=1.530169462s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23312026/11/09 12:01:29 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_closures23322026/11/09 12:01:29 WARN Request failed, retrying attempt=2 backoff=195.717588ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23332026/11/09 12:01:29 WARN Request failed, retrying attempt=3 backoff=366.933033ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23342026/11/09 12:01:30 WARN Request failed, retrying attempt=4 backoff=724.700484ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23352026/11/09 12:01:31 WARN Request failed, retrying attempt=5 backoff=1.712620639s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2336--- PASS: TestClientErrorHandling (0.00s)2337 --- PASS: TestClientErrorHandling/InvalidStorePath (0.18s)2338 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)2339 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.16s)2340PASS2341{"timestamp":"2026-11-09T12:01:32.759225017Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:45700","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}23422026-11-09 12:01:32.979 UTC [129] LOG: received smart shutdown request23432026-11-09 12:01:32.984 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 123442026-11-09 12:01:32.994 UTC [134] LOG: shutting down23452026-11-09 12:01:32.994 UTC [134] LOG: checkpoint starting: shutdown immediate23462026-11-09 12:01:33.909 UTC [134] LOG: checkpoint complete: wrote 10696 buffers (65.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.186 s, sync=0.693 s, total=0.916 s; sync files=36397, longest=0.003 s, average=0.001 s; distance=525998 kB, estimate=525998 kB; lsn=0/21911600, redo lsn=0/2191160023472026-11-09 12:01:33.977 UTC [129] LOG: database system is shut down2348Running OIDC tests...2349=== RUN TestAudienceForIssuer2350=== PAUSE TestAudienceForIssuer2351=== RUN TestGlobMatch2352=== PAUSE TestGlobMatch2353=== RUN TestValidateToken_ValidToken2354=== PAUSE TestValidateToken_ValidToken2355=== RUN TestValidateToken_WrongAudience2356=== PAUSE TestValidateToken_WrongAudience2357=== RUN TestValidateToken_Expired2358=== PAUSE TestValidateToken_Expired2359=== RUN TestValidateToken_BoundClaimsMismatch2360=== PAUSE TestValidateToken_BoundClaimsMismatch2361=== RUN TestValidateToken_BoundSubjectMismatch2362=== PAUSE TestValidateToken_BoundSubjectMismatch2363=== RUN TestValidateToken_MultipleProviders2364=== PAUSE TestValidateToken_MultipleProviders2365=== RUN TestValidateToken_NoMatchingProvider2366=== PAUSE TestValidateToken_NoMatchingProvider2367=== RUN TestValidateToken_KubernetesServiceAccount2368=== PAUSE TestValidateToken_KubernetesServiceAccount2369=== RUN TestNewValidator_KubernetesRequiresCA2370=== PAUSE TestNewValidator_KubernetesRequiresCA2371=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2372=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2373=== RUN TestPins_ReservedForMatchingRule2374=== PAUSE TestPins_ReservedForMatchingRule2375=== RUN TestPins_TopLevelShorthand2376=== PAUSE TestPins_TopLevelShorthand2377=== RUN TestPins_ConfigValidation2378=== PAUSE TestPins_ConfigValidation2379=== RUN TestScopes_LegacyProviderDefaultsToWrite2380=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2381=== RUN TestScopes_Rules2382=== PAUSE TestScopes_Rules2383=== RUN TestScopes_ConfigValidation2384=== PAUSE TestScopes_ConfigValidation2385=== CONT TestAudienceForIssuer2386=== CONT TestPins_ConfigValidation2387--- PASS: TestAudienceForIssuer (0.00s)2388=== CONT TestValidateToken_NoMatchingProvider2389=== CONT TestPins_ReservedForMatchingRule2390=== CONT TestScopes_Rules2391=== CONT TestValidateToken_Expired2392=== CONT TestValidateToken_ValidToken2393=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2394=== CONT TestValidateToken_BoundSubjectMismatch2395--- PASS: TestPins_ConfigValidation (0.00s)2396=== CONT TestScopes_LegacyProviderDefaultsToWrite2397=== CONT TestValidateToken_BoundClaimsMismatch2398=== CONT TestNewValidator_KubernetesRequiresCA2399=== CONT TestValidateToken_WrongAudience2400=== CONT TestGlobMatch2401=== RUN TestGlobMatch/foo_foo2402=== PAUSE TestGlobMatch/foo_foo2403=== RUN TestGlobMatch/foo_bar2404=== PAUSE TestGlobMatch/foo_bar2405=== RUN TestGlobMatch/*_2406=== PAUSE TestGlobMatch/*_2407=== RUN TestGlobMatch/*_anything2408=== PAUSE TestGlobMatch/*_anything2409=== RUN TestGlobMatch/foo*_foo2410=== PAUSE TestGlobMatch/foo*_foo2411=== RUN TestGlobMatch/foo*_foobar2412=== PAUSE TestGlobMatch/foo*_foobar2413=== RUN TestGlobMatch/foo*_bar2414=== PAUSE TestGlobMatch/foo*_bar2415=== CONT TestScopes_ConfigValidation2416=== CONT TestPins_TopLevelShorthand2417=== CONT TestValidateToken_KubernetesServiceAccount2418=== CONT TestValidateToken_MultipleProviders2419=== RUN TestGlobMatch/*bar_bar2420=== PAUSE TestGlobMatch/*bar_bar2421=== RUN TestGlobMatch/*bar_foobar2422=== PAUSE TestGlobMatch/*bar_foobar2423=== RUN TestGlobMatch/*bar_foo2424=== PAUSE TestGlobMatch/*bar_foo2425=== RUN TestGlobMatch/foo*bar_foobar2426=== PAUSE TestGlobMatch/foo*bar_foobar2427=== RUN TestGlobMatch/foo*bar_foo123bar2428=== PAUSE TestGlobMatch/foo*bar_foo123bar2429=== RUN TestGlobMatch/foo*bar_foobarbaz2430=== PAUSE TestGlobMatch/foo*bar_foobarbaz2431=== RUN TestGlobMatch/*/*_foo/bar2432--- PASS: TestScopes_ConfigValidation (0.00s)2433=== PAUSE TestGlobMatch/*/*_foo/bar2434=== RUN TestGlobMatch/*/*_foo2435=== PAUSE TestGlobMatch/*/*_foo2436=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2437=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2438=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02439=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02440=== RUN TestGlobMatch/refs/*/main_refs/heads/main2441=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2442=== RUN TestGlobMatch/fo?_foo2443=== PAUSE TestGlobMatch/fo?_foo2444=== RUN TestGlobMatch/fo?_fo2445=== PAUSE TestGlobMatch/fo?_fo2446=== RUN TestGlobMatch/fo?_fooo2447=== PAUSE TestGlobMatch/fo?_fooo2448=== RUN TestGlobMatch/?oo_foo2449=== PAUSE TestGlobMatch/?oo_foo2450=== RUN TestGlobMatch/?oo_boo2451=== PAUSE TestGlobMatch/?oo_boo2452=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2453=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2454=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2455=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2456=== CONT TestGlobMatch/foo_foo2457=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2458=== CONT TestGlobMatch/foo*_foobar2459=== CONT TestGlobMatch/fo?_foo2460=== CONT TestGlobMatch/?oo_boo2461=== CONT TestGlobMatch/?oo_foo2462=== CONT TestGlobMatch/fo?_fooo2463=== CONT TestGlobMatch/fo?_fo2464=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2465=== CONT TestGlobMatch/refs/*/main_refs/heads/main2466=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02467=== CONT TestGlobMatch/*bar_foobar2468=== CONT TestGlobMatch/*/*_foo2469=== CONT TestGlobMatch/*bar_bar2470=== CONT TestGlobMatch/*/*_foo/bar2471=== CONT TestGlobMatch/foo*_bar2472=== CONT TestGlobMatch/foo*bar_foobarbaz2473=== CONT TestGlobMatch/foo*_foo2474=== CONT TestGlobMatch/*_anything2475=== CONT TestGlobMatch/*_2476=== CONT TestGlobMatch/foo_bar2477=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2478=== CONT TestGlobMatch/*bar_foo2479=== CONT TestGlobMatch/foo*bar_foo123bar2480=== CONT TestGlobMatch/foo*bar_foobar2481--- PASS: TestGlobMatch (0.00s)2482 --- PASS: TestGlobMatch/foo_foo (0.00s)2483 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2484 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2485 --- PASS: TestGlobMatch/fo?_foo (0.00s)2486 --- PASS: TestGlobMatch/?oo_boo (0.00s)2487 --- PASS: TestGlobMatch/?oo_foo (0.00s)2488 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2489 --- PASS: TestGlobMatch/fo?_fo (0.00s)2490 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2491 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2492 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2493 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2494 --- PASS: TestGlobMatch/*/*_foo (0.00s)2495 --- PASS: TestGlobMatch/*bar_bar (0.00s)2496 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2497 --- PASS: TestGlobMatch/foo*_bar (0.00s)2498 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2499 --- PASS: TestGlobMatch/foo*_foo (0.00s)2500 --- PASS: TestGlobMatch/*_anything (0.00s)2501 --- PASS: TestGlobMatch/*_ (0.00s)2502 --- PASS: TestGlobMatch/foo_bar (0.00s)2503 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2504 --- PASS: TestGlobMatch/*bar_foo (0.00s)2505 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2506 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)25072026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34153/oidc2508--- PASS: TestValidateToken_Expired (0.04s)25092026/11/09 12:01:35 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232510--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)25112026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44699/oidc2512--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)25132026/11/09 12:01:35 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:404912514--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)25152026/11/09 12:01:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35337/oidc25162026/11/09 12:01:35 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:36993/oidc2517--- PASS: TestValidateToken_MultipleProviders (0.13s)25182026/11/09 12:01:35 http: TLS handshake error from 127.0.0.1:41046: remote error: tls: bad certificate2519--- PASS: TestNewValidator_KubernetesRequiresCA (0.14s)25202026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40711/oidc2521--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)25222026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36945/oidc2523--- PASS: TestValidateToken_BoundClaimsMismatch (0.17s)25242026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44011/oidc25252026/11/09 12:01:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36373/oidc2526--- PASS: TestPins_TopLevelShorthand (0.19s)2527--- PASS: TestValidateToken_NoMatchingProvider (0.20s)25282026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43619/oidc2529--- PASS: TestPins_ReservedForMatchingRule (0.25s)25302026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34863/oidc2531--- PASS: TestValidateToken_ValidToken (0.25s)25322026/11/09 12:01:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39847/oidc2533--- PASS: TestValidateToken_WrongAudience (0.32s)25342026/11/09 12:01:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36175/oidc2535--- PASS: TestScopes_Rules (0.55s)2536PASS2537Running hook tests...2538=== RUN TestSendPathsEmpty2539=== PAUSE TestSendPathsEmpty2540=== RUN TestQueueEnqueueAndFetch2541=== PAUSE TestQueueEnqueueAndFetch2542=== RUN TestQueueDeduplication2543=== PAUSE TestQueueDeduplication2544=== RUN TestQueueRemove2545=== PAUSE TestQueueRemove2546=== RUN TestQueueFetchBatchLimit2547=== PAUSE TestQueueFetchBatchLimit2548=== RUN TestQueueRetryMovesToBack2549=== PAUSE TestQueueRetryMovesToBack2550=== RUN TestQueueFetchRemoveLifecycle2551=== PAUSE TestQueueFetchRemoveLifecycle2552=== RUN TestQueueConcurrentWriters2553=== PAUSE TestQueueConcurrentWriters2554=== RUN TestQueueRemoveLargeClosure2555=== PAUSE TestQueueRemoveLargeClosure2556=== RUN TestServerClientIntegration2557--- PASS: TestServerClientIntegration (0.00s)2558=== RUN TestServerQueueError25592026/11/09 12:01:36 ERROR Failed to queue paths error="permission denied" count=12560--- PASS: TestServerQueueError (0.00s)2561=== RUN TestGetListenerSocketActivation2562 server_test.go:218: === RUN TestGetListenerSocketActivation2563 --- PASS: TestGetListenerSocketActivation (0.00s)2564 PASS2565 2566--- PASS: TestGetListenerSocketActivation (0.01s)2567=== RUN TestServerStalledClientDoesNotBlockShutdown2568=== PAUSE TestServerStalledClientDoesNotBlockShutdown2569=== RUN TestServerBacksOffOnAcceptErrors2570=== PAUSE TestServerBacksOffOnAcceptErrors2571=== RUN TestDrainIsolatesPoisonPath2572=== PAUSE TestDrainIsolatesPoisonPath2573=== RUN TestRunNotBlockedByPoisonHead2574=== PAUSE TestRunNotBlockedByPoisonHead2575=== RUN TestDrainGivesUpWhenServerDown2576=== PAUSE TestDrainGivesUpWhenServerDown2577=== RUN TestFailedPathPrunedByLaterClosure2578=== PAUSE TestFailedPathPrunedByLaterClosure2579=== RUN TestWorkerUploadsAndRemoves2580=== PAUSE TestWorkerUploadsAndRemoves2581=== RUN TestWorkerSkipsGCdPaths2582=== PAUSE TestWorkerSkipsGCdPaths2583=== RUN TestWorkerPrunesClosureDeps2584=== PAUSE TestWorkerPrunesClosureDeps2585=== RUN TestDrainTimeout2586=== PAUSE TestDrainTimeout2587=== RUN TestWorkerRemoveFailureIsNotProgress2588=== PAUSE TestWorkerRemoveFailureIsNotProgress2589=== RUN TestWorkerKeepsPathItCannotStat2590=== PAUSE TestWorkerKeepsPathItCannotStat2591=== CONT TestSendPathsEmpty2592=== CONT TestFailedPathPrunedByLaterClosure2593=== CONT TestWorkerUploadsAndRemoves2594=== CONT TestServerBacksOffOnAcceptErrors25952026/11/09 12:01:36 ERROR Accept failed error="too many open files"2596--- PASS: TestSendPathsEmpty (0.00s)2597=== CONT TestWorkerKeepsPathItCannotStat2598=== CONT TestWorkerRemoveFailureIsNotProgress2599=== CONT TestServerStalledClientDoesNotBlockShutdown2600=== CONT TestDrainTimeout2601=== CONT TestQueueRemoveLargeClosure2602=== CONT TestWorkerPrunesClosureDeps2603=== CONT TestQueueConcurrentWriters2604=== CONT TestWorkerSkipsGCdPaths2605=== CONT TestQueueFetchRemoveLifecycle2606=== CONT TestQueueEnqueueAndFetch2607=== CONT TestQueueRemove2608=== CONT TestQueueRetryMovesToBack2609=== CONT TestQueueFetchBatchLimit2610=== CONT TestRunNotBlockedByPoisonHead2611=== CONT TestQueueDeduplication2612=== CONT TestDrainIsolatesPoisonPath2613=== CONT TestDrainGivesUpWhenServerDown26142026/11/09 12:01:36 ERROR Accept failed error="too many open files"26152026/11/09 12:01:36 INFO Uploading batch count=226162026/11/09 12:01:36 INFO Upload queue status pending=226172026/11/09 12:01:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths759733862/002/nonexistent26182026/11/09 12:01:36 INFO Upload queue status pending=226192026/11/09 12:01:36 INFO Uploading batch count=426202026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=426212026/11/09 12:01:36 INFO Uploading batch count=22622--- PASS: TestQueueFetchBatchLimit (0.01s)26232026/11/09 12:01:36 INFO Uploading batch count=126242026/11/09 12:01:36 INFO Uploading batch count=126252026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=126262026/11/09 12:01:36 INFO Upload queue status pending=326272026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2815384230/002/bbb26282026/11/09 12:01:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa: permission denied"2629--- PASS: TestQueueDeduplication (0.01s)26302026/11/09 12:01:36 INFO Upload queue status pending=226312026/11/09 12:01:36 INFO Uploading batch count=126322026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=126332026/11/09 12:01:36 INFO Uploading batch count=12634--- PASS: TestQueueFetchRemoveLifecycle (0.01s)26352026/11/09 12:01:36 INFO Uploading batch count=126362026/11/09 12:01:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa: permission denied"26372026/11/09 12:01:36 INFO Uploading batch count=22638--- PASS: TestQueueRetryMovesToBack (0.01s)26392026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=226402026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/a26412026/11/09 12:01:36 INFO Uploading batch count=126422026/11/09 12:01:36 ERROR Accept failed error="too many open files"26432026/11/09 12:01:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3908065531/002/nonexistent2644--- PASS: TestQueueEnqueueAndFetch (0.01s)26452026/11/09 12:01:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126462026/11/09 12:01:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1751279474/002/locked/aaa: permission denied"26472026/11/09 12:01:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3908065531/002/nonexistent26482026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/b26492026/11/09 12:01:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12650--- PASS: TestQueueRemove (0.01s)26512026/11/09 12:01:36 INFO Uploading batch count=126522026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=126532026/11/09 12:01:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress3908065531/002/nonexistent26542026/11/09 12:01:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126552026/11/09 12:01:36 ERROR Drain finished with paths left in queue remaining=126562026/11/09 12:01:36 INFO Uploading batch count=126572026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=126582026/11/09 12:01:36 ERROR Drain finished with paths left in queue remaining=126592026/11/09 12:01:36 INFO Uploading batch count=226602026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=226612026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/c2662--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)26632026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/d26642026/11/09 12:01:36 INFO Uploading batch count=126652026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=12666--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)26672026/11/09 12:01:36 ERROR Drain finished with paths left in queue remaining=126682026/11/09 12:01:36 INFO Uploading batch count=226692026/11/09 12:01:36 ERROR Upload failed error="upload failed" count=226702026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/e2671--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)26722026/11/09 12:01:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1379970879/002/f26732026/11/09 12:01:36 ERROR Drain finished with paths left in queue remaining=102674--- PASS: TestDrainIsolatesPoisonPath (0.02s)2675--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2676--- PASS: TestWorkerSkipsGCdPaths (0.03s)2677--- PASS: TestWorkerUploadsAndRemoves (0.03s)26782026/11/09 12:01:36 ERROR Accept failed error="too many open files"2679--- PASS: TestWorkerPrunesClosureDeps (0.04s)26802026/11/09 12:01:36 ERROR Accept failed error="too many open files"2681--- PASS: TestQueueRemoveLargeClosure (0.11s)2682--- PASS: TestQueueConcurrentWriters (0.11s)26832026/11/09 12:01:36 ERROR Accept failed error="too many open files"26842026/11/09 12:01:36 ERROR Failed to decode request error="read unix /build/hook25240602/test.sock->@: i/o timeout"26852026/11/09 12:01:36 ERROR Failed to write response error="write unix /build/hook25240602/test.sock->@: i/o timeout"2686--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26872026/11/09 12:01:36 ERROR Upload failed error="context deadline exceeded" count=226882026/11/09 12:01:36 ERROR Drain finished with paths left in queue remaining=42689--- PASS: TestDrainTimeout (0.21s)26902026/11/09 12:01:36 ERROR Accept failed error="too many open files"26912026/11/09 12:01:36 ERROR Accept failed error="too many open files"2692--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26932026/11/09 12:01:37 INFO Uploading batch count=126942026/11/09 12:01:37 INFO Uploading batch count=126952026/11/09 12:01:37 INFO Uploading batch count=126962026/11/09 12:01:37 ERROR Upload failed error="upload failed" count=126972026/11/09 12:01:37 INFO Uploading batch count=126982026/11/09 12:01:37 ERROR Upload failed error="upload failed" count=126992026/11/09 12:01:37 INFO Uploading batch count=127002026/11/09 12:01:37 ERROR Upload failed error="upload failed" count=127012026/11/09 12:01:37 INFO Uploading batch count=127022026/11/09 12:01:37 ERROR Upload failed error="upload failed" count=127032026/11/09 12:01:37 ERROR Drain finished with paths left in queue remaining=12704--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2705PASS2706Running signing tests...2707=== RUN TestExternalSigner2708=== PAUSE TestExternalSigner2709=== RUN TestExternalSignerWrongPublicKey2710=== PAUSE TestExternalSignerWrongPublicKey2711=== RUN TestExternalSignerErrors2712=== PAUSE TestExternalSignerErrors2713=== RUN TestExternalSignerRestartsAfterCrash2714=== PAUSE TestExternalSignerRestartsAfterCrash2715=== RUN TestExternalSignerProgramErrorKeepsProcess2716=== PAUSE TestExternalSignerProgramErrorKeepsProcess2717=== RUN TestExternalSignerClose2718=== PAUSE TestExternalSignerClose2719=== RUN TestExternalSignerRejectsInvalidPublicKey2720=== PAUSE TestExternalSignerRejectsInvalidPublicKey2721=== RUN TestExternalSignerCancellation2722=== PAUSE TestExternalSignerCancellation2723=== RUN TestGenerateFingerprint2724=== PAUSE TestGenerateFingerprint2725=== RUN TestParseSigningKey2726=== PAUSE TestParseSigningKey2727=== RUN TestSign2728=== PAUSE TestSign2729=== RUN TestSignBatch2730=== PAUSE TestSignBatch2731=== RUN TestNilKeyPublicKey2732=== PAUSE TestNilKeyPublicKey2733=== RUN TestSignErrors2734=== PAUSE TestSignErrors2735=== CONT TestExternalSigner2736=== CONT TestExternalSignerCancellation2737=== CONT TestSignBatch2738=== CONT TestSignErrors2739=== CONT TestExternalSignerRejectsInvalidPublicKey2740=== RUN TestExternalSignerRejectsInvalidPublicKey/#002741=== CONT TestExternalSignerClose2742=== CONT TestExternalSignerProgramErrorKeepsProcess2743=== CONT TestExternalSignerRestartsAfterCrash2744=== CONT TestExternalSignerErrors2745=== RUN TestExternalSignerErrors/null_signatures2746=== PAUSE TestExternalSignerErrors/null_signatures2747=== CONT TestExternalSignerWrongPublicKey2748=== CONT TestNilKeyPublicKey2749=== CONT TestParseSigningKey2750=== CONT TestSign2751=== CONT TestGenerateFingerprint2752=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002753=== RUN TestExternalSignerErrors/wrong_signatures_shape2754=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2755=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2756=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2757=== RUN TestGenerateFingerprint/basic_with_references2758=== RUN TestParseSigningKey/valid_32-byte_key2759--- PASS: TestNilKeyPublicKey (0.00s)2760=== RUN TestExternalSignerErrors/missing_signature_name2761=== PAUSE TestParseSigningKey/valid_32-byte_key2762=== PAUSE TestGenerateFingerprint/basic_with_references2763=== PAUSE TestExternalSignerErrors/missing_signature_name2764=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2765=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2766=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2767=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2768=== RUN TestParseSigningKey/no_colon2769=== PAUSE TestParseSigningKey/no_colon2770=== RUN TestParseSigningKey/empty_name2771=== PAUSE TestParseSigningKey/empty_name2772=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2773=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2774=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2775=== RUN TestGenerateFingerprint/no_references2776=== PAUSE TestGenerateFingerprint/no_references2777=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2778=== RUN TestExternalSignerErrors/null2779=== PAUSE TestExternalSignerErrors/null2780=== RUN TestExternalSignerErrors/unrequested_key2781=== RUN TestParseSigningKey/invalid_base642782=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2783=== CONT TestExternalSignerRejectsInvalidPublicKey/#002784=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2785=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2786=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2787=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2788--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2789 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2790 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2791 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2792 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2793 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2794=== PAUSE TestParseSigningKey/invalid_base642795=== RUN TestParseSigningKey/wrong_length2796=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2797=== PAUSE TestExternalSignerErrors/unrequested_key2798=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2799=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2800=== RUN TestGenerateFingerprint/invalid_nar_hash_length2801=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2802=== RUN TestGenerateFingerprint/invalid_store_path_prefix2803=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2804=== RUN TestGenerateFingerprint/invalid_reference_prefix2805=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2806=== CONT TestGenerateFingerprint/basic_with_references2807=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2808=== PAUSE TestParseSigningKey/wrong_length2809=== CONT TestParseSigningKey/valid_32-byte_key2810=== CONT TestParseSigningKey/invalid_base642811=== CONT TestGenerateFingerprint/no_references2812=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2813=== RUN TestExternalSignerErrors/wrong_signature_length2814=== PAUSE TestExternalSignerErrors/wrong_signature_length2815=== CONT TestGenerateFingerprint/invalid_nar_hash_length2816=== CONT TestGenerateFingerprint/invalid_store_path_prefix2817=== CONT TestGenerateFingerprint/invalid_reference_prefix2818=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2819--- PASS: TestGenerateFingerprint (0.00s)2820 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2821 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2822 --- PASS: TestGenerateFingerprint/no_references (0.00s)2823 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2824 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2825 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2826 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2827=== RUN TestSignErrors/nil_key2828=== PAUSE TestSignErrors/nil_key2829=== CONT TestParseSigningKey/no_colon2830=== CONT TestParseSigningKey/wrong_length2831=== RUN TestExternalSignerErrors/exit_on_request2832=== PAUSE TestExternalSignerErrors/exit_on_request2833=== RUN TestSignErrors/nil_narinfo2834--- PASS: TestSign (0.00s)2835=== CONT TestParseSigningKey/empty_name2836=== RUN TestExternalSignerErrors/invalid_JSON2837=== PAUSE TestExternalSignerErrors/invalid_JSON2838=== PAUSE TestSignErrors/nil_narinfo2839=== RUN TestSignErrors/invalid_narinfo2840=== PAUSE TestSignErrors/invalid_narinfo2841=== RUN TestSignErrors/canceled2842=== PAUSE TestSignErrors/canceled2843=== CONT TestSignErrors/nil_key2844--- PASS: TestParseSigningKey (0.00s)2845 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2846 --- PASS: TestParseSigningKey/no_colon (0.00s)2847 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2848 --- PASS: TestParseSigningKey/wrong_length (0.00s)2849 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2850 --- PASS: TestParseSigningKey/empty_name (0.00s)2851=== CONT TestSignErrors/canceled2852=== CONT TestSignErrors/nil_narinfo2853=== RUN TestExternalSignerErrors/wrong_id2854=== PAUSE TestExternalSignerErrors/wrong_id2855=== CONT TestSignErrors/invalid_narinfo2856--- PASS: TestSignErrors (0.00s)2857 --- PASS: TestSignErrors/nil_key (0.00s)2858 --- PASS: TestSignErrors/canceled (0.00s)2859 --- PASS: TestSignErrors/nil_narinfo (0.00s)2860 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2861=== RUN TestExternalSignerErrors/wrong_signature_name2862=== PAUSE TestExternalSignerErrors/wrong_signature_name2863=== RUN TestExternalSignerErrors/invalid_signature_base642864=== PAUSE TestExternalSignerErrors/invalid_signature_base642865=== RUN TestExternalSignerErrors/program_error2866=== PAUSE TestExternalSignerErrors/program_error2867=== RUN TestExternalSignerErrors/too_few_signatures2868=== PAUSE TestExternalSignerErrors/too_few_signatures2869=== RUN TestExternalSignerErrors/exit_at_startup2870=== PAUSE TestExternalSignerErrors/exit_at_startup2871=== RUN TestExternalSignerErrors/wrong_shape2872=== PAUSE TestExternalSignerErrors/wrong_shape2873=== RUN TestExternalSignerErrors/missing_signatures2874=== PAUSE TestExternalSignerErrors/missing_signatures2875=== CONT TestExternalSignerErrors/null_signatures2876=== CONT TestExternalSignerErrors/wrong_shape2877=== CONT TestExternalSignerErrors/unrequested_key2878--- PASS: TestSignBatch (0.00s)2879=== CONT TestExternalSignerErrors/wrong_signature_length2880=== CONT TestExternalSignerErrors/wrong_signatures_shape2881=== CONT TestExternalSignerErrors/too_few_signatures2882=== CONT TestExternalSignerErrors/missing_signatures2883--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2884=== CONT TestExternalSignerErrors/wrong_signature_name2885=== CONT TestExternalSignerErrors/wrong_id2886=== CONT TestExternalSignerErrors/invalid_JSON2887=== CONT TestExternalSignerErrors/exit_on_request2888=== CONT TestExternalSignerErrors/null2889=== CONT TestExternalSignerErrors/exit_at_startup2890=== CONT TestExternalSignerErrors/program_error2891=== CONT TestExternalSignerErrors/missing_signature_name2892=== CONT TestExternalSignerErrors/invalid_signature_base642893--- PASS: TestExternalSignerWrongPublicKey (0.01s)2894--- PASS: TestExternalSignerClose (0.01s)2895--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2896--- PASS: TestExternalSigner (0.01s)2897--- PASS: TestExternalSignerErrors (0.00s)2898 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2899 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2900 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2901 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)2902 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2903 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2904 --- PASS: TestExternalSignerErrors/null (0.00s)2905 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2906 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2907 --- PASS: TestExternalSignerErrors/program_error (0.00s)2908 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2909 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2910 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2911 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2912 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2913 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2914--- PASS: TestExternalSignerCancellation (0.02s)2915PASS2916Running OpenBao signer tests...2917=== RUN TestSign2918=== PAUSE TestSign2919=== RUN TestSignErrors2920=== PAUSE TestSignErrors2921=== RUN TestServe2922=== PAUSE TestServe2923=== RUN TestServeRejectsGarbage2924=== PAUSE TestServeRejectsGarbage2925=== CONT TestSign2926=== CONT TestServeRejectsGarbage2927=== CONT TestServe2928--- PASS: TestServeRejectsGarbage (0.00s)2929=== CONT TestSignErrors2930=== RUN TestSignErrors/http_error2931=== PAUSE TestSignErrors/http_error2932=== RUN TestSignErrors/invalid_json2933=== PAUSE TestSignErrors/invalid_json2934=== RUN TestSignErrors/no_prefix2935=== PAUSE TestSignErrors/no_prefix2936=== RUN TestSignErrors/invalid_base642937=== PAUSE TestSignErrors/invalid_base642938=== CONT TestSignErrors/http_error2939=== CONT TestSignErrors/invalid_base642940=== CONT TestSignErrors/no_prefix2941=== CONT TestSignErrors/invalid_json2942--- PASS: TestServe (0.00s)2943--- PASS: TestSign (0.01s)2944--- PASS: TestSignErrors (0.00s)2945 --- PASS: TestSignErrors/invalid_json (0.00s)2946 --- PASS: TestSignErrors/no_prefix (0.00s)2947 --- PASS: TestSignErrors/http_error (0.00s)2948 --- PASS: TestSignErrors/invalid_base64 (0.00s)2949PASS