niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #400
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestRetryTimeoutOutlastsMaxRetries56=== PAUSE TestRetryTimeoutOutlastsMaxRetries57=== RUN TestShellSplit58=== PAUSE TestShellSplit59=== RUN TestShellSplitErrors60=== PAUSE TestShellSplitErrors61=== RUN TestStreamPushReportsEveryPath62=== PAUSE TestStreamPushReportsEveryPath63=== RUN TestStreamPushBatchesUnderLoad64=== PAUSE TestStreamPushBatchesUnderLoad65=== RUN TestStreamPushIsolatesFailures66=== PAUSE TestStreamPushIsolatesFailures67=== RUN TestStreamPushGivesUpOnDeadServer68=== PAUSE TestStreamPushGivesUpOnDeadServer69=== RUN TestStreamPushRequestLine70=== PAUSE TestStreamPushRequestLine71=== RUN TestStreamPushReportsSignatures72=== PAUSE TestStreamPushReportsSignatures73=== RUN TestStreamPushReportsSkippedPaths74=== PAUSE TestStreamPushReportsSkippedPaths75=== RUN TestClientSignaturesByStorePath76=== PAUSE TestClientSignaturesByStorePath77=== RUN TestStreamPushStopsWhenCanceled78=== PAUSE TestStreamPushStopsWhenCanceled79=== RUN TestSetClientTLS80=== PAUSE TestSetClientTLS81=== RUN TestSetClientTLSDoesNotMutateDefaultTransport82=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport83=== RUN TestSetClientTLSErrors84=== PAUSE TestSetClientTLSErrors85=== RUN TestStaticToken86=== PAUSE TestStaticToken87=== RUN TestFileTokenReadsAndCaches88=== PAUSE TestFileTokenReadsAndCaches89=== RUN TestFileTokenMissing90=== PAUSE TestFileTokenMissing91=== RUN TestFileTokenEmpty92=== PAUSE TestFileTokenEmpty93=== RUN TestScriptTokenNoExpiryRerunsEveryCall94=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall95=== RUN TestScriptTokenCachesUntilRefresh96=== PAUSE TestScriptTokenCachesUntilRefresh97=== RUN TestScriptTokenEmptyToken98=== PAUSE TestScriptTokenEmptyToken99=== RUN TestScriptTokenBadJSON100=== PAUSE TestScriptTokenBadJSON101=== RUN TestScriptTokenScriptFails102=== PAUSE TestScriptTokenScriptFails103=== RUN TestScriptTokenEmptyCommand104=== PAUSE TestScriptTokenEmptyCommand105=== CONT TestScriptTokenScriptFails106=== CONT TestDoServerRequestAttachesToken107=== CONT TestDoWithRetry_BodyReplayedViaGetBody108=== CONT TestResolveStorePath109=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess110=== CONT TestRateLimiterFeedback111=== RUN TestRateLimiterFeedback/429_enables_limiter112=== PAUSE TestRateLimiterFeedback/429_enables_limiter113=== RUN TestRateLimiterFeedback/503_enables_limiter114=== PAUSE TestRateLimiterFeedback/503_enables_limiter115=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter116=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter117=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter118=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter119=== CONT TestPathInfoCACompatibility120=== RUN TestPathInfoCACompatibility/null_ca_field121=== PAUSE TestPathInfoCACompatibility/null_ca_field122=== RUN TestPathInfoCACompatibility/old_string_format_-_text123=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text124=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive125=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive126=== RUN TestPathInfoCACompatibility/new_structured_format_-_text127--- PASS: TestResolveStorePath (0.00s)128=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica1292026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=5130=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text131--- PASS: TestScriptTokenScriptFails (0.00s)132=== CONT TestParsePathInfoJSON133=== CONT TestPathInfoHashCompatibility134=== CONT TestGetStorePathHash135=== CONT TestConvertHashToNix32136=== CONT TestEncodeNixBase32WithRealHash137=== CONT TestEncodeNixBase32138=== CONT TestDumpPathWriterError139=== CONT TestDumpPathSingleFile140=== CONT TestDumpPathMatchesNix141=== CONT TestUploadMultipart_SupersededByPeer142=== CONT TestPartSizeForNAR143=== CONT TestUploadMultipart_PartsInParallel144=== CONT TestFilterOversizedClosures145=== CONT TestCaseHackSuffix146=== CONT TestRetryTimeoutOutlastsMaxRetries147=== CONT TestSetClientTLS148=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun149=== CONT TestParsePathInfoJSONMultiplePaths150=== RUN TestParsePathInfoJSON/Nix_format151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155--- PASS: TestEncodeNixBase32WithRealHash (0.00s)156=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method157=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158=== CONT TestClientSignaturesByStorePath159=== CONT TestStreamPushReportsSkippedPaths160=== CONT TestStreamPushStopsWhenCanceled161--- PASS: TestClientSignaturesByStorePath (0.00s)162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== CONT TestRegisterUploadedObjectReusesConnections164=== CONT TestStreamPushRequestLine165=== RUN TestGetStorePathHash/valid_store_path166=== PAUSE TestGetStorePathHash/valid_store_path167=== RUN TestGetStorePathHash/basename_without_hyphen_should_error168=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error169=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error170=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error171=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error172=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestEncodeNixBase32/test_string_hash175=== PAUSE TestEncodeNixBase32/test_string_hash176=== RUN TestEncodeNixBase32/empty_input177=== PAUSE TestEncodeNixBase32/empty_input178--- PASS: TestStreamPushStopsWhenCanceled (0.00s)179=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32180=== CONT TestStreamPushReportsSignatures181=== CONT TestFileTokenMissing182=== PAUSE TestParsePathInfoJSON/Nix_format183=== RUN TestConvertHashToNix32/already_Nix32_format184=== RUN TestPartSizeForNAR/zero_stays_at_minimum185=== RUN TestFilterOversizedClosures/no_limit_keeps_everything186=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum187=== CONT TestScriptTokenBadJSON188=== RUN TestPartSizeForNAR/small_stays_at_minimum1892026/10/08 17:08:07 ERROR Upload failed error=boom count=1190=== RUN TestUploadMultipart_SupersededByPeer/exists191=== PAUSE TestUploadMultipart_SupersededByPeer/exists192=== RUN TestUploadMultipart_SupersededByPeer/missing193=== PAUSE TestUploadMultipart_SupersededByPeer/missing194=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon197=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1982026/10/08 17:08:07 INFO Garbage collection started1992026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=52002026/10/08 17:08:07 INFO Garbage collection started2012026/10/08 17:08:07 ERROR Upload failed error=boom count=1202=== CONT TestStreamPushGivesUpOnDeadServer203--- PASS: TestStreamPushReportsSkippedPaths (0.00s)204=== CONT TestScriptTokenEmptyToken205=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything206=== CONT TestScriptTokenCachesUntilRefresh207=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2082026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:33437209=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI210=== PAUSE TestPartSizeForNAR/small_stays_at_minimum211=== PAUSE TestConvertHashToNix32/already_Nix32_format212--- PASS: TestFileTokenMissing (0.00s)213--- PASS: TestStreamPushReportsSignatures (0.00s)214=== CONT TestFileTokenReadsAndCaches215=== RUN TestParsePathInfoJSON/Lix_format216=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== RUN TestFilterOversizedClosures/all_closures_skipped218=== PAUSE TestFilterOversizedClosures/all_closures_skipped219=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512220=== CONT TestStaticToken221--- PASS: TestStaticToken (0.00s)222=== CONT TestStreamPushIsolatesFailures223=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512224=== PAUSE TestParsePathInfoJSON/Lix_format225=== CONT TestSetClientTLSErrors226=== RUN TestParsePathInfoJSON/empty_input227=== PAUSE TestParsePathInfoJSON/empty_input2282026/10/08 17:08:07 ERROR Upload failed error="bad path" count=3229=== RUN TestParsePathInfoJSON/whitespace_only230=== PAUSE TestParsePathInfoJSON/whitespace_only231=== RUN TestParsePathInfoJSON/invalid_JSON232=== PAUSE TestParsePathInfoJSON/invalid_JSON233=== CONT TestStreamPushBatchesUnderLoad234--- PASS: TestStreamPushIsolatesFailures (0.00s)235=== CONT TestStreamPushReportsEveryPath236=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum237=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum238=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts239=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts2402026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:43429241=== RUN TestPartSizeForNAR/1_TiB242=== PAUSE TestPartSizeForNAR/1_TiB243=== RUN TestPartSizeForNAR/5_TiB_S3_max_object244=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object245=== RUN TestPartSizeForNAR/capped_at_5_GiB246=== PAUSE TestPartSizeForNAR/capped_at_5_GiB247=== CONT TestShellSplitErrors248--- PASS: TestShellSplitErrors (0.00s)249=== CONT TestShellSplit250--- PASS: TestShellSplit (0.00s)251=== CONT TestFileTokenEmpty2522026/10/08 17:08:07 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=0253--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)2542026/10/08 17:08:07 ERROR Upload failed error="connection refused" count=20255=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2562026/10/08 17:08:07 ERROR Server seems unavailable, giving up on batch untried=17257=== CONT TestScriptTokenEmptyCommand258=== CONT TestRateLimiterFeedback/429_enables_limiter259=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter260--- PASS: TestDoServerRequestAttachesToken (0.04s)261=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2622026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=52632026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:33715264=== CONT TestScriptTokenNoExpiryRerunsEveryCall2652026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=52662026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=52672026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:334372682026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:43429269=== RUN TestConvertHashToNix32/invalid_format270=== PAUSE TestConvertHashToNix32/invalid_format271=== CONT TestRateLimiterFeedback/503_enables_limiter272=== CONT TestPathInfoCACompatibility/null_ca_field273=== CONT TestPathInfoCACompatibility/old_string_format_-_text274=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive275=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276=== CONT TestGetStorePathHash/valid_store_path277=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error279=== CONT TestGetStorePathHash/basename_without_hyphen_should_error280=== CONT TestEncodeNixBase32/test_string_hash281=== CONT TestEncodeNixBase32/empty_input282=== CONT TestUploadMultipart_SupersededByPeer/exists283=== CONT TestUploadMultipart_SupersededByPeer/missing2842026/10/08 17:08:07 WARN Rate limiter enabled after throttle name=server-test rate=52852026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46749286=== CONT TestFilterOversizedClosures/no_limit_keeps_everything287=== CONT TestFilterOversizedClosures/all_closures_skipped2882026/10/08 17:08:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50289=== CONT TestPathInfoCACompatibility/new_structured_format_-_text290=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped291=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error2922026/10/08 17:08:07 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=2000293--- PASS: TestScriptTokenBadJSON (0.03s)294--- PASS: TestScriptTokenEmptyCommand (0.00s)295=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2962026/10/08 17:08:07 WARN Garbage collection finished on another replica. Its statistics are not available here297=== RUN TestSetClientTLSErrors/missing_cert_file298=== CONT TestParsePathInfoJSON/Nix_format299=== CONT TestParsePathInfoJSON/whitespace_only300=== CONT TestParsePathInfoJSON/empty_input301=== CONT TestParsePathInfoJSON/Lix_format302=== PAUSE TestSetClientTLSErrors/missing_cert_file303=== CONT TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestPartSizeForNAR/5_TiB_S3_max_object305=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum306=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts307=== CONT TestPartSizeForNAR/small_stays_at_minimum308=== CONT TestConvertHashToNix32/SRI_format_to_Nix32309=== CONT TestConvertHashToNix32/invalid_format310=== CONT TestConvertHashToNix32/already_Nix32_format3112026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:434293122026/10/08 17:08:07 WARN Rate limiter backed off name=server-test rate=5313=== CONT TestParsePathInfoJSON/invalid_JSON314=== RUN TestSetClientTLS/rejects_connection_without_client_cert315=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert316=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA317=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA318=== RUN TestSetClientTLS/preserves_debug_logging_transport319=== PAUSE TestSetClientTLS/preserves_debug_logging_transport320=== CONT TestSetClientTLS/rejects_connection_without_client_cert321=== CONT TestSetClientTLS/preserves_debug_logging_transport322=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)323=== RUN TestSetClientTLSErrors/missing_key_file324=== PAUSE TestSetClientTLSErrors/missing_key_file325=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon326=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512327=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI328--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)329--- PASS: TestFileTokenEmpty (0.00s)330=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA331=== CONT TestPartSizeForNAR/zero_stays_at_minimum3322026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:43429333=== RUN TestSetClientTLSErrors/missing_ca_file334=== PAUSE TestSetClientTLSErrors/missing_ca_file335=== RUN TestSetClientTLSErrors/invalid_ca_file336=== PAUSE TestSetClientTLSErrors/invalid_ca_file337=== CONT TestSetClientTLSErrors/missing_cert_file338=== CONT TestPartSizeForNAR/1_TiB339--- PASS: TestStreamPushReportsEveryPath (0.03s)340=== CONT TestSetClientTLSErrors/missing_ca_file341=== CONT TestSetClientTLSErrors/invalid_ca_file342--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)343=== CONT TestSetClientTLSErrors/missing_key_file344--- PASS: TestEncodeNixBase32 (0.00s)345 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)346 --- PASS: TestEncodeNixBase32/empty_input (0.00s)347--- PASS: TestDumpPathSingleFile (0.03s)348--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)349--- PASS: TestPathInfoCACompatibility (0.00s)350 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)351 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)352 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)353 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)354 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)355--- PASS: TestGetStorePathHash (0.00s)356 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)357 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)358 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)360--- PASS: TestFilterOversizedClosures (0.01s)361 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)362 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)363 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)364--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)365 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)366 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)367--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)368--- PASS: TestFileTokenReadsAndCaches (0.03s)369--- PASS: TestConvertHashToNix32 (0.04s)370 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)371 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)372 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)373--- PASS: TestParsePathInfoJSON (0.01s)374 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)375 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)376 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)377 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)378 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)379--- PASS: TestRateLimiterFeedback (0.00s)380 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)381 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)382 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)383 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)384--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)385 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)386 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)387--- PASS: TestScriptTokenEmptyToken (0.00s)388--- PASS: TestPathInfoHashCompatibility (0.01s)389 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)390 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)391 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)392 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)393--- PASS: TestPartSizeForNAR (0.03s)394 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)395 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)396 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)397 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)398 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)399 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)400 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)4012026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:43429402--- PASS: TestSetClientTLSErrors (0.03s)403 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)404 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)405 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)406 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)407--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)408--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)4092026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:434294102026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:434294112026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:43429412--- PASS: TestCaseHackSuffix (0.06s)4132026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:434294142026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:434294152026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:434294162026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:434294172026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:434294182026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:434294192026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:434294202026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:434294212026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:434294222026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:434294232026/10/08 17:08:07 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:434294242026/10/08 17:08:07 http: TLS handshake error from 127.0.0.1:42390: remote error: tls: bad certificate425--- PASS: TestSetClientTLS (0.04s)426 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)427 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)428 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.04s)429--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.08s)430--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)431--- PASS: TestStreamPushRequestLine (0.09s)432--- PASS: TestDumpPathWriterError (0.08s)433--- PASS: TestDumpPathMatchesNix (0.11s)434--- PASS: TestStreamPushBatchesUnderLoad (0.13s)435--- PASS: TestUploadMultipart_PartsInParallel (0.66s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "nixbld".440This user must also own the server process.441442The database cluster will be initialized with locale "C".443The default database encoding has accordingly been set to "SQL_ASCII".444The default text search configuration will be set to "english".445446Data page checksums are enabled.447448creating directory /build/postgres362712774/data ... ok449creating subdirectories ... ok450selecting dynamic shared memory implementation ... posix451selecting default "max_connections" ... 100452selecting default "shared_buffers" ... 128MB453selecting default time zone ... UTC454creating configuration files ... ok455running bootstrap script ... ok456performing post-bootstrap initialization ... ok457syncing data to disk ... ok458459initdb: warning: enabling "trust" authentication for local connections460initdb: 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.461462Success. You can now start the database server using:463464 pg_ctl -D /build/postgres362712774/data -l logfile start465466/build/postgres362712774:5432 - no response4672026-10-08 17:08:09.593 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4682026-10-08 17:08:09.594 UTC [128] LOG: listening on Unix socket "/build/postgres362712774/.s.PGSQL.5432"4692026-10-08 17:08:09.598 UTC [135] LOG: database system was shut down at 2026-10-08 17:08:09 UTC4702026-10-08 17:08:09.602 UTC [128] LOG: database system is ready to accept connections471/build/postgres362712774:5432 - accepting connections472=== RUN TestService_AuthMiddleware473=== PAUSE TestService_AuthMiddleware474=== RUN TestService_AuthMiddleware_MTLSProxyHeader475=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader476=== RUN TestService_AuthMiddleware_MTLSBoundSubjects477=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects478=== RUN TestService_ReadAuthMiddleware479=== PAUSE TestService_ReadAuthMiddleware480=== RUN TestService_AuthMiddleware_OIDC481=== PAUSE TestService_AuthMiddleware_OIDC482=== RUN TestService_RequireScope_OIDC483=== PAUSE TestService_RequireScope_OIDC484=== RUN TestService_ReadScope_PublicByDefault485=== PAUSE TestService_ReadScope_PublicByDefault486=== RUN TestCacheConfigHandler487=== PAUSE TestCacheConfigHandler488=== RUN TestCacheStatsHandler489=== PAUSE TestCacheStatsHandler490=== RUN TestClientCADerivations491=== PAUSE TestClientCADerivations492=== RUN TestClientErrorHandling493=== PAUSE TestClientErrorHandling494=== RUN TestClientIntegration495=== PAUSE TestClientIntegration496=== RUN TestClientMultipleUploads497=== PAUSE TestClientMultipleUploads498=== RUN TestClientWithDependencies499=== PAUSE TestClientWithDependencies500=== RUN TestClientSharedPathCommittedMidPush501=== PAUSE TestClientSharedPathCommittedMidPush502=== RUN TestPinProtectsFromGC503=== PAUSE TestPinProtectsFromGC504=== RUN TestClientPushesUseOnePush505=== PAUSE TestClientPushesUseOnePush506=== RUN TestClientFallsBackToClosures507=== PAUSE TestClientFallsBackToClosures508=== RUN TestDeleteClosuresRacingPins509=== PAUSE TestDeleteClosuresRacingPins510=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock511=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock512=== RUN TestResolveDBConnectionString513=== PAUSE TestResolveDBConnectionString514=== RUN TestConnectWaitsForAPeerMigration515=== PAUSE TestConnectWaitsForAPeerMigration516=== RUN TestLeadElectsOneAndHandsOver517=== PAUSE TestLeadElectsOneAndHandsOver518=== RUN TestLeadIncumbentWinsAfterRestart5192026/10/08 17:08:10 INFO lead: acquired remote=192.0.2.1:12345202026/10/08 17:08:10 INFO lead: released remote=192.0.2.1:12345212026/10/08 17:08:10 INFO lead: acquired remote=192.0.2.1:12345222026/10/08 17:08:11 INFO lead: released remote=192.0.2.1:1234523--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)524=== RUN TestLeadIncumbentAnnouncesAtOnce525=== PAUSE TestLeadIncumbentAnnouncesAtOnce526=== RUN TestLeadEndsOnShutdown527=== PAUSE TestLeadEndsOnShutdown528=== RUN TestLeadEndsWhenItsConnectionHangs5292026/10/08 17:08:11 INFO lead: acquired remote=192.0.2.1:12345302026-10-08 17:08:13.316 UTC [383] FATAL: terminating connection due to administrator command5312026/10/08 17:08:13 INFO lead: acquired remote=192.0.2.1:12345322026/10/08 17:08:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5332026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:12345342026/10/08 17:08:14 INFO lead: released remote=192.0.2.1:1234535--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)536=== RUN TestGCAdvisoryLockBlocksConcurrentRun537=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun538=== RUN TestGCBugBareHashReferences539=== PAUSE TestGCBugBareHashReferences540=== RUN TestGCMetrics541=== PAUSE TestGCMetrics542=== RUN TestPushDedupSurvivesConcurrentGC543=== PAUSE TestPushDedupSurvivesConcurrentGC544=== RUN TestDeduplicatedObjectsRecordedAsPending545=== PAUSE TestDeduplicatedObjectsRecordedAsPending546=== RUN TestGCSweepSkipsPendingObjects547=== PAUSE TestGCSweepSkipsPendingObjects548=== RUN TestTombstonedObjectOfferedWithoutWaiting549=== PAUSE TestTombstonedObjectOfferedWithoutWaiting550=== RUN TestGCSweepDeliversEachKeyOnce551=== PAUSE TestGCSweepDeliversEachKeyOnce552=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection553=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection554=== RUN TestForceGCDuringPushOffersSweptObject555=== PAUSE TestForceGCDuringPushOffersSweptObject556=== RUN TestFailedS3DeleteKeepsTombstone557=== PAUSE TestFailedS3DeleteKeepsTombstone558=== RUN TestSweepSkipsRowsLockedByPush559=== PAUSE TestSweepSkipsRowsLockedByPush560=== RUN TestRegisterCompletedObjectNeedsPendingRow561=== PAUSE TestRegisterCompletedObjectNeedsPendingRow562=== RUN TestGetExistingObjectsLocksRows563=== PAUSE TestGetExistingObjectsLocksRows564=== RUN TestSweepRechecksPendingAfterLocking565=== PAUSE TestSweepRechecksPendingAfterLocking566=== RUN TestPushWaitsForSweepHoldingRow567=== PAUSE TestPushWaitsForSweepHoldingRow568=== RUN TestCommitRacingPendingCleanupKeepsObjects569=== PAUSE TestCommitRacingPendingCleanupKeepsObjects570=== RUN TestGCEndsOnShutdown571=== PAUSE TestGCEndsOnShutdown572=== RUN TestGCTaskStore_StartNew573=== PAUSE TestGCTaskStore_StartNew574=== RUN TestGCTaskStore_DeduplicateSameParams575=== PAUSE TestGCTaskStore_DeduplicateSameParams576=== RUN TestGCTaskStore_ConflictDifferentParams577=== PAUSE TestGCTaskStore_ConflictDifferentParams578=== RUN TestGCTaskStore_GetEmpty579=== PAUSE TestGCTaskStore_GetEmpty580=== RUN TestGCTaskStore_GetReturnsLatest581=== PAUSE TestGCTaskStore_GetReturnsLatest582=== RUN TestGCTaskStore_CompletedAllowsNewTask583=== PAUSE TestGCTaskStore_CompletedAllowsNewTask584=== RUN TestGCTaskStore_PhaseUpdates585=== PAUSE TestGCTaskStore_PhaseUpdates586=== RUN TestGCTaskStore_Fail587=== PAUSE TestGCTaskStore_Fail588=== RUN TestGracefulShutdownDrainsInflight589=== PAUSE TestGracefulShutdownDrainsInflight590=== RUN TestService_healthCheckHandler591=== PAUSE TestService_healthCheckHandler592=== RUN TestService_readinessHandler593=== PAUSE TestService_readinessHandler594=== RUN TestGenerateLandingPage595=== PAUSE TestGenerateLandingPage596=== RUN TestCacheConfigHandlerMaxNarSize597=== PAUSE TestCacheConfigHandlerMaxNarSize598=== RUN TestCreatePendingClosureRejectsOversizedNAR599=== PAUSE TestCreatePendingClosureRejectsOversizedNAR600=== RUN TestNARDeduplicationMetadataUploadBug601=== PAUSE TestNARDeduplicationMetadataUploadBug602=== RUN TestMetricsInventory603=== PAUSE TestMetricsInventory604=== RUN TestMetricsCommit605=== PAUSE TestMetricsCommit606=== RUN TestService_NativeMTLS607=== PAUSE TestService_NativeMTLS608=== RUN TestServerTLSConfig609=== PAUSE TestServerTLSConfig610=== RUN TestMultipartCleanup611=== PAUSE TestMultipartCleanup612=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded613=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded614=== RUN TestPendingCleanupUsesOneCutoff615=== PAUSE TestPendingCleanupUsesOneCutoff616=== RUN TestObjectStatsTrigger617=== PAUSE TestObjectStatsTrigger618=== RUN TestObjectStatsLargeCommit619=== PAUSE TestObjectStatsLargeCommit620=== RUN TestOrphanedObjectsGC621=== PAUSE TestOrphanedObjectsGC622=== RUN TestOrphanedObjectsGCStressTest623=== PAUSE TestOrphanedObjectsGCStressTest624=== RUN TestCreatePin_ReservedPins625=== PAUSE TestCreatePin_ReservedPins626=== RUN TestPresentReportsOnlyClosureRoots627=== PAUSE TestPresentReportsOnlyClosureRoots628=== RUN TestPresentRefreshesOnlyStaleClosures629=== PAUSE TestPresentRefreshesOnlyStaleClosures630=== RUN TestPresentNotReportedWhileGCDeletesClosure631=== PAUSE TestPresentNotReportedWhileGCDeletesClosure632=== RUN TestParseSingleRange633=== PAUSE TestParseSingleRange634=== RUN TestProxyHeadersOnlyTrustedOnSocket6352026/10/08 17:08:15 INFO Starting HTTP server address=127.0.0.1:460036362026/10/08 17:08:15 INFO Starting HTTP server address=proxy.sock6372026/10/08 17:08:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6382026/10/08 17:08:15 INFO Shutdown signal received, draining in-flight requests timeout=10s639--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)640=== RUN TestIsValidCachePath641=== PAUSE TestIsValidCachePath642=== RUN TestReadProxyNarinfo643=== PAUSE TestReadProxyNarinfo644=== RUN TestReadProxyNarinfoAlreadyDecompressed645=== PAUSE TestReadProxyNarinfoAlreadyDecompressed646=== RUN TestReadProxyContentNegotiation647=== PAUSE TestReadProxyContentNegotiation648=== RUN TestReadProxyNarStreaming649=== PAUSE TestReadProxyNarStreaming650=== RUN TestReadProxy404651=== PAUSE TestReadProxy404652=== RUN TestReadProxyInvalidPath653=== PAUSE TestReadProxyInvalidPath654=== RUN TestReadProxyHead655=== PAUSE TestReadProxyHead656=== RUN TestReadProxyOutlastsServerWriteTimeout657=== PAUSE TestReadProxyOutlastsServerWriteTimeout658=== RUN TestReadProxyConditionalGet659=== PAUSE TestReadProxyConditionalGet660=== RUN TestReadProxyRootRedirectsToIndexHTML661=== PAUSE TestReadProxyRootRedirectsToIndexHTML662=== RUN TestReadProxyDisabled663=== PAUSE TestReadProxyDisabled664=== RUN TestReadRedirectNar665=== PAUSE TestReadRedirectNar666=== RUN TestReadRedirectKeepsNarinfoProxied667=== PAUSE TestReadRedirectKeepsNarinfoProxied668=== RUN TestReadProxyRangeRequest669=== PAUSE TestReadProxyRangeRequest670=== RUN TestReadRedirectUsesPublicS3URL671=== PAUSE TestReadRedirectUsesPublicS3URL672=== RUN TestPush_OverlappingRootsStoreOneRowPerKey673=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey674=== RUN TestPush_CompleteCommitsEveryRoot675=== PAUSE TestPush_CompleteCommitsEveryRoot676=== RUN TestPush_RepeatedRootCommitsOnce677=== PAUSE TestPush_RepeatedRootCommitsOnce678=== RUN TestPush_CompleteWaitsForCleanupOfThePush679=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush680=== RUN TestPush_RootsAreLockedInByteOrder681=== PAUSE TestPush_RootsAreLockedInByteOrder682=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit683=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit684=== RUN TestPush_RejectsBadRequests685=== PAUSE TestPush_RejectsBadRequests686=== RUN TestPush_SignsNarinfosOfItsPendingObjects687=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects688=== RUN TestRedundantMultipartUpload689=== PAUSE TestRedundantMultipartUpload690=== RUN TestCompleteMultipartUpload_ErrorButObjectExists691=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists692=== RUN TestCompletedNarNotReofferedAcrossClosures693=== PAUSE TestCompletedNarNotReofferedAcrossClosures694=== RUN TestPresignedUploadRegisteredBeforeCommit695=== PAUSE TestPresignedUploadRegisteredBeforeCommit696=== RUN TestService_Rustfstest697=== PAUSE TestService_Rustfstest698=== RUN TestParseSize699=== PAUSE TestParseSize700=== RUN TestSkippedUploadsHandler701=== PAUSE TestSkippedUploadsHandler702=== RUN TestSystemdListenerNotActivated703--- PASS: TestSystemdListenerNotActivated (0.00s)704=== RUN TestWatchdogBeatsWhenHealthy705--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)706=== RUN TestWatchdogSkipsWhenUnhealthy7072026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7082026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7092026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7102026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7112026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7122026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7132026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/08 17:08:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"717--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)718=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle719=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle720=== RUN TestProxyWriteTimeout721=== PAUSE TestProxyWriteTimeout722=== RUN TestPendingClosureWriteTimeout723=== PAUSE TestPendingClosureWriteTimeout724=== RUN TestIsValidUploadKey725=== PAUSE TestIsValidUploadKey726=== RUN TestUploadHandlersRejectInvalidKeys727=== PAUSE TestUploadHandlersRejectInvalidKeys728=== RUN TestUploadHandlersRejectOversizedBody729=== PAUSE TestUploadHandlersRejectOversizedBody730=== RUN TestService_cleanupPendingClosuresHandler731=== PAUSE TestService_cleanupPendingClosuresHandler732=== RUN TestService_createPendingClosureHandler733=== PAUSE TestService_createPendingClosureHandler734=== RUN TestService_verifyS3Integrity735=== PAUSE TestService_verifyS3Integrity736=== RUN TestCompleteMultipartUnregistered737=== PAUSE TestCompleteMultipartUnregistered738=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT739=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT740=== CONT TestPendingClosureWriteTimeout741=== CONT TestSkippedUploadsHandler742=== CONT TestService_verifyS3Integrity743=== CONT TestService_createPendingClosureHandler744=== CONT TestProxyWriteTimeout745=== RUN TestProxyWriteTimeout/narinfo7462026/10/08 17:08:15 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000747=== PAUSE TestProxyWriteTimeout/narinfo748=== RUN TestProxyWriteTimeout/1_GiB_nar749=== PAUSE TestProxyWriteTimeout/1_GiB_nar750=== RUN TestProxyWriteTimeout/10_GiB_nar751=== PAUSE TestProxyWriteTimeout/10_GiB_nar752=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle753=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT754=== CONT TestCompleteMultipartUnregistered755=== CONT TestUploadHandlersRejectOversizedBody756=== CONT TestService_cleanupPendingClosuresHandler757=== CONT TestUploadHandlersRejectInvalidKeys758=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info759=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info760=== CONT TestService_healthCheckHandler761=== CONT TestParseSize762--- PASS: TestParseSize (0.00s)763=== CONT TestCompleteMultipartUpload_ErrorButObjectExists764=== RUN TestPendingClosureWriteTimeout/empty765=== PAUSE TestPendingClosureWriteTimeout/empty766=== RUN TestPendingClosureWriteTimeout/400_objects767=== PAUSE TestPendingClosureWriteTimeout/400_objects768=== RUN TestPendingClosureWriteTimeout/670k_objects769=== CONT TestService_Rustfstest770=== CONT TestService_AuthMiddleware771=== CONT TestPresignedUploadRegisteredBeforeCommit772=== CONT TestIsValidUploadKey773=== CONT TestCompletedNarNotReofferedAcrossClosures774=== CONT TestReadProxyNarinfo775=== CONT TestIsValidCachePath776=== CONT TestParseSingleRange777=== CONT TestReadProxyRangeRequest778=== CONT TestPresentNotReportedWhileGCDeletesClosure779=== CONT TestReadProxyNarinfoAlreadyDecompressed780=== RUN TestProxyWriteTimeout/unknown_size781=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal782=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal783=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key784=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key785=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key786=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key787=== RUN TestIsValidCachePath/narinfo788=== PAUSE TestIsValidCachePath/narinfo789=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars790=== CONT TestRedundantMultipartUpload791=== RUN TestIsValidUploadKey/narinfo792=== PAUSE TestPendingClosureWriteTimeout/670k_objects793=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline794=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline795=== CONT TestPresentRefreshesOnlyStaleClosures796--- PASS: TestSkippedUploadsHandler (0.08s)797=== CONT TestPush_SignsNarinfosOfItsPendingObjects798=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars799=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh800=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh801=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale802=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale803=== PAUSE TestProxyWriteTimeout/unknown_size804=== CONT TestPush_RejectsBadRequests805=== CONT TestReadRedirectKeepsNarinfoProxied806=== RUN TestParseSingleRange/none807=== PAUSE TestParseSingleRange/none808=== RUN TestParseSingleRange/unknown_unit809=== PAUSE TestParseSingleRange/unknown_unit810=== RUN TestParseSingleRange/multi-range_ignored811=== PAUSE TestParseSingleRange/multi-range_ignored812=== RUN TestParseSingleRange/malformed_no_dash813=== PAUSE TestParseSingleRange/malformed_no_dash814=== RUN TestParseSingleRange/malformed_both_empty815=== PAUSE TestParseSingleRange/malformed_both_empty816=== RUN TestParseSingleRange/malformed_end_before_start817=== PAUSE TestIsValidUploadKey/narinfo818=== PAUSE TestParseSingleRange/malformed_end_before_start819=== RUN TestIsValidCachePath/nar_zst820=== RUN TestIsValidUploadKey/nar_zst821=== RUN TestParseSingleRange/closed822=== PAUSE TestIsValidCachePath/nar_zst823=== RUN TestIsValidCachePath/nar_xz824=== PAUSE TestIsValidCachePath/nar_xz825=== RUN TestIsValidCachePath/nar_bz2826=== PAUSE TestIsValidCachePath/nar_bz2827=== RUN TestIsValidCachePath/nar_uncompressed828=== PAUSE TestIsValidCachePath/nar_uncompressed829=== PAUSE TestIsValidUploadKey/nar_zst830=== PAUSE TestParseSingleRange/closed831=== RUN TestIsValidCachePath/ls832=== PAUSE TestIsValidCachePath/ls833=== RUN TestIsValidCachePath/log834=== PAUSE TestIsValidCachePath/log835=== RUN TestIsValidUploadKey/nar_xz836=== PAUSE TestIsValidUploadKey/nar_xz837=== RUN TestIsValidUploadKey/nar_plain838=== RUN TestParseSingleRange/open-ended839=== PAUSE TestParseSingleRange/open-ended840=== RUN TestParseSingleRange/end_clamped_to_size841=== RUN TestIsValidCachePath/realisation842=== PAUSE TestIsValidUploadKey/nar_plain843=== PAUSE TestIsValidCachePath/realisation844=== RUN TestIsValidUploadKey/listing845=== PAUSE TestIsValidUploadKey/listing846=== RUN TestIsValidUploadKey/build_log847=== PAUSE TestIsValidUploadKey/build_log848=== RUN TestIsValidUploadKey/build_log_home-manager_file849=== PAUSE TestParseSingleRange/end_clamped_to_size850=== RUN TestParseSingleRange/suffix851=== PAUSE TestParseSingleRange/suffix852=== RUN TestParseSingleRange/suffix_exceeds_size853=== PAUSE TestParseSingleRange/suffix_exceeds_size854=== RUN TestParseSingleRange/single_byte855=== PAUSE TestParseSingleRange/single_byte856=== RUN TestParseSingleRange/start_past_EOF857=== PAUSE TestParseSingleRange/start_past_EOF858=== RUN TestParseSingleRange/start_far_past_EOF859=== PAUSE TestParseSingleRange/start_far_past_EOF860=== RUN TestIsValidCachePath/nix-cache-info861=== PAUSE TestIsValidCachePath/nix-cache-info862=== PAUSE TestIsValidUploadKey/build_log_home-manager_file863=== CONT TestReadRedirectNar864=== RUN TestIsValidUploadKey/build_log_plus_in_name865=== PAUSE TestIsValidUploadKey/build_log_plus_in_name866=== RUN TestIsValidUploadKey/build_log_question_mark867=== RUN TestIsValidCachePath/index.html868=== PAUSE TestIsValidCachePath/index.html869=== RUN TestIsValidCachePath/traversal_parent870=== PAUSE TestIsValidCachePath/traversal_parent871=== RUN TestIsValidCachePath/traversal_in_middle872=== PAUSE TestIsValidCachePath/traversal_in_middle873=== PAUSE TestIsValidUploadKey/build_log_question_mark874=== RUN TestIsValidUploadKey/build_log_equals875=== RUN TestIsValidCachePath/invalid_char_e876=== PAUSE TestIsValidCachePath/invalid_char_e877=== PAUSE TestIsValidUploadKey/build_log_equals878=== RUN TestIsValidCachePath/invalid_char_u879=== PAUSE TestIsValidCachePath/invalid_char_u880=== RUN TestIsValidCachePath/random_path881=== RUN TestIsValidUploadKey/realisation882=== PAUSE TestIsValidCachePath/random_path883=== PAUSE TestIsValidUploadKey/realisation884=== RUN TestIsValidUploadKey/realisation_plus_in_output885=== RUN TestIsValidCachePath/empty886=== PAUSE TestIsValidUploadKey/realisation_plus_in_output887=== RUN TestIsValidUploadKey/nix-cache-info888=== PAUSE TestIsValidCachePath/empty889=== RUN TestIsValidCachePath/leading_slash890=== PAUSE TestIsValidCachePath/leading_slash891=== RUN TestIsValidCachePath/wrong_extension892=== PAUSE TestIsValidCachePath/wrong_extension893=== RUN TestIsValidCachePath/short_hash894=== PAUSE TestIsValidCachePath/short_hash895=== PAUSE TestIsValidUploadKey/nix-cache-info896=== RUN TestIsValidUploadKey/index.html897=== PAUSE TestIsValidUploadKey/index.html898=== RUN TestIsValidUploadKey/narinfo_key,_nar_type899=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type900=== RUN TestIsValidUploadKey/nar_key,_narinfo_type901=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type902=== RUN TestIsValidUploadKey/listing_key,_narinfo_type903=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type904=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit905=== RUN TestIsValidUploadKey/traversal906=== PAUSE TestIsValidUploadKey/traversal907=== RUN TestIsValidUploadKey/traversal_nar908=== PAUSE TestIsValidUploadKey/traversal_nar909=== RUN TestIsValidUploadKey/absolute910=== PAUSE TestIsValidUploadKey/absolute911=== RUN TestIsValidUploadKey/empty_key912=== PAUSE TestIsValidUploadKey/empty_key913=== RUN TestIsValidUploadKey/unknown_type914=== PAUSE TestIsValidUploadKey/unknown_type915=== CONT TestReadProxyDisabled916=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure917=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure918=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart919=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart920=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts921=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts922=== CONT TestPresentReportsOnlyClosureRoots923--- PASS: TestService_healthCheckHandler (0.28s)924=== CONT TestReadProxyRootRedirectsToIndexHTML9252026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9262026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9312026/10/08 17:08:15 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjAzYzc1MTM0LTcyMWUtNDQ1NC1iOTYzLTFmNGVlYjMzYzQxY3gxNzkxNDc5Mjk1NTc2MTM1NjI59322026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9332026/10/08 17:08:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjAzYzc1MTM0LTcyMWUtNDQ1NC1iOTYzLTFmNGVlYjMzYzQxY3gxNzkxNDc5Mjk1NTc2MTM1NjI5 parts=1934--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.35s)935=== CONT TestCreatePin_ReservedPins9362026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9372026/10/08 17:08:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst938--- PASS: TestCompleteMultipartUnregistered (0.37s)939=== CONT TestPush_RootsAreLockedInByteOrder9402026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9412026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures942--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.40s)943=== CONT TestOrphanedObjectsGCStressTest9442026/10/08 17:08:15 INFO Received cleanup request method=DELETE path=/api/pending_closures9452026/10/08 17:08:15 INFO Aborted multipart uploads count=0 kept=09462026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/08 17:08:15 INFO Received cleanup request method=DELETE path=/api/pending_closures9482026/10/08 17:08:15 INFO Aborted multipart uploads count=1 kept=09492026/10/08 17:08:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9502026-10-08 17:08:15.680 UTC [461] ERROR: Closure does not exist: id=19512026-10-08 17:08:15.680 UTC [461] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9522026-10-08 17:08:15.680 UTC [461] STATEMENT: -- name: CommitPendingClosure :one953 SELECT commit_pending_closure($1::bigint)::bigint954 955--- PASS: TestService_cleanupPendingClosuresHandler (0.43s)956=== CONT TestPush_CompleteWaitsForCleanupOfThePush9572026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9582026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/08 17:08:15 INFO Received push request method=POST path=/api/pushes9602026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9612026/10/08 17:08:15 INFO Signed narinfos id=1 count=19622026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9632026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9642026/10/08 17:08:15 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9652026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9662026/10/08 17:08:15 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9672026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9682026/10/08 17:08:15 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19692026/10/08 17:08:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9702026/10/08 17:08:15 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo971--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.42s)972=== CONT TestOrphanedObjectsGC9732026/10/08 17:08:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"974--- PASS: TestService_AuthMiddleware (0.42s)975=== CONT TestPush_RepeatedRootCommitsOnce9762026/10/08 17:08:15 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>977--- PASS: TestReadProxyNarinfo (0.51s)978=== CONT TestReadProxyConditionalGet979--- PASS: TestReadProxyDisabled (0.44s)9802026/10/08 17:08:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34531/oidc981=== CONT TestPush_CompleteCommitsEveryRoot982--- PASS: TestReadProxyRangeRequest (0.47s)983=== CONT TestObjectStatsLargeCommit984--- PASS: TestPresentRefreshesOnlyStaleClosures (0.50s)985=== CONT TestReadProxyOutlastsServerWriteTimeout9862026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/08 17:08:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9882026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures989--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.53s)990=== CONT TestPush_OverlappingRootsStoreOneRowPerKey991=== RUN TestPush_RejectsBadRequests/no_roots992=== PAUSE TestPush_RejectsBadRequests/no_roots993=== RUN TestPush_RejectsBadRequests/no_objects994=== PAUSE TestPush_RejectsBadRequests/no_objects995=== RUN TestPush_RejectsBadRequests/bad_root996=== PAUSE TestPush_RejectsBadRequests/bad_root997=== RUN TestPush_RejectsBadRequests/root_not_in_objects998=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects999=== CONT TestReadProxyHead1000--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.56s)1001=== CONT TestReadRedirectUsesPublicS3URL10022026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10032026/10/08 17:08:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/10/08 17:08:15 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjQzYjE0ZDIzLWIxYTgtNDE1YS05MjIzLWQ2NzA1YWRkNDI0ZngxNzkxNDc5Mjk1NTkyMjg5OTMz parts=101005--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)1006=== CONT TestReadProxyInvalidPath10072026/10/08 17:08:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10082026/10/08 17:08:15 INFO Completed upload id=1 objects=2 duration=3.166988ms10092026/10/08 17:08:15 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010102026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/08 17:08:15 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjIxNWIxY2QxLWI2NmEtNDE4Yi1hZWEwLWZmYjUwM2UyOWI0OXgxNzkxNDc5Mjk1NjA4NTIxNDk3 parts=1010122026/10/08 17:08:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10132026/10/08 17:08:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures10142026/10/08 17:08:15 INFO Completed upload id=1 objects=2 duration=4.138317ms10152026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/08 17:08:15 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/08 17:08:15 INFO Aborted multipart uploads count=0 kept=010192026/10/08 17:08:15 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10202026/10/08 17:08:15 WARN Found objects in DB but missing from S3, will re-upload count=11021--- PASS: TestService_verifyS3Integrity (0.68s)1022=== CONT TestObjectStatsTrigger10232026/10/08 17:08:15 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=010242026/10/08 17:08:15 INFO Vacuumed table table=pending_closures10252026/10/08 17:08:15 INFO Vacuumed table table=pending_objects10262026/10/08 17:08:15 INFO Vacuumed table table=multipart_uploads10272026/10/08 17:08:15 INFO Received push request method=POST path=/api/pushes10282026/10/08 17:08:15 INFO Vacuumed table table=closures10292026/10/08 17:08:15 INFO Vacuumed table table=objects10302026/10/08 17:08:15 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001031--- PASS: TestService_createPendingClosureHandler (0.72s)1032=== CONT TestReadProxy40410332026/10/08 17:08:15 INFO Received complete push request method=POST path=/api/pushes/1/complete1034--- PASS: TestReadRedirectNar (0.65s)1035=== CONT TestMetricsCommit10362026/10/08 17:08:15 INFO Completed push id=1 objects=4 duration=10.877577ms10372026/10/08 17:08:15 INFO Received push request method=POST path=/api/pushes1038--- PASS: TestService_Rustfstest (0.67s)1039=== CONT TestMetricsInventory1040--- PASS: TestPresentReportsOnlyClosureRoots (0.61s)1041=== CONT TestReadProxyNarStreaming10422026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=01043--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.52s)1044=== CONT TestPendingCleanupUsesOneCutoff10452026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/10/08 17:08:16 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=010472026/10/08 17:08:16 INFO Vacuumed table table=pending_closures10482026/10/08 17:08:16 INFO Vacuumed table table=pending_objects10492026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads10502026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10512026/10/08 17:08:16 INFO Vacuumed table table=closures10522026/10/08 17:08:16 INFO Vacuumed table table=objects10532026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/2/complete10542026/10/08 17:08:16 INFO Completed push id=2 objects=4 duration=4.282198ms1055--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.75s)1056=== CONT TestNARDeduplicationMetadataUploadBug10572026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjMxY2Q3Y2Y1LTNjYTgtNGMyZi04NmY2LWNjNGQ0MTM0NjY4OXgxNzkxNDc5Mjk1NzA0Nzc2NTc2 parts=1210592026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures10602026-10-08 17:08:16.112 UTC [560] ERROR: could not obtain lock on row in relation "closures"10612026-10-08 17:08:16.112 UTC [560] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10622026-10-08 17:08:16.113 UTC [560] ERROR: could not obtain lock on row in relation "closures"10632026-10-08 17:08:16.113 UTC [560] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10642026-10-08 17:08:16.113 UTC [560] ERROR: could not obtain lock on row in relation "closures"10652026-10-08 17:08:16.113 UTC [560] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10662026-10-08 17:08:16.113 UTC [560] ERROR: could not obtain lock on row in relation "closures"10672026-10-08 17:08:16.113 UTC [560] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10682026-10-08 17:08:16.114 UTC [560] ERROR: could not obtain lock on row in relation "closures"10692026-10-08 17:08:16.114 UTC [560] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10702026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures10712026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes1072--- PASS: TestPush_RootsAreLockedInByteOrder (0.50s)1073=== CONT TestReadProxyContentNegotiation10742026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10752026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10762026/10/08 17:08:16 INFO Completed push id=1 objects=4 duration=10.145071ms1077--- PASS: TestPush_RepeatedRootCommitsOnce (0.43s)1078=== CONT TestCreatePendingClosureRejectsOversizedNAR10792026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1080--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1081=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1082--- PASS: TestReadProxyConditionalGet (0.43s)1083=== CONT TestCacheConfigHandlerMaxNarSize1084--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1085=== CONT TestGCBugBareHashReferences10862026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10872026/10/08 17:08:16 WARN Refused reserved pin name=worker-x86_64-linux10882026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10892026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/my-app10902026/10/08 17:08:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1091--- PASS: TestCreatePin_ReservedPins (0.60s)1092=== CONT TestGenerateLandingPage1093--- PASS: TestGenerateLandingPage (0.00s)1094=== CONT TestService_readinessHandler10952026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes10962026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete10972026/10/08 17:08:16 INFO Completed push id=1 objects=6 duration=11.868646ms1098--- PASS: TestPush_CompleteCommitsEveryRoot (0.49s)1099=== CONT TestGracefulShutdownDrainsInflight11002026/10/08 17:08:16 INFO Starting HTTP server address=127.0.0.1:3581911012026/10/08 17:08:16 INFO Shutdown signal received, draining in-flight requests timeout=10s11022026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes11032026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1104--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.45s)1105=== CONT TestMultipartCleanup11062026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjlhMjU5OWM3LWFmNzItNDBjOS05M2Y4LWZkMjNmNDc3NzNhYXgxNzkxNDc5Mjk1OTMyNzU5NDY3 parts=1211072026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestReadProxyHead (0.46s)1109=== CONT TestSweepRechecksPendingAfterLocking1110--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.99s)1111=== CONT TestServerTLSConfig1112=== RUN TestServerTLSConfig/no_client_CA1113=== PAUSE TestServerTLSConfig/no_client_CA1114=== RUN TestServerTLSConfig/missing_CA_file1115=== PAUSE TestServerTLSConfig/missing_CA_file1116=== RUN TestServerTLSConfig/not_a_PEM_file1117=== PAUSE TestServerTLSConfig/not_a_PEM_file1118=== CONT TestGCTaskStore_Fail1119--- PASS: TestGCTaskStore_Fail (0.00s)1120=== CONT TestGetExistingObjectsLocksRows1121--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1122=== CONT TestGCTaskStore_PhaseUpdates1123--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1124=== CONT TestRegisterCompletedObjectNeedsPendingRow1125--- PASS: TestReadRedirectUsesPublicS3URL (0.46s)1126=== CONT TestService_NativeMTLS1127--- PASS: TestReadProxyInvalidPath (0.44s)1128=== CONT TestGCTaskStore_CompletedAllowsNewTask1129--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1130=== CONT TestSweepSkipsRowsLockedByPush1131--- PASS: TestObjectStatsTrigger (0.46s)1132=== CONT TestGCTaskStore_GetReturnsLatest1133--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1134=== CONT TestFailedS3DeleteKeepsTombstone1135--- PASS: TestReadProxy404 (0.45s)1136=== CONT TestGCTaskStore_StartNew1137--- PASS: TestGCTaskStore_StartNew (0.00s)1138=== CONT TestForceGCDuringPushOffersSweptObject1139=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1140=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1141=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1142=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1143=== CONT TestGCTaskStore_GetEmpty1144--- PASS: TestGCTaskStore_GetEmpty (0.00s)1145=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11462026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes11472026-10-08 17:08:16.431 UTC [570] ERROR: Push does not exist: id=111482026-10-08 17:08:16.431 UTC [570] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11492026-10-08 17:08:16.431 UTC [570] STATEMENT: SELECT commit_push($1)1150--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.75s)1151=== CONT TestGCSweepDeliversEachKeyOnce11522026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete11532026/10/08 17:08:16 INFO Completed push id=1 objects=4 duration=9.00306ms11542026/10/08 17:08:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11552026/10/08 17:08:16 INFO Completed upload id=2 objects=2 duration=2.309281ms1156--- PASS: TestMetricsCommit (0.47s)1157=== CONT TestTombstonedObjectOfferedWithoutWaiting1158--- PASS: TestMetricsInventory (0.46s)1159=== CONT TestGCSweepSkipsPendingObjects1160--- PASS: TestReadProxyNarStreaming (0.44s)1161=== CONT TestDeduplicatedObjectsRecordedAsPending1162=== NAME TestOrphanedObjectsGC1163 orphaned_objects_gc_test.go:287: GC Test Summary:1164 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1165 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1166 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1167 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1168 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1169--- PASS: TestOrphanedObjectsGC (0.74s)1170=== CONT TestGCTaskStore_ConflictDifferentParams1171--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1172=== CONT TestPushDedupSurvivesConcurrentGC11732026/10/08 17:08:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11742026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/08 17:08:16 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLjVhNDQxMDhiLTRjZjUtNDEwZS1hN2JiLWRhZDRmYjZmZmU3MngxNzkxNDc5Mjk2MTIwMTQwMDE3 error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11762026/10/08 17:08:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGVlZjMxZjQtNDI3Yi00NmNjLWEzZjYtYTYxMmU1Njc4ZGMzLmU4NjJiYWMxLWJhZTEtNDA0Yi04MDAxLWExZWU5NjE4Y2NjYXgxNzkxNDc5Mjk2MTEzNjc5MDIw parts=1211772026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures11782026/10/08 17:08:16 INFO Aborted multipart uploads count=1 kept=011792026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1180--- PASS: TestRedundantMultipartUpload (1.18s)1181=== CONT TestGCTaskStore_DeduplicateSameParams1182--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1183=== CONT TestGCMetrics11842026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures11852026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1186=== NAME TestNARDeduplicationMetadataUploadBug1187 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2002716762/001/store/m4wiw66yin6k87pgxyscd52i17dhmk4n-file1.txt1188--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.41s)1189=== CONT TestGCEndsOnShutdown1190=== RUN TestGCEndsOnShutdown/before_the_run1191=== PAUSE TestGCEndsOnShutdown/before_the_run1192=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1193=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1194=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1195=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1196=== CONT TestPushWaitsForSweepHoldingRow1197--- PASS: TestReadProxyContentNegotiation (0.48s)1198=== CONT TestCommitRacingPendingCleanupKeepsObjects11992026/10/08 17:08:16 WARN readiness check failed error="closed pool"1200--- PASS: TestService_readinessHandler (0.40s)1201=== CONT TestClientWithDependencies12022026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes12032026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures12042026/10/08 17:08:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12052026/10/08 17:08:16 INFO Uploading m4wiw66yin6k87pgxyscd52i17dhmk4n-file1.txt (160B)12062026/10/08 17:08:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12072026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12082026/10/08 17:08:16 WARN Failed to register uploaded object key=m4wiw66yin6k87pgxyscd52i17dhmk4n.ls error="server returned 404: 404 page not found\n"12092026/10/08 17:08:16 INFO Signed narinfos id=1 count=112102026/10/08 17:08:16 INFO Uploading 1 narinfos12112026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/1/complete12122026/10/08 17:08:16 WARN Failed to register uploaded object key=m4wiw66yin6k87pgxyscd52i17dhmk4n.narinfo error="server returned 404: 404 page not found\n"12132026/10/08 17:08:16 INFO Completed push id=1 objects=3 duration=6.443357ms12142026/10/08 17:08:16 INFO Upload complete. (58ms)1215=== NAME TestNARDeduplicationMetadataUploadBug1216 metadata_upload_test.go:54: Retrieved narinfo from S3:1217 StorePath: /build/TestNARDeduplicationMetadataUploadBug2002716762/001/store/m4wiw66yin6k87pgxyscd52i17dhmk4n-file1.txt1218 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1219 Compression: zstd1220 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1221 NarSize: 1601222 References: 1223 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1224 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1225 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1226 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1227--- PASS: TestGetExistingObjectsLocksRows (0.35s)1228=== CONT TestResolveDBConnectionString1229=== RUN TestResolveDBConnectionString/flag_wins1230=== PAUSE TestResolveDBConnectionString/flag_wins1231=== RUN TestResolveDBConnectionString/file_when_flag_empty1232=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1233=== RUN TestResolveDBConnectionString/missing_file_is_an_error1234=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1235=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1236=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1237=== RUN TestResolveDBConnectionString/nothing_configured1238=== PAUSE TestResolveDBConnectionString/nothing_configured1239=== CONT TestCacheConfigHandler1240=== RUN TestCacheConfigHandler/full_config,_no_issuer1241=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1242=== RUN TestCacheConfigHandler/no_cache_url_configured1243=== PAUSE TestCacheConfigHandler/no_cache_url_configured1244=== RUN TestCacheConfigHandler/no_signing_keys1245=== PAUSE TestCacheConfigHandler/no_signing_keys1246=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1247=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1248=== CONT TestGCAdvisoryLockBlocksConcurrentRun12492026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=01250=== NAME TestNARDeduplicationMetadataUploadBug1251 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2002716762/001/store/pslxlmgd39xif0ygf0hnw6k6rprddvjd-file2.txt12522026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period1253--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.37s)1254=== CONT TestClientMultipleUploads12552026/10/08 17:08:16 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=012562026/10/08 17:08:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12572026/10/08 17:08:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1258--- PASS: TestService_NativeMTLS (0.36s)1259=== CONT TestLeadEndsOnShutdown12602026/10/08 17:08:16 INFO Vacuumed table table=pending_closures12612026/10/08 17:08:16 INFO Vacuumed table table=pending_objects12622026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads12632026/10/08 17:08:16 INFO Vacuumed table table=closures12642026/10/08 17:08:16 INFO Vacuumed table table=objects1265--- PASS: TestSweepRechecksPendingAfterLocking (0.41s)1266=== CONT TestLeadIncumbentAnnouncesAtOnce12672026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures12682026/10/08 17:08:16 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12692026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=112702026/10/08 17:08:16 INFO Received cleanup request method=DELETE path=/api/pending_closures12712026/10/08 17:08:16 INFO Aborted multipart uploads count=1 kept=012722026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1273--- PASS: TestMultipartCleanup (0.45s)1274=== CONT TestLeadElectsOneAndHandsOver12752026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=012762026/10/08 17:08:16 INFO Received push request method=POST path=/api/pushes12772026/10/08 17:08:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12782026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period12792026/10/08 17:08:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12802026/10/08 17:08:16 INFO Signed narinfos id=2 count=112812026/10/08 17:08:16 INFO Uploading 1 narinfos12822026/10/08 17:08:16 WARN Failed to register uploaded object key=pslxlmgd39xif0ygf0hnw6k6rprddvjd.ls error="server returned 404: 404 page not found\n"12832026/10/08 17:08:16 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=012842026/10/08 17:08:16 INFO Vacuumed table table=pending_closures12852026/10/08 17:08:16 INFO Vacuumed table table=pending_objects12862026/10/08 17:08:16 INFO Received complete push request method=POST path=/api/pushes/2/complete12872026/10/08 17:08:16 WARN Failed to register uploaded object key=pslxlmgd39xif0ygf0hnw6k6rprddvjd.narinfo error="server returned 404: 404 page not found\n"12882026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads12892026/10/08 17:08:16 INFO Vacuumed table table=closures12902026/10/08 17:08:16 INFO Vacuumed table table=objects12912026/10/08 17:08:16 INFO Completed push id=2 objects=3 duration=8.043552ms12922026/10/08 17:08:16 INFO Upload complete. (50ms)12932026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1294=== NAME TestNARDeduplicationMetadataUploadBug1295 metadata_upload_test.go:76: Retrieved narinfo from S3:1296 StorePath: /build/TestNARDeduplicationMetadataUploadBug2002716762/001/store/pslxlmgd39xif0ygf0hnw6k6rprddvjd-file2.txt1297 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1298 Compression: zstd1299 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1300 NarSize: 1601301 References: 1302 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1303 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1304 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):13052026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=01306 {"version":1,"root":{"type":"regular","size":44}}1307--- PASS: TestNARDeduplicationMetadataUploadBug (0.70s)1308=== CONT TestClientIntegration13092026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13102026/10/08 17:08:16 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=013112026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13122026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13132026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13142026/10/08 17:08:16 INFO Vacuumed table table=closures13152026/10/08 17:08:16 INFO Vacuumed table table=objects1316--- PASS: TestSweepSkipsRowsLockedByPush (0.45s)1317=== CONT TestConnectWaitsForAPeerMigration1318--- PASS: TestGCBugBareHashReferences (0.62s)1319=== CONT TestClientErrorHandling1320=== RUN TestClientErrorHandling/InvalidStorePath1321=== PAUSE TestClientErrorHandling/InvalidStorePath1322=== RUN TestClientErrorHandling/InvalidAuthToken1323=== PAUSE TestClientErrorHandling/InvalidAuthToken1324=== RUN TestClientErrorHandling/ServerNotAvailable1325=== PAUSE TestClientErrorHandling/ServerNotAvailable1326=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13272026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013282026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1329--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.35s)1330=== CONT TestCacheStatsHandler13312026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13322026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013332026/10/08 17:08:16 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=013342026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13352026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures13372026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13382026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13392026/10/08 17:08:16 INFO Vacuumed table table=closures13402026/10/08 17:08:16 INFO Vacuumed table table=objects1341--- PASS: TestGCSweepDeliversEachKeyOnce (0.42s)1342=== CONT TestDeleteClosuresRacingPins1343--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.40s)1344=== CONT TestService_AuthMiddleware_OIDC13452026/10/08 17:08:16 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13462026/10/08 17:08:16 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1347--- PASS: TestFailedS3DeleteKeepsTombstone (0.47s)1348=== CONT TestService_ReadScope_PublicByDefault13492026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures13502026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013512026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13522026/10/08 17:08:16 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=013532026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13542026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13552026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13562026/10/08 17:08:16 INFO Vacuumed table table=closures13572026/10/08 17:08:16 INFO Vacuumed table table=objects13582026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1359--- PASS: TestGCSweepSkipsPendingObjects (0.45s)1360=== CONT TestService_RequireScope_OIDC13612026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013622026/10/08 17:08:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40555/oidc13632026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13642026/10/08 17:08:16 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=013652026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13662026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13672026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13682026/10/08 17:08:16 INFO Vacuumed table table=closures13692026/10/08 17:08:16 INFO Vacuumed table table=objects13702026/10/08 17:08:16 INFO Received uploads request method=POST path=/api/pending_closures1371--- PASS: TestGCMetrics (0.42s)1372=== CONT TestService_AuthMiddleware_MTLSProxyHeader13732026/10/08 17:08:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42203/oidc13742026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013752026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013762026/10/08 17:08:16 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=013772026/10/08 17:08:16 WARN Force mode enabled - objects will be deleted immediately without grace period13782026/10/08 17:08:16 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=01379--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.57s)1380=== CONT TestClientFallsBackToClosures13812026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13822026/10/08 17:08:16 INFO Vacuumed table table=pending_closures13832026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13842026/10/08 17:08:16 INFO Vacuumed table table=pending_objects13852026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13862026/10/08 17:08:16 INFO Vacuumed table table=multipart_uploads13872026/10/08 17:08:16 INFO Vacuumed table table=closures13882026/10/08 17:08:16 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"1389--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.32s)1390=== CONT TestService_ReadAuthMiddleware13912026/10/08 17:08:16 INFO Vacuumed table table=objects13922026/10/08 17:08:16 INFO Vacuumed table table=closures13932026/10/08 17:08:16 INFO Vacuumed table table=objects13942026/10/08 17:08:16 INFO Aborted multipart uploads count=0 kept=013952026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1396--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.40s)1397=== CONT TestClientPushesUseOnePush13982026/10/08 17:08:17 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=013992026/10/08 17:08:17 INFO Vacuumed table table=pending_closures14002026/10/08 17:08:17 INFO Vacuumed table table=pending_objects14012026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads14022026/10/08 17:08:17 INFO Vacuumed table table=closures14032026/10/08 17:08:17 INFO Vacuumed table table=objects1404--- PASS: TestPushDedupSurvivesConcurrentGC (0.53s)1405=== CONT TestPinProtectsFromGC14062026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:123414072026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:123414082026/10/08 17:08:17 INFO lead: released remote=192.0.2.1:12341409--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.32s)1410=== CONT TestClientCADerivations1411=== NAME TestClientMultipleUploads1412 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads731197166/001/store/anm986qsmlw6rpx23323clb9vxw43nlj-test-file-0.txt1413=== NAME TestClientWithDependencies1414 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2383502412/001/store/y9zqs9fym5w4x4xl11ljrpwq2b6n10am-test-script14152026/10/08 17:08:17 INFO lead: acquired remote=192.0.2.1:12341416=== NAME TestClientMultipleUploads1417 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads731197166/001/store/41z41vw7y4y5na7adjzg4gpp55dyvkba-test-file-1.txt1418=== NAME TestClientWithDependencies1419 client_integration_test.go:615: Found 1 dependencies (including self)1420=== NAME TestClientMultipleUploads1421 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads731197166/001/store/5jvgdwm2l3ssm9rszxrlkzmfiv0rvj02-test-file-2.txt1422--- PASS: TestCacheStatsHandler (0.30s)1423=== CONT TestClientSharedPathCommittedMidPush1424=== NAME TestClientIntegration1425 client_integration_test.go:286: Created store path: /build/TestClientIntegration4215581448/002/store/gqgi20i6lhchmq430dp5dnjijklsiymd-test-file.txt14262026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes14272026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14282026/10/08 17:08:17 INFO Uploading y9zqs9fym5w4x4xl11ljrpwq2b6n10am-test-script (136B)14292026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14302026/10/08 17:08:17 WARN Failed to register uploaded object key=log/why05g8l97jsjavkyad9jy1dz32q6cw8-test-script.drv error="server returned 404: 404 page not found\n"14312026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14322026/10/08 17:08:17 WARN Failed to register uploaded object key=y9zqs9fym5w4x4xl11ljrpwq2b6n10am.ls error="server returned 404: 404 page not found\n"14332026/10/08 17:08:17 INFO Signed narinfos id=1 count=114342026/10/08 17:08:17 INFO Uploading 1 narinfos14352026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14362026/10/08 17:08:17 WARN Failed to register uploaded object key=y9zqs9fym5w4x4xl11ljrpwq2b6n10am.narinfo error="server returned 404: 404 page not found\n"14372026/10/08 17:08:17 INFO Completed push id=1 objects=4 duration=6.144495ms14382026/10/08 17:08:17 INFO Upload complete. (56ms)1439=== NAME TestClientWithDependencies1440 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2383502412/001/store) requires matching store prefix1441--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1442=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1443--- PASS: TestClientWithDependencies (0.57s)1444=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14452026/10/08 17:08:17 INFO Received uploads request method=POST path=/1446=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14472026/10/08 17:08:17 INFO Received request for more parts method=POST path=/1448=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14492026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/1450=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14512026/10/08 17:08:17 INFO Received uploads request method=POST path=/1452--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1453 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1454 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1455 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1456 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1457=== CONT TestPendingClosureWriteTimeout/empty1458=== CONT TestPendingClosureWriteTimeout/670k_objects1459=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1460=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1461=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1462=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1463=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1464=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1465=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1466=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1467=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1468=== CONT TestPendingClosureWriteTimeout/400_objects1469=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh14702026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes14712026/10/08 17:08:17 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14722026/10/08 17:08:17 INFO Uploading anm986qsmlw6rpx23323clb9vxw43nlj-test-file-0.txt (160B)14732026/10/08 17:08:17 INFO Uploading 5jvgdwm2l3ssm9rszxrlkzmfiv0rvj02-test-file-2.txt (160B)14742026/10/08 17:08:17 INFO Uploading 41z41vw7y4y5na7adjzg4gpp55dyvkba-test-file-1.txt (160B)14752026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14762026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14772026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14782026/10/08 17:08:17 WARN Failed to register uploaded object key=anm986qsmlw6rpx23323clb9vxw43nlj.ls error="server returned 404: 404 page not found\n"14792026/10/08 17:08:17 WARN Failed to register uploaded object key=41z41vw7y4y5na7adjzg4gpp55dyvkba.ls error="server returned 404: 404 page not found\n"14802026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14812026/10/08 17:08:17 WARN Failed to register uploaded object key=5jvgdwm2l3ssm9rszxrlkzmfiv0rvj02.ls error="server returned 404: 404 page not found\n"14822026/10/08 17:08:17 INFO Signed narinfos id=1 count=314832026/10/08 17:08:17 INFO Uploading 3 narinfos14842026/10/08 17:08:17 WARN Failed to register uploaded object key=anm986qsmlw6rpx23323clb9vxw43nlj.narinfo error="server returned 404: 404 page not found\n"14852026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14862026/10/08 17:08:17 WARN Failed to register uploaded object key=5jvgdwm2l3ssm9rszxrlkzmfiv0rvj02.narinfo error="server returned 404: 404 page not found\n"14872026/10/08 17:08:17 WARN Failed to register uploaded object key=41z41vw7y4y5na7adjzg4gpp55dyvkba.narinfo error="server returned 404: 404 page not found\n"14882026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1489--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1490=== CONT TestProxyWriteTimeout/narinfo1491=== CONT TestProxyWriteTimeout/10_GiB_nar1492=== CONT TestProxyWriteTimeout/unknown_size1493=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale14942026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14952026/10/08 17:08:17 INFO Uploading gqgi20i6lhchmq430dp5dnjijklsiymd-test-file.txt (152B)14962026/10/08 17:08:17 INFO Completed push id=1 objects=9 duration=6.856662ms14972026/10/08 17:08:17 INFO Upload complete. (66ms)1498=== NAME TestClientMultipleUploads1499 client_integration_test.go:369: Uploaded 3 paths in 100.372315ms15002026/10/08 17:08:17 WARN Failed to register uploaded object key=gqgi20i6lhchmq430dp5dnjijklsiymd.ls error="server returned 404: 404 page not found\n"15012026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15022026/10/08 17:08:17 INFO Signed narinfos id=1 count=115032026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15042026/10/08 17:08:17 INFO Uploading 1 narinfos15052026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15062026/10/08 17:08:17 WARN Failed to register uploaded object key=gqgi20i6lhchmq430dp5dnjijklsiymd.narinfo error="server returned 404: 404 page not found\n"1507--- PASS: TestClientMultipleUploads (0.53s)1508=== CONT TestProxyWriteTimeout/1_GiB_nar1509--- PASS: TestProxyWriteTimeout (0.08s)1510 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1511 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1512 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1513 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1514=== CONT TestParseSingleRange/none1515=== CONT TestParseSingleRange/suffix_exceeds_size1516=== CONT TestParseSingleRange/suffix1517=== CONT TestParseSingleRange/end_clamped_to_size1518=== CONT TestParseSingleRange/open-ended1519=== CONT TestParseSingleRange/closed1520=== CONT TestParseSingleRange/malformed_end_before_start1521=== CONT TestParseSingleRange/malformed_both_empty1522=== CONT TestParseSingleRange/malformed_no_dash1523=== CONT TestParseSingleRange/single_byte1524=== CONT TestParseSingleRange/multi-range_ignored1525=== CONT TestParseSingleRange/unknown_unit1526=== CONT TestParseSingleRange/start_far_past_EOF1527=== CONT TestParseSingleRange/start_past_EOF1528--- PASS: TestParseSingleRange (0.00s)1529 --- PASS: TestParseSingleRange/none (0.00s)1530 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1531 --- PASS: TestParseSingleRange/suffix (0.00s)1532 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1533 --- PASS: TestParseSingleRange/open-ended (0.00s)1534 --- PASS: TestParseSingleRange/closed (0.00s)1535 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1536 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1537 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1538 --- PASS: TestParseSingleRange/single_byte (0.00s)1539 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1540 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1541 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1542 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1543=== CONT TestIsValidCachePath/narinfo1544=== CONT TestIsValidCachePath/traversal_parent1545=== CONT TestIsValidCachePath/short_hash1546=== CONT TestIsValidCachePath/invalid_char_u1547=== CONT TestIsValidCachePath/invalid_char_e1548=== CONT TestIsValidCachePath/traversal_in_middle1549=== CONT TestIsValidCachePath/leading_slash1550=== CONT TestIsValidCachePath/wrong_extension1551=== CONT TestIsValidCachePath/empty1552=== CONT TestIsValidCachePath/nar_uncompressed1553=== CONT TestIsValidCachePath/index.html1554=== CONT TestIsValidCachePath/nix-cache-info1555=== CONT TestIsValidCachePath/realisation1556=== CONT TestIsValidCachePath/log1557=== CONT TestIsValidCachePath/ls1558=== CONT TestIsValidCachePath/nar_zst1559=== CONT TestIsValidCachePath/nar_bz21560=== CONT TestIsValidCachePath/nar_xz1561=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1562=== CONT TestIsValidCachePath/random_path1563--- PASS: TestIsValidCachePath (0.08s)1564 --- PASS: TestIsValidCachePath/narinfo (0.00s)1565 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1566 --- PASS: TestIsValidCachePath/short_hash (0.00s)1567 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1568 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1569 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1570 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1571 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1572 --- PASS: TestIsValidCachePath/empty (0.00s)1573 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1574 --- PASS: TestIsValidCachePath/index.html (0.00s)1575 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1576 --- PASS: TestIsValidCachePath/realisation (0.00s)1577 --- PASS: TestIsValidCachePath/log (0.00s)1578 --- PASS: TestIsValidCachePath/ls (0.00s)1579 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1580 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1581 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1582 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1583 --- PASS: TestIsValidCachePath/random_path (0.00s)1584=== CONT TestIsValidUploadKey/narinfo1585=== CONT TestIsValidUploadKey/nix-cache-info1586=== CONT TestIsValidUploadKey/build_log1587=== CONT TestIsValidUploadKey/listing1588=== CONT TestIsValidUploadKey/nar_plain1589=== CONT TestIsValidUploadKey/nar_xz1590=== CONT TestIsValidUploadKey/nar_zst1591=== CONT TestIsValidUploadKey/traversal1592=== CONT TestIsValidUploadKey/unknown_type1593=== CONT TestIsValidUploadKey/empty_key1594=== CONT TestIsValidUploadKey/absolute1595=== CONT TestIsValidUploadKey/traversal_nar1596=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1597=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1598=== CONT TestIsValidUploadKey/build_log_equals1599=== CONT TestIsValidUploadKey/realisation_plus_in_output1600=== CONT TestIsValidUploadKey/realisation1601=== CONT TestIsValidUploadKey/build_log_question_mark1602=== CONT TestIsValidUploadKey/build_log_plus_in_name1603=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1604=== CONT TestIsValidUploadKey/index.html1605=== CONT TestIsValidUploadKey/build_log_home-manager_file1606--- PASS: TestIsValidUploadKey (0.01s)1607 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1608 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1609 --- PASS: TestIsValidUploadKey/build_log (0.00s)1610 --- PASS: TestIsValidUploadKey/listing (0.00s)1611 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1612 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1613 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1614 --- PASS: TestIsValidUploadKey/traversal (0.00s)1615 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1616 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1617 --- PASS: TestIsValidUploadKey/absolute (0.00s)1618 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1619 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1620 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1621 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1622 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1623 --- PASS: TestIsValidUploadKey/realisation (0.00s)1624 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1625 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1626 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1627 --- PASS: TestIsValidUploadKey/index.html (0.00s)1628 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1629=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16302026/10/08 17:08:17 INFO Received uploads request method=POST path=/16312026/10/08 17:08:17 INFO Completed push id=1 objects=3 duration=6.365616ms16322026/10/08 17:08:17 INFO Upload complete. (61ms)1633=== RUN TestService_RequireScope_OIDC/builder_may_write1634=== PAUSE TestService_RequireScope_OIDC/builder_may_write1635=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1636=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1637=== RUN TestService_RequireScope_OIDC/ops_may_admin1638=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1639=== RUN TestService_RequireScope_OIDC/ops_may_not_write1640=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1641=== RUN TestService_RequireScope_OIDC/reader_may_not_write1642=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1643=== RUN TestService_RequireScope_OIDC/static_token_may_admin1644=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1645=== RUN TestService_RequireScope_OIDC/static_token_may_write1646=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1647=== RUN TestService_RequireScope_OIDC/reader_may_read1648=== PAUSE TestService_RequireScope_OIDC/reader_may_read1649=== RUN TestService_RequireScope_OIDC/writer_implies_read1650=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1651=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1652=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1653=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1654=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1655=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1656=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1657=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1658=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1659=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1660=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1661=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16622026/10/08 17:08:17 INFO Received request for more parts method=POST path=/16632026/10/08 17:08:17 INFO All 1 paths already cached1664=== NAME TestClientIntegration1665 client_integration_test.go:312: Retrieved narinfo from S3:1666 StorePath: /build/TestClientIntegration4215581448/002/store/gqgi20i6lhchmq430dp5dnjijklsiymd-test-file.txt1667 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1668 Compression: zstd1669 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11670 NarSize: 1521671 References: 1672 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11673 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1674 client_integration_test.go:313: Decompressed .ls content (64 bytes):1675 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1676 client_integration_test.go:316: Testing garbage collection...1677--- PASS: TestService_ReadAuthMiddleware (0.29s)1678=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16792026/10/08 17:08:17 INFO Received complete multipart upload request method=POST path=/1680--- PASS: TestObjectStatsLargeCommit (1.50s)1681=== CONT TestPush_RejectsBadRequests/no_roots16822026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1683=== CONT TestPush_RejectsBadRequests/bad_root16842026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1685=== CONT TestPush_RejectsBadRequests/no_objects16862026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1687=== CONT TestPush_RejectsBadRequests/root_not_in_objects16882026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1689=== CONT TestServerTLSConfig/no_client_CA1690--- PASS: TestPush_RejectsBadRequests (0.53s)1691 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1692 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1693 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1694 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1695=== CONT TestServerTLSConfig/not_a_PEM_file1696=== CONT TestServerTLSConfig/missing_CA_file1697--- PASS: TestServerTLSConfig (0.00s)1698 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1699 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1700 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1701=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17022026/10/08 17:08:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures17032026/10/08 17:08:17 INFO Garbage collection started17042026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=017052026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1706=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1707=== CONT TestGCEndsOnShutdown/before_the_run17082026/10/08 17:08:17 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=017092026/10/08 17:08:17 INFO Vacuumed table table=pending_closures17102026/10/08 17:08:17 INFO Vacuumed table table=pending_objects17112026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads17122026/10/08 17:08:17 INFO Vacuumed table table=closures17132026/10/08 17:08:17 INFO Vacuumed table table=objects17142026/10/08 17:08:17 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17152026/10/08 17:08:17 WARN mTLS auth: bound subjects configured but subject DN unavailable17162026/10/08 17:08:17 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1717--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.21s)1718=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1719=== NAME TestPinProtectsFromGC1720 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1132559113/001/store/nm6ny3qkz0hk1i206lgzjlj8ahrj776v-pinned-file.txt1721 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1132559113/001/store/injgyj3g4hg3ksv7h88yl4k815wshr81-unpinned-file.txt17222026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures1723--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.61s)1724=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1725--- PASS: TestPushWaitsForSweepHoldingRow (0.85s)1726=== CONT TestResolveDBConnectionString/flag_wins1727=== CONT TestResolveDBConnectionString/nothing_configured1728=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1729=== CONT TestResolveDBConnectionString/missing_file_is_an_error1730=== CONT TestResolveDBConnectionString/file_when_flag_empty1731=== CONT TestCacheConfigHandler/full_config,_no_issuer1732--- PASS: TestResolveDBConnectionString (0.00s)1733 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1734 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1735 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1736 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1737 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1738=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1739=== CONT TestCacheConfigHandler/no_signing_keys1740=== CONT TestCacheConfigHandler/no_cache_url_configured1741--- PASS: TestCacheConfigHandler (0.00s)1742 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1743 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1744 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1745 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1746=== CONT TestClientErrorHandling/InvalidStorePath1747=== NAME TestClientCADerivations1748 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations745236862/001/store/4hiskgdg5l6grsyhgqcdp4ydwyga10ap-ca-test1749 client_ca_test.go:139: Found 1 dependencies (including self)17502026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes17512026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures17522026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17532026/10/08 17:08:17 INFO Uploading nm6ny3qkz0hk1i206lgzjlj8ahrj776v-pinned-file.txt (128B)17542026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures17552026/10/08 17:08:17 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17562026/10/08 17:08:17 INFO Uploading wn77kb7vr0sb8ci6hrdcwizjyf9sb3m6-b (216B)17572026/10/08 17:08:17 INFO Uploading p6byvfwyx6m4i2pvmsv17abf1jfdk1v9-shared-dep (136B)17582026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17592026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17602026/10/08 17:08:17 WARN Failed to register uploaded object key=nm6ny3qkz0hk1i206lgzjlj8ahrj776v.ls error="server returned 404: 404 page not found\n"17612026/10/08 17:08:17 INFO Signed narinfos id=1 count=117622026/10/08 17:08:17 INFO Uploading 1 narinfos17632026/10/08 17:08:17 WARN Failed to register uploaded object key=qz346fn629ls1zdfmsfh60i85sr74x6c.ls error="server returned 404: 404 page not found\n"17642026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1gq5d003ss6b3ibcdyfm2n93dsi7lx9yg1a4ly02l38gglmrk4pi.nar.zst error="server returned 404: 404 page not found\n"17652026/10/08 17:08:17 WARN Failed to register uploaded object key=wn77kb7vr0sb8ci6hrdcwizjyf9sb3m6.ls error="server returned 404: 404 page not found\n"17662026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17672026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17682026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete17692026/10/08 17:08:17 WARN Failed to register uploaded object key=p6byvfwyx6m4i2pvmsv17abf1jfdk1v9.ls error="server returned 404: 404 page not found\n"17702026/10/08 17:08:17 WARN Failed to register uploaded object key=nm6ny3qkz0hk1i206lgzjlj8ahrj776v.narinfo error="server returned 404: 404 page not found\n"17712026/10/08 17:08:17 INFO Signed narinfos id=1 count=217722026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17732026/10/08 17:08:17 INFO Signed narinfos id=2 count=217742026/10/08 17:08:17 INFO Uploading 4 narinfos17752026/10/08 17:08:17 WARN Failed to register uploaded object key=p6byvfwyx6m4i2pvmsv17abf1jfdk1v9.narinfo error="server returned 404: 404 page not found\n"17762026/10/08 17:08:17 INFO Completed push id=1 objects=3 duration=5.781112ms17772026/10/08 17:08:17 INFO Upload complete. (92ms)17782026/10/08 17:08:17 WARN Failed to register uploaded object key=qz346fn629ls1zdfmsfh60i85sr74x6c.narinfo error="server returned 404: 404 page not found\n"17792026/10/08 17:08:17 WARN Failed to register uploaded object key=wn77kb7vr0sb8ci6hrdcwizjyf9sb3m6.narinfo error="server returned 404: 404 page not found\n"17802026/10/08 17:08:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17812026/10/08 17:08:17 WARN Failed to register uploaded object key=p6byvfwyx6m4i2pvmsv17abf1jfdk1v9.narinfo error="server returned 404: 404 page not found\n"17822026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures17832026/10/08 17:08:17 INFO Completed upload id=2 objects=6 duration=5.343928ms17842026/10/08 17:08:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17852026/10/08 17:08:17 INFO Completed upload id=1 objects=6 duration=1.154851ms17862026/10/08 17:08:17 INFO Upload complete. (120ms)1787=== NAME TestClientFallsBackToClosures1788 client_pushes_test.go:112: Retrieved narinfo from S3:1789 StorePath: /build/TestClientFallsBackToClosures3494156015/001/store/p6byvfwyx6m4i2pvmsv17abf1jfdk1v9-shared-dep1790 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1791 Compression: zstd1792 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821793 NarSize: 1361794 References: 1795 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17962026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=01797 client_pushes_test.go:112: Retrieved narinfo from S3:1798 StorePath: /build/TestClientFallsBackToClosures3494156015/001/store/qz346fn629ls1zdfmsfh60i85sr74x6c-a1799 URL: nar/1gq5d003ss6b3ibcdyfm2n93dsi7lx9yg1a4ly02l38gglmrk4pi.nar.zst1800 Compression: zstd1801 NarHash: sha256:1gq5d003ss6b3ibcdyfm2n93dsi7lx9yg1a4ly02l38gglmrk4pi1802 NarSize: 2161803 References: /build/TestClientFallsBackToClosures3494156015/001/store/p6byvfwyx6m4i2pvmsv17abf1jfdk1v9-shared-dep1804 CA: text:sha256:04bmm2yy0cfh796adwr7wlkm6l2rfcsfc7nim7kifxpzgmnii3j118052026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1806 client_pushes_test.go:112: Retrieved narinfo from S3:1807 StorePath: /build/TestClientFallsBackToClosures3494156015/001/store/wn77kb7vr0sb8ci6hrdcwizjyf9sb3m6-b1808 URL: nar/1gq5d003ss6b3ibcdyfm2n93dsi7lx9yg1a4ly02l38gglmrk4pi.nar.zst1809 Compression: zstd1810 NarHash: sha256:1gq5d003ss6b3ibcdyfm2n93dsi7lx9yg1a4ly02l38gglmrk4pi1811 NarSize: 2161812 References: /build/TestClientFallsBackToClosures3494156015/001/store/p6byvfwyx6m4i2pvmsv17abf1jfdk1v9-shared-dep1813 CA: text:sha256:04bmm2yy0cfh796adwr7wlkm6l2rfcsfc7nim7kifxpzgmnii3j118142026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1815--- PASS: TestClientFallsBackToClosures (0.55s)1816=== CONT TestClientErrorHandling/InvalidAuthToken18172026/10/08 17:08:17 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18182026/10/08 17:08:17 INFO Uploading pzy8031ryh943g053zyrsmiz908nbq97-a (216B)18192026/10/08 17:08:17 INFO Uploading qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh-shared-dep (136B)18202026/10/08 17:08:17 WARN Failed to register uploaded object key=1d096vkkf1cdrnvv98ysg13xqw2dawdf.ls error="server returned 404: 404 page not found\n"18212026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18222026/10/08 17:08:17 WARN Failed to register uploaded object key=qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh.ls error="server returned 404: 404 page not found\n"18232026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/0mfbjqc8vv4jfh6dgvs4c4b18y3mhdmd64djxk4x5db67dcqwiwi.nar.zst error="server returned 404: 404 page not found\n"18242026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18252026/10/08 17:08:17 WARN Failed to register uploaded object key=pzy8031ryh943g053zyrsmiz908nbq97.ls error="server returned 404: 404 page not found\n"18262026/10/08 17:08:17 INFO Signed narinfos id=1 count=318272026/10/08 17:08:17 INFO Uploading 3 narinfos1828=== CONT TestClientErrorHandling/ServerNotAvailable18292026/10/08 17:08:17 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=018302026/10/08 17:08:17 WARN Failed to register uploaded object key=qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh.narinfo error="server returned 404: 404 page not found\n"18312026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete18322026/10/08 17:08:17 WARN Failed to register uploaded object key=1d096vkkf1cdrnvv98ysg13xqw2dawdf.narinfo error="server returned 404: 404 page not found\n"18332026/10/08 17:08:17 WARN Failed to register uploaded object key=pzy8031ryh943g053zyrsmiz908nbq97.narinfo error="server returned 404: 404 page not found\n"18342026/10/08 17:08:17 INFO Vacuumed table table=pending_closures18352026/10/08 17:08:17 INFO Vacuumed table table=pending_objects18362026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads18372026/10/08 17:08:17 INFO Vacuumed table table=closures18382026/10/08 17:08:17 INFO Vacuumed table table=objects18392026/10/08 17:08:17 INFO Completed push id=1 objects=8 duration=6.176995ms18402026/10/08 17:08:17 INFO Upload complete. (109ms)1841=== NAME TestClientPushesUseOnePush1842 client_pushes_test.go:97: Retrieved narinfo from S3:1843 StorePath: /build/TestClientPushesUseOnePush2002098615/001/store/qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh-shared-dep1844 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1845 Compression: zstd1846 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821847 NarSize: 1361848 References: 1849 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1850 client_pushes_test.go:97: Retrieved narinfo from S3:1851 StorePath: /build/TestClientPushesUseOnePush2002098615/001/store/pzy8031ryh943g053zyrsmiz908nbq97-a1852 URL: nar/0mfbjqc8vv4jfh6dgvs4c4b18y3mhdmd64djxk4x5db67dcqwiwi.nar.zst1853 Compression: zstd1854 NarHash: sha256:0mfbjqc8vv4jfh6dgvs4c4b18y3mhdmd64djxk4x5db67dcqwiwi1855 NarSize: 2161856 References: /build/TestClientPushesUseOnePush2002098615/001/store/qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh-shared-dep1857 CA: text:sha256:19q8rl7q9jn9yag7wn4glj9y47k1j17mi89l0a8qp3bzsaq4zh5v1858 client_pushes_test.go:97: Retrieved narinfo from S3:1859 StorePath: /build/TestClientPushesUseOnePush2002098615/001/store/1d096vkkf1cdrnvv98ysg13xqw2dawdf-b1860 URL: nar/0mfbjqc8vv4jfh6dgvs4c4b18y3mhdmd64djxk4x5db67dcqwiwi.nar.zst1861 Compression: zstd1862 NarHash: sha256:0mfbjqc8vv4jfh6dgvs4c4b18y3mhdmd64djxk4x5db67dcqwiwi1863 NarSize: 2161864 References: /build/TestClientPushesUseOnePush2002098615/001/store/qa2nnl2v7yfh0dw9sp26mbx4xcqblsbh-shared-dep1865 CA: text:sha256:19q8rl7q9jn9yag7wn4glj9y47k1j17mi89l0a8qp3bzsaq4zh5v1866--- PASS: TestClientPushesUseOnePush (0.56s)1867=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18682026/10/08 17:08:17 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes1870=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18712026/10/08 17:08:17 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]1872=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1873=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1874=== CONT TestService_RequireScope_OIDC/builder_may_write1875=== CONT TestService_RequireScope_OIDC/reader_may_read1876=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read18772026/10/08 17:08:17 WARN Authentication failed token_preview=eyJhbGciOi...onS5B8S37A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1878=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18792026/10/08 17:08:17 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]1880=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1881=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1882=== CONT TestService_RequireScope_OIDC/writer_implies_read1883=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1884--- PASS: TestService_AuthMiddleware_OIDC (0.34s)1885 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1886 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1887 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1888 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1889=== CONT TestService_RequireScope_OIDC/reader_may_not_write1890=== CONT TestService_RequireScope_OIDC/static_token_may_write1891=== CONT TestService_RequireScope_OIDC/static_token_may_admin1892=== CONT TestService_RequireScope_OIDC/ops_may_admin1893=== CONT TestService_RequireScope_OIDC/ops_may_not_write1894=== CONT TestService_RequireScope_OIDC/builder_may_not_admin18952026/10/08 17:08:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18962026/10/08 17:08:17 INFO Uploading p8zrcbgk0gy6drxri8aqz8h14gjf80pi-top (224B)18972026/10/08 17:08:17 INFO Uploading 7g1wz475lxd5h0g7f0dlqbw4l13wwin7-shared-dep (136B)1898--- PASS: TestService_RequireScope_OIDC (0.35s)1899 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19132026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/04k27qn2lqwaj30a0q2ii1zhwfh85b701fixc4fq01waaaxzv9zp.nar.zst error="server returned 404: 404 page not found\n"19142026/10/08 17:08:17 WARN Failed to register uploaded object key=p8zrcbgk0gy6drxri8aqz8h14gjf80pi.ls error="server returned 404: 404 page not found\n"19152026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19162026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19172026/10/08 17:08:17 WARN Failed to register uploaded object key=7g1wz475lxd5h0g7f0dlqbw4l13wwin7.ls error="server returned 404: 404 page not found\n"19182026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=019192026/10/08 17:08:17 INFO Signed narinfos id=1 count=219202026/10/08 17:08:17 INFO Uploading 2 narinfos19212026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete19222026/10/08 17:08:17 WARN Failed to register uploaded object key=7g1wz475lxd5h0g7f0dlqbw4l13wwin7.narinfo error="server returned 404: 404 page not found\n"19232026/10/08 17:08:17 WARN Failed to register uploaded object key=p8zrcbgk0gy6drxri8aqz8h14gjf80pi.narinfo error="server returned 404: 404 page not found\n"19242026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes19252026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period19262026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19272026/10/08 17:08:17 INFO Uploading injgyj3g4hg3ksv7h88yl4k815wshr81-unpinned-file.txt (128B)19282026/10/08 17:08:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019292026/10/08 17:08:17 INFO Completed push id=1 objects=6 duration=6.378177ms19302026/10/08 17:08:17 INFO Upload complete. (62ms)19312026/10/08 17:08:17 INFO Vacuumed table table=pending_closures19322026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1933=== NAME TestClientSharedPathCommittedMidPush1934 client_integration_test.go:680: Retrieved narinfo from S3:1935 StorePath: /build/TestClientSharedPathCommittedMidPush56928033/001/store/7g1wz475lxd5h0g7f0dlqbw4l13wwin7-shared-dep1936 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1937 Compression: zstd1938 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821939 NarSize: 1361940 References: 19412026/10/08 17:08:17 WARN Failed to register uploaded object key=injgyj3g4hg3ksv7h88yl4k815wshr81.ls error="server returned 404: 404 page not found\n"1942 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19432026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19442026/10/08 17:08:17 INFO Signed narinfos id=2 count=119452026/10/08 17:08:17 INFO Uploading 1 narinfos19462026/10/08 17:08:17 INFO Vacuumed table table=pending_objects19472026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads19482026/10/08 17:08:17 INFO Vacuumed table table=closures1949 client_integration_test.go:680: Retrieved narinfo from S3:1950 StorePath: /build/TestClientSharedPathCommittedMidPush56928033/001/store/p8zrcbgk0gy6drxri8aqz8h14gjf80pi-top1951 URL: nar/04k27qn2lqwaj30a0q2ii1zhwfh85b701fixc4fq01waaaxzv9zp.nar.zst1952 Compression: zstd1953 NarHash: sha256:04k27qn2lqwaj30a0q2ii1zhwfh85b701fixc4fq01waaaxzv9zp1954 NarSize: 2241955 References: /build/TestClientSharedPathCommittedMidPush56928033/001/store/7g1wz475lxd5h0g7f0dlqbw4l13wwin7-shared-dep1956 CA: text:sha256:0h365r69h7jl1ivimql7pwj6ka241z7g3k4v5kf3ga2hcv1lflwp19572026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/2/complete19582026/10/08 17:08:17 INFO Vacuumed table table=objects19592026/10/08 17:08:17 WARN Failed to register uploaded object key=injgyj3g4hg3ksv7h88yl4k815wshr81.narinfo error="server returned 404: 404 page not found\n"19602026/10/08 17:08:17 INFO Completed push id=2 objects=3 duration=1.652114ms19612026/10/08 17:08:17 INFO Upload complete. (44ms)1962--- PASS: TestClientSharedPathCommittedMidPush (0.47s)19632026/10/08 17:08:17 INFO Received push request method=POST path=/api/pushes19642026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=019652026/10/08 17:08:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19662026/10/08 17:08:17 INFO Uploading 4hiskgdg5l6grsyhgqcdp4ydwyga10ap-ca-test (144B)19672026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period19682026/10/08 17:08:17 WARN Failed to register uploaded object key=4hiskgdg5l6grsyhgqcdp4ydwyga10ap.ls error="server returned 404: 404 page not found\n"19692026/10/08 17:08:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19702026/10/08 17:08:17 WARN Failed to register uploaded object key=log/7wd61azm8phk4cfsqqg73scxjj54zpri-ca-test.drv error="server returned 404: 404 page not found\n"19712026/10/08 17:08:17 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19722026/10/08 17:08:17 INFO Signed narinfos id=1 count=119732026/10/08 17:08:17 INFO Uploading 1 narinfos19742026/10/08 17:08:17 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/present19752026/10/08 17:08:17 INFO Received complete push request method=POST path=/api/pushes/1/complete19762026/10/08 17:08:17 WARN Failed to register uploaded object key=4hiskgdg5l6grsyhgqcdp4ydwyga10ap.narinfo error="server returned 404: 404 page not found\n"19772026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=01978--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1979 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.26s)1980 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.28s)19812026/10/08 17:08:17 INFO Completed push id=1 objects=4 duration=5.531689ms19822026/10/08 17:08:17 INFO Upload complete. (92ms)19832026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period1984=== NAME TestClientCADerivations1985 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations745236862/001/store/4hiskgdg5l6grsyhgqcdp4ydwyga10ap-ca-test1986 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1987 Compression: zstd1988 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1989 NarSize: 1441990 References: 1991 Deriver: /build/TestClientCADerivations745236862/001/store/7wd61azm8phk4cfsqqg73scxjj54zpri-ca-test.drv1992 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1993 client_ca_test.go:185: Checking for realisation files in S3...1994 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1995 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19962026/10/08 17:08:17 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44899/bucket98/?delete=\": context canceled"1997--- PASS: TestGCEndsOnShutdown (0.00s)1998 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)1999 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.23s)2000 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.20s)20012026/10/08 17:08:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures20022026/10/08 17:08:17 INFO Garbage collection started2003=== NAME TestOrphanedObjectsGCStressTest2004 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20052026/10/08 17:08:17 INFO Aborted multipart uploads count=0 kept=020062026/10/08 17:08:17 WARN Force mode enabled - objects will be deleted immediately without grace period2007 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20082026/10/08 17:08:17 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=020092026/10/08 17:08:17 INFO Vacuumed table table=pending_closures20102026/10/08 17:08:17 INFO Vacuumed table table=pending_objects20112026/10/08 17:08:17 INFO Vacuumed table table=multipart_uploads20122026/10/08 17:08:17 INFO Vacuumed table table=closures20132026/10/08 17:08:17 INFO Vacuumed table table=objects20142026/10/08 17:08:17 WARN Request failed, retrying attempt=2 backoff=208.940368ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2015=== NAME TestClientCADerivations2016 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2017 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2018 error: binary cache 's3://bucket88?endpoint=http://localhost:44899®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations745236862/001/store'2019 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12020--- PASS: TestClientCADerivations (0.67s)20212026/10/08 17:08:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20222026/10/08 17:08:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2023=== NAME TestOrphanedObjectsGCStressTest2024 orphaned_objects_gc_test.go:503: Stress test completed successfully:2025 orphaned_objects_gc_test.go:504: - Active objects preserved: 202026 orphaned_objects_gc_test.go:505: - Objects deleted: 2102027 orphaned_objects_gc_test.go:506: - Total GC'd: 2102028--- PASS: TestOrphanedObjectsGCStressTest (2.24s)20292026/10/08 17:08:17 WARN Request failed, retrying attempt=3 backoff=405.069021ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2030--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2031 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.74s)2032 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.79s)20332026/10/08 17:08:18 INFO lead: released remote=192.0.2.1:12342034--- PASS: TestLeadEndsOnShutdown (1.36s)2035--- PASS: TestPendingClosureWriteTimeout (0.08s)2036 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2037 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2038 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2039 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.04s)2040--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)2041 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)2042 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2043 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.99s)20442026/10/08 17:08:18 INFO lead: released remote=192.0.2.1:12342045--- PASS: TestDeleteClosuresRacingPins (1.46s)20462026/10/08 17:08:18 INFO lead: acquired remote=192.0.2.1:123420472026/10/08 17:08:18 WARN Request failed, retrying attempt=4 backoff=864.570791ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20482026/10/08 17:08:19 WARN Request failed, retrying attempt=5 backoff=1.611051539s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20492026/10/08 17:08:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02050=== NAME TestClientIntegration2051 client_integration_test.go:323: Objects in database after GC:2052 client_integration_test.go:323: Successfully deleted all objects with GC --force2053--- PASS: TestClientIntegration (2.53s)20542026/10/08 17:08:19 INFO lead: released remote=192.0.2.1:12342055--- PASS: TestLeadElectsOneAndHandsOver (2.67s)20562026/10/08 17:08:19 WARN Rate limiter enabled after throttle name=s3-test rate=520572026/10/08 17:08:19 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2058=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2059 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102060 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002061--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.28s)20622026/10/08 17:08:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020632026/10/08 17:08:19 INFO Received create pin request method=POST path=/api/pins/myapp20642026/10/08 17:08:19 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1132559113/001/store/nm6ny3qkz0hk1i206lgzjlj8ahrj776v-pinned-file.txt narinfo_key=nm6ny3qkz0hk1i206lgzjlj8ahrj776v.narinfo20652026/10/08 17:08:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures20662026/10/08 17:08:19 INFO Garbage collection started20672026/10/08 17:08:19 INFO Aborted multipart uploads count=0 kept=020682026/10/08 17:08:19 WARN Force mode enabled - objects will be deleted immediately without grace period20692026/10/08 17:08: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=020702026/10/08 17:08:19 INFO Vacuumed table table=pending_closures20712026/10/08 17:08:19 INFO Vacuumed table table=pending_objects20722026/10/08 17:08:19 INFO Vacuumed table table=multipart_uploads20732026/10/08 17:08:19 INFO Vacuumed table table=closures20742026/10/08 17:08:19 INFO Vacuumed table table=objects2075--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.65s)20762026/10/08 17:08:20 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-config20772026/10/08 17:08:20 WARN Request failed, retrying attempt=2 backoff=203.58292ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20782026/10/08 17:08:21 WARN Request failed, retrying attempt=3 backoff=380.345212ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20792026/10/08 17:08:21 WARN Request failed, retrying attempt=4 backoff=874.488752ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2080=== NAME TestPinProtectsFromGC2081 client_integration_test.go:840: Pin successfully protected closure from garbage collection2082--- PASS: TestPinProtectsFromGC (4.63s)2083--- PASS: TestConnectWaitsForAPeerMigration (5.13s)20842026/10/08 17:08:22 WARN Request failed, retrying attempt=5 backoff=1.66819697s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20852026/10/08 17:08:22 INFO Aborted multipart uploads count=1 kept=020862026/10/08 17:08:22 INFO Received cleanup request method=DELETE path=/api/pending_closures20872026/10/08 17:08:22 INFO Aborted multipart uploads count=1 kept=02088--- PASS: TestPendingCleanupUsesOneCutoff (6.47s)20892026/10/08 17:08:24 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"20902026/10/08 17:08:24 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-config20912026/10/08 17:08:24 WARN Request failed, retrying attempt=2 backoff=203.172322ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20922026/10/08 17:08:24 WARN Request failed, retrying attempt=3 backoff=432.103204ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20932026/10/08 17:08:24 WARN Request failed, retrying attempt=4 backoff=833.06174ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20942026/10/08 17:08:25 WARN Request failed, retrying attempt=5 backoff=1.696863306s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/08 17:08:27 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_closures20962026/10/08 17:08:27 WARN Request failed, retrying attempt=2 backoff=213.319639ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20972026/10/08 17:08:27 WARN Request failed, retrying attempt=3 backoff=401.986822ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20982026/10/08 17:08:28 WARN Request failed, retrying attempt=4 backoff=855.573564ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20992026/10/08 17:08:28 WARN Request failed, retrying attempt=5 backoff=1.692228041s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2100--- PASS: TestClientErrorHandling (0.00s)2101 --- PASS: TestClientErrorHandling/InvalidStorePath (0.22s)2102 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.23s)2103 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.07s)2104PASS21052026-10-08 17:08:30.854 UTC [128] LOG: received smart shutdown request21062026-10-08 17:08:30.858 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121072026-10-08 17:08:30.870 UTC [133] LOG: shutting down21082026-10-08 17:08:30.871 UTC [133] LOG: checkpoint starting: shutdown immediate21092026-10-08 17:08:31.346 UTC [133] LOG: checkpoint complete: wrote 10378 buffers (63.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.167 s, sync=0.282 s, total=0.476 s; sync files=34045, longest=0.006 s, average=0.001 s; distance=531617 kB, estimate=531617 kB; lsn=0/21E8E258, redo lsn=0/21E8E25821102026-10-08 17:08:31.420 UTC [128] LOG: database system is shut down2111Running OIDC tests...2112=== RUN TestAudienceForIssuer2113=== PAUSE TestAudienceForIssuer2114=== RUN TestGlobMatch2115=== PAUSE TestGlobMatch2116=== RUN TestValidateToken_ValidToken2117=== PAUSE TestValidateToken_ValidToken2118=== RUN TestValidateToken_WrongAudience2119=== PAUSE TestValidateToken_WrongAudience2120=== RUN TestValidateToken_Expired2121=== PAUSE TestValidateToken_Expired2122=== RUN TestValidateToken_BoundClaimsMismatch2123=== PAUSE TestValidateToken_BoundClaimsMismatch2124=== RUN TestValidateToken_BoundSubjectMismatch2125=== PAUSE TestValidateToken_BoundSubjectMismatch2126=== RUN TestValidateToken_MultipleProviders2127=== PAUSE TestValidateToken_MultipleProviders2128=== RUN TestValidateToken_NoMatchingProvider2129=== PAUSE TestValidateToken_NoMatchingProvider2130=== RUN TestValidateToken_KubernetesServiceAccount2131=== PAUSE TestValidateToken_KubernetesServiceAccount2132=== RUN TestNewValidator_KubernetesRequiresCA2133=== PAUSE TestNewValidator_KubernetesRequiresCA2134=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2135=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2136=== RUN TestPins_ReservedForMatchingRule2137=== PAUSE TestPins_ReservedForMatchingRule2138=== RUN TestPins_TopLevelShorthand2139=== PAUSE TestPins_TopLevelShorthand2140=== RUN TestPins_ConfigValidation2141=== PAUSE TestPins_ConfigValidation2142=== RUN TestScopes_LegacyProviderDefaultsToWrite2143=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2144=== RUN TestScopes_Rules2145=== PAUSE TestScopes_Rules2146=== RUN TestScopes_ConfigValidation2147=== PAUSE TestScopes_ConfigValidation2148=== CONT TestAudienceForIssuer2149=== CONT TestPins_ConfigValidation2150=== CONT TestValidateToken_BoundClaimsMismatch2151--- PASS: TestAudienceForIssuer (0.00s)2152=== CONT TestValidateToken_Expired2153=== CONT TestValidateToken_WrongAudience2154=== CONT TestValidateToken_ValidToken2155=== CONT TestGlobMatch2156=== RUN TestGlobMatch/foo_foo2157=== PAUSE TestGlobMatch/foo_foo2158=== RUN TestGlobMatch/foo_bar2159=== PAUSE TestGlobMatch/foo_bar2160=== RUN TestGlobMatch/*_2161=== PAUSE TestGlobMatch/*_2162=== RUN TestGlobMatch/*_anything2163=== PAUSE TestGlobMatch/*_anything2164=== RUN TestGlobMatch/foo*_foo2165--- PASS: TestPins_ConfigValidation (0.00s)2166=== PAUSE TestGlobMatch/foo*_foo2167=== CONT TestScopes_ConfigValidation2168=== CONT TestValidateToken_MultipleProviders2169=== CONT TestValidateToken_NoMatchingProvider2170=== CONT TestPins_ReservedForMatchingRule2171=== CONT TestPins_TopLevelShorthand2172--- PASS: TestScopes_ConfigValidation (0.00s)2173=== CONT TestScopes_LegacyProviderDefaultsToWrite2174=== CONT TestValidateToken_BoundSubjectMismatch2175=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2176=== CONT TestNewValidator_KubernetesRequiresCA2177=== CONT TestValidateToken_KubernetesServiceAccount2178=== CONT TestScopes_Rules2179=== RUN TestGlobMatch/foo*_foobar2180=== PAUSE TestGlobMatch/foo*_foobar2181=== RUN TestGlobMatch/foo*_bar2182=== PAUSE TestGlobMatch/foo*_bar2183=== RUN TestGlobMatch/*bar_bar2184=== PAUSE TestGlobMatch/*bar_bar2185=== RUN TestGlobMatch/*bar_foobar2186=== PAUSE TestGlobMatch/*bar_foobar2187=== RUN TestGlobMatch/*bar_foo2188=== PAUSE TestGlobMatch/*bar_foo2189=== RUN TestGlobMatch/foo*bar_foobar2190=== PAUSE TestGlobMatch/foo*bar_foobar2191=== RUN TestGlobMatch/foo*bar_foo123bar2192=== PAUSE TestGlobMatch/foo*bar_foo123bar2193=== RUN TestGlobMatch/foo*bar_foobarbaz2194=== PAUSE TestGlobMatch/foo*bar_foobarbaz2195=== RUN TestGlobMatch/*/*_foo/bar2196=== PAUSE TestGlobMatch/*/*_foo/bar2197=== RUN TestGlobMatch/*/*_foo2198=== PAUSE TestGlobMatch/*/*_foo2199=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2200=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2201=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02202=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02203=== RUN TestGlobMatch/refs/*/main_refs/heads/main2204=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2205=== RUN TestGlobMatch/fo?_foo2206=== PAUSE TestGlobMatch/fo?_foo2207=== RUN TestGlobMatch/fo?_fo2208=== PAUSE TestGlobMatch/fo?_fo2209=== RUN TestGlobMatch/fo?_fooo2210=== PAUSE TestGlobMatch/fo?_fooo2211=== RUN TestGlobMatch/?oo_foo2212=== PAUSE TestGlobMatch/?oo_foo2213=== RUN TestGlobMatch/?oo_boo2214=== PAUSE TestGlobMatch/?oo_boo2215=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2216=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2217=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2218=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2219=== CONT TestGlobMatch/foo_foo2220=== CONT TestGlobMatch/?oo_foo2221=== CONT TestGlobMatch/fo?_fooo2222=== CONT TestGlobMatch/fo?_fo2223=== CONT TestGlobMatch/fo?_foo2224=== CONT TestGlobMatch/refs/*/main_refs/heads/main2225=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02226=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2227=== CONT TestGlobMatch/*/*_foo2228=== CONT TestGlobMatch/*/*_foo/bar2229=== CONT TestGlobMatch/foo*bar_foobarbaz2230=== CONT TestGlobMatch/foo*_bar2231=== CONT TestGlobMatch/foo*bar_foo123bar2232=== CONT TestGlobMatch/foo*bar_foobar2233=== CONT TestGlobMatch/*bar_foobar2234=== CONT TestGlobMatch/*bar_bar2235=== CONT TestGlobMatch/?oo_boo2236=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2237=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2238=== CONT TestGlobMatch/foo*_foobar2239=== CONT TestGlobMatch/foo*_foo2240=== CONT TestGlobMatch/*_anything2241=== CONT TestGlobMatch/*_2242=== CONT TestGlobMatch/foo_bar2243=== CONT TestGlobMatch/*bar_foo2244--- PASS: TestGlobMatch (0.00s)2245 --- PASS: TestGlobMatch/foo_foo (0.00s)2246 --- PASS: TestGlobMatch/?oo_foo (0.00s)2247 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2248 --- PASS: TestGlobMatch/fo?_fo (0.00s)2249 --- PASS: TestGlobMatch/fo?_foo (0.00s)2250 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2251 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2252 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2253 --- PASS: TestGlobMatch/*/*_foo (0.00s)2254 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2255 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2256 --- PASS: TestGlobMatch/foo*_bar (0.00s)2257 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2258 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2259 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2260 --- PASS: TestGlobMatch/*bar_bar (0.00s)2261 --- PASS: TestGlobMatch/?oo_boo (0.00s)2262 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2263 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2264 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2265 --- PASS: TestGlobMatch/foo*_foo (0.00s)2266 --- PASS: TestGlobMatch/*_anything (0.00s)2267 --- PASS: TestGlobMatch/*_ (0.00s)2268 --- PASS: TestGlobMatch/foo_bar (0.00s)2269 --- PASS: TestGlobMatch/*bar_foo (0.00s)22702026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44951/oidc22712026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46507/oidc22722026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32885/oidc2273--- PASS: TestValidateToken_ValidToken (0.09s)2274--- PASS: TestValidateToken_WrongAudience (0.09s)22752026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40887/oidc2276--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2277--- PASS: TestScopes_Rules (0.10s)22782026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41817/oidc22792026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36467/oidc2280--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)2281--- PASS: TestPins_ReservedForMatchingRule (0.11s)22822026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33739/oidc2283--- PASS: TestValidateToken_Expired (0.14s)22842026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34041/oidc2285--- PASS: TestPins_TopLevelShorthand (0.15s)22862026/10/08 17:08:33 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:349172287--- PASS: TestValidateToken_KubernetesServiceAccount (0.17s)22882026/10/08 17:08:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37101/oidc22892026/10/08 17:08:33 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37875/oidc2290--- PASS: TestValidateToken_MultipleProviders (0.19s)22912026/10/08 17:08:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45737/oidc22922026/10/08 17:08:33 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232293--- PASS: TestValidateToken_BoundClaimsMismatch (0.25s)2294--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.25s)22952026/10/08 17:08:33 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36201/oidc2296--- PASS: TestValidateToken_NoMatchingProvider (0.26s)22972026/10/08 17:08:33 http: TLS handshake error from 127.0.0.1:43428: remote error: tls: bad certificate2298--- PASS: TestNewValidator_KubernetesRequiresCA (0.33s)2299PASS2300Running hook tests...2301=== RUN TestSendPathsEmpty2302=== PAUSE TestSendPathsEmpty2303=== RUN TestQueueEnqueueAndFetch2304=== PAUSE TestQueueEnqueueAndFetch2305=== RUN TestQueueDeduplication2306=== PAUSE TestQueueDeduplication2307=== RUN TestQueueRemove2308=== PAUSE TestQueueRemove2309=== RUN TestQueueFetchBatchLimit2310=== PAUSE TestQueueFetchBatchLimit2311=== RUN TestQueueRetryMovesToBack2312=== PAUSE TestQueueRetryMovesToBack2313=== RUN TestQueueFetchRemoveLifecycle2314=== PAUSE TestQueueFetchRemoveLifecycle2315=== RUN TestQueueConcurrentWriters2316=== PAUSE TestQueueConcurrentWriters2317=== RUN TestQueueRemoveLargeClosure2318=== PAUSE TestQueueRemoveLargeClosure2319=== RUN TestServerClientIntegration2320--- PASS: TestServerClientIntegration (0.00s)2321=== RUN TestServerQueueError23222026/10/08 17:08:33 ERROR Failed to queue paths error="permission denied" count=12323--- PASS: TestServerQueueError (0.00s)2324=== RUN TestGetListenerSocketActivation2325 server_test.go:219: === RUN TestGetListenerSocketActivation2326 --- PASS: TestGetListenerSocketActivation (0.00s)2327 PASS2328 2329--- PASS: TestGetListenerSocketActivation (0.01s)2330=== RUN TestDrainIsolatesPoisonPath2331=== PAUSE TestDrainIsolatesPoisonPath2332=== RUN TestRunNotBlockedByPoisonHead2333=== PAUSE TestRunNotBlockedByPoisonHead2334=== RUN TestDrainGivesUpWhenServerDown2335=== PAUSE TestDrainGivesUpWhenServerDown2336=== RUN TestFailedPathPrunedByLaterClosure2337=== PAUSE TestFailedPathPrunedByLaterClosure2338=== RUN TestWorkerUploadsAndRemoves2339=== PAUSE TestWorkerUploadsAndRemoves2340=== RUN TestWorkerSkipsGCdPaths2341=== PAUSE TestWorkerSkipsGCdPaths2342=== RUN TestWorkerPrunesClosureDeps2343=== PAUSE TestWorkerPrunesClosureDeps2344=== RUN TestDrainTimeout2345=== PAUSE TestDrainTimeout2346=== CONT TestSendPathsEmpty2347=== CONT TestQueueFetchBatchLimit2348=== CONT TestQueueConcurrentWriters2349=== CONT TestDrainTimeout2350=== CONT TestWorkerPrunesClosureDeps2351--- PASS: TestSendPathsEmpty (0.00s)2352=== CONT TestWorkerSkipsGCdPaths2353=== CONT TestWorkerUploadsAndRemoves2354=== CONT TestQueueRemove2355=== CONT TestFailedPathPrunedByLaterClosure2356=== CONT TestQueueDeduplication2357=== CONT TestDrainGivesUpWhenServerDown2358=== CONT TestQueueEnqueueAndFetch2359=== CONT TestRunNotBlockedByPoisonHead2360=== CONT TestDrainIsolatesPoisonPath2361=== CONT TestQueueRemoveLargeClosure2362=== CONT TestQueueRetryMovesToBack2363=== CONT TestQueueFetchRemoveLifecycle23642026/10/08 17:08:33 INFO Uploading batch count=223652026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=223662026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/a23672026/10/08 17:08:33 INFO Upload queue status pending=223682026/10/08 17:08:33 INFO Uploading batch count=223692026/10/08 17:08:33 INFO Uploading batch count=123702026/10/08 17:08:33 INFO Upload queue status pending=323712026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=123722026/10/08 17:08:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths837459254/002/nonexistent23732026/10/08 17:08:33 INFO Uploading batch count=123742026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=123752026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/b23762026/10/08 17:08:33 INFO Uploading batch count=12377--- PASS: TestQueueEnqueueAndFetch (0.01s)2378--- PASS: TestQueueRemove (0.01s)2379--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23802026/10/08 17:08:33 INFO Uploading batch count=423812026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=423822026/10/08 17:08:33 INFO Upload queue status pending=223832026/10/08 17:08:33 INFO Uploading batch count=223842026/10/08 17:08:33 INFO Upload queue status pending=223852026/10/08 17:08:33 INFO Uploading batch count=223862026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=223872026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3053067408/002/bbb2388--- PASS: TestQueueDeduplication (0.01s)23892026/10/08 17:08:33 INFO Uploading batch count=123902026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/c23912026/10/08 17:08:33 INFO Uploading batch count=12392--- PASS: TestQueueFetchBatchLimit (0.02s)23932026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/d23942026/10/08 17:08:33 INFO Uploading batch count=12395--- PASS: TestQueueRetryMovesToBack (0.01s)23962026/10/08 17:08:33 INFO Uploading batch count=223972026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=223982026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/e23992026/10/08 17:08:33 INFO Uploading batch count=124002026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=124012026/10/08 17:08:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown234107192/002/f24022026/10/08 17:08:33 INFO Uploading batch count=124032026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=124042026/10/08 17:08:33 ERROR Drain finished with paths left in queue remaining=1024052026/10/08 17:08:33 INFO Uploading batch count=12406--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24072026/10/08 17:08:33 ERROR Upload failed error="upload failed" count=124082026/10/08 17:08:33 ERROR Drain finished with paths left in queue remaining=12409--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2410--- PASS: TestDrainIsolatesPoisonPath (0.02s)2411--- PASS: TestWorkerSkipsGCdPaths (0.03s)2412--- PASS: TestWorkerUploadsAndRemoves (0.03s)2413--- PASS: TestWorkerPrunesClosureDeps (0.03s)2414--- PASS: TestQueueRemoveLargeClosure (0.10s)2415--- PASS: TestQueueConcurrentWriters (0.16s)24162026/10/08 17:08:33 ERROR Upload failed error="context deadline exceeded" count=224172026/10/08 17:08:33 ERROR Drain finished with paths left in queue remaining=42418--- PASS: TestDrainTimeout (0.21s)24192026/10/08 17:08:34 INFO Uploading batch count=124202026/10/08 17:08:34 INFO Uploading batch count=124212026/10/08 17:08:34 INFO Uploading batch count=124222026/10/08 17:08:34 ERROR Upload failed error="upload failed" count=124232026/10/08 17:08:34 INFO Uploading batch count=124242026/10/08 17:08:34 ERROR Upload failed error="upload failed" count=124252026/10/08 17:08:34 INFO Uploading batch count=124262026/10/08 17:08:34 ERROR Upload failed error="upload failed" count=124272026/10/08 17:08:34 INFO Uploading batch count=124282026/10/08 17:08:34 ERROR Upload failed error="upload failed" count=124292026/10/08 17:08:34 ERROR Drain finished with paths left in queue remaining=12430--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2431PASS2432Running signing tests...2433=== RUN TestExternalSigner2434=== PAUSE TestExternalSigner2435=== RUN TestExternalSignerWrongPublicKey2436=== PAUSE TestExternalSignerWrongPublicKey2437=== RUN TestExternalSignerErrors2438=== PAUSE TestExternalSignerErrors2439=== RUN TestExternalSignerRestartsAfterCrash2440=== PAUSE TestExternalSignerRestartsAfterCrash2441=== RUN TestExternalSignerProgramErrorKeepsProcess2442=== PAUSE TestExternalSignerProgramErrorKeepsProcess2443=== RUN TestExternalSignerClose2444=== PAUSE TestExternalSignerClose2445=== RUN TestExternalSignerRejectsInvalidPublicKey2446=== PAUSE TestExternalSignerRejectsInvalidPublicKey2447=== RUN TestExternalSignerCancellation2448=== PAUSE TestExternalSignerCancellation2449=== RUN TestGenerateFingerprint2450=== PAUSE TestGenerateFingerprint2451=== RUN TestParseSigningKey2452=== PAUSE TestParseSigningKey2453=== RUN TestSign2454=== PAUSE TestSign2455=== RUN TestSignBatch2456=== PAUSE TestSignBatch2457=== RUN TestNilKeyPublicKey2458=== PAUSE TestNilKeyPublicKey2459=== RUN TestSignErrors2460=== PAUSE TestSignErrors2461=== CONT TestExternalSigner2462=== CONT TestExternalSignerCancellation2463=== CONT TestExternalSignerProgramErrorKeepsProcess2464=== CONT TestExternalSignerWrongPublicKey2465=== CONT TestSignErrors2466=== CONT TestExternalSignerErrors2467=== CONT TestNilKeyPublicKey2468--- PASS: TestNilKeyPublicKey (0.00s)2469=== CONT TestSignBatch2470=== CONT TestSign2471=== CONT TestParseSigningKey2472=== RUN TestParseSigningKey/valid_32-byte_key2473=== PAUSE TestParseSigningKey/valid_32-byte_key2474=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2475=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2476=== RUN TestParseSigningKey/no_colon2477=== PAUSE TestParseSigningKey/no_colon2478=== RUN TestParseSigningKey/empty_name2479=== PAUSE TestParseSigningKey/empty_name2480=== RUN TestParseSigningKey/invalid_base642481=== CONT TestGenerateFingerprint2482=== CONT TestExternalSignerRestartsAfterCrash2483=== CONT TestExternalSignerRejectsInvalidPublicKey2484=== RUN TestExternalSignerRejectsInvalidPublicKey/#002485=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002486=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2487=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2488=== CONT TestExternalSignerClose2489=== RUN TestExternalSignerErrors/wrong_shape2490=== PAUSE TestExternalSignerErrors/wrong_shape2491=== RUN TestExternalSignerErrors/null2492=== PAUSE TestExternalSignerErrors/null2493=== RUN TestExternalSignerErrors/wrong_signature_length2494=== PAUSE TestExternalSignerErrors/wrong_signature_length2495=== RUN TestExternalSignerErrors/program_error2496=== PAUSE TestParseSigningKey/invalid_base642497=== RUN TestGenerateFingerprint/basic_with_references2498=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2499=== PAUSE TestExternalSignerErrors/program_error2500=== RUN TestExternalSignerErrors/exit_on_request2501=== PAUSE TestExternalSignerErrors/exit_on_request2502=== RUN TestExternalSignerErrors/wrong_id2503=== PAUSE TestExternalSignerErrors/wrong_id2504=== RUN TestExternalSignerErrors/missing_signatures2505=== PAUSE TestExternalSignerErrors/missing_signatures2506=== RUN TestExternalSignerErrors/wrong_signatures_shape2507=== RUN TestParseSigningKey/wrong_length2508=== PAUSE TestGenerateFingerprint/basic_with_references2509=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2510=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2511=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2512=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2513=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2514=== CONT TestExternalSignerRejectsInvalidPublicKey/#002515=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2516=== RUN TestGenerateFingerprint/no_references2517=== PAUSE TestGenerateFingerprint/no_references2518=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2519=== PAUSE TestParseSigningKey/wrong_length2520=== CONT TestParseSigningKey/valid_32-byte_key2521=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2522=== CONT TestParseSigningKey/empty_name2523=== RUN TestExternalSignerErrors/too_few_signatures2524=== CONT TestParseSigningKey/wrong_length2525=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2526=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2527=== CONT TestParseSigningKey/invalid_base642528=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2529=== CONT TestParseSigningKey/no_colon2530=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2531=== PAUSE TestExternalSignerErrors/too_few_signatures2532=== RUN TestExternalSignerErrors/unrequested_key2533=== PAUSE TestExternalSignerErrors/unrequested_key2534=== RUN TestExternalSignerErrors/wrong_signature_name2535=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2536--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2537 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2538 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2539 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2540 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2541 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2542=== PAUSE TestExternalSignerErrors/wrong_signature_name2543=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2544=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2545=== RUN TestGenerateFingerprint/invalid_nar_hash_length2546=== RUN TestExternalSignerErrors/invalid_signature_base642547=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2548=== PAUSE TestExternalSignerErrors/invalid_signature_base642549=== RUN TestExternalSignerErrors/invalid_JSON2550=== PAUSE TestExternalSignerErrors/invalid_JSON2551=== RUN TestExternalSignerErrors/null_signatures2552=== PAUSE TestExternalSignerErrors/null_signatures2553=== RUN TestGenerateFingerprint/invalid_store_path_prefix2554=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2555=== RUN TestGenerateFingerprint/invalid_reference_prefix2556=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2557=== CONT TestGenerateFingerprint/basic_with_references2558=== RUN TestExternalSignerErrors/missing_signature_name2559=== CONT TestGenerateFingerprint/invalid_store_path_prefix2560=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2561=== CONT TestGenerateFingerprint/invalid_reference_prefix2562=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2563=== RUN TestSignErrors/nil_key2564=== PAUSE TestSignErrors/nil_key2565=== CONT TestGenerateFingerprint/no_references2566=== CONT TestGenerateFingerprint/invalid_nar_hash_length2567--- PASS: TestGenerateFingerprint (0.00s)2568 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2569 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2570 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2571 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2572 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2573 --- PASS: TestGenerateFingerprint/no_references (0.00s)2574 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2575=== PAUSE TestExternalSignerErrors/missing_signature_name2576=== RUN TestExternalSignerErrors/exit_at_startup2577=== PAUSE TestExternalSignerErrors/exit_at_startup2578=== CONT TestExternalSignerErrors/wrong_shape2579=== CONT TestExternalSignerErrors/unrequested_key2580--- PASS: TestSign (0.00s)2581=== CONT TestExternalSignerErrors/wrong_signatures_shape2582=== CONT TestExternalSignerErrors/invalid_signature_base642583=== CONT TestExternalSignerErrors/wrong_signature_length2584=== CONT TestExternalSignerErrors/program_error2585=== CONT TestExternalSignerErrors/null_signatures2586=== CONT TestExternalSignerErrors/null2587=== RUN TestSignErrors/nil_narinfo2588=== PAUSE TestSignErrors/nil_narinfo2589=== RUN TestSignErrors/invalid_narinfo2590=== CONT TestExternalSignerErrors/exit_at_startup2591=== CONT TestExternalSignerErrors/missing_signature_name2592=== CONT TestExternalSignerErrors/wrong_id2593=== CONT TestExternalSignerErrors/too_few_signatures2594--- PASS: TestParseSigningKey (0.00s)2595 --- PASS: TestParseSigningKey/empty_name (0.00s)2596 --- PASS: TestParseSigningKey/wrong_length (0.00s)2597 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2598 --- PASS: TestParseSigningKey/no_colon (0.00s)2599 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2600 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2601--- PASS: TestSignBatch (0.00s)2602--- PASS: TestExternalSignerWrongPublicKey (0.01s)2603--- PASS: TestExternalSignerClose (0.01s)2604=== CONT TestExternalSignerErrors/missing_signatures2605=== CONT TestExternalSignerErrors/wrong_signature_name2606=== CONT TestExternalSignerErrors/exit_on_request2607=== CONT TestExternalSignerErrors/invalid_JSON2608=== PAUSE TestSignErrors/invalid_narinfo2609=== RUN TestSignErrors/canceled2610=== PAUSE TestSignErrors/canceled2611=== CONT TestSignErrors/nil_key2612=== CONT TestSignErrors/canceled2613=== CONT TestSignErrors/invalid_narinfo2614--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2615=== CONT TestSignErrors/nil_narinfo2616--- PASS: TestSignErrors (0.01s)2617 --- PASS: TestSignErrors/canceled (0.00s)2618 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2619 --- PASS: TestSignErrors/nil_key (0.00s)2620 --- PASS: TestSignErrors/nil_narinfo (0.00s)2621--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2622--- PASS: TestExternalSigner (0.01s)2623--- PASS: TestExternalSignerErrors (0.00s)2624 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2625 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2626 --- PASS: TestExternalSignerErrors/null (0.01s)2627 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2628 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2629 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2630 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2631 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2632 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2633 --- PASS: TestExternalSignerErrors/program_error (0.01s)2634 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2635 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2636 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2637 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2638 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2639 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2640--- PASS: TestExternalSignerCancellation (0.02s)2641PASS2642Running OpenBao signer tests...2643=== RUN TestSign2644=== PAUSE TestSign2645=== RUN TestSignErrors2646=== PAUSE TestSignErrors2647=== RUN TestServe2648=== PAUSE TestServe2649=== RUN TestServeRejectsGarbage2650=== PAUSE TestServeRejectsGarbage2651=== CONT TestSign2652=== CONT TestServe2653=== CONT TestServeRejectsGarbage2654=== CONT TestSignErrors2655=== RUN TestSignErrors/http_error2656--- PASS: TestServeRejectsGarbage (0.00s)2657=== PAUSE TestSignErrors/http_error2658=== RUN TestSignErrors/invalid_json2659=== PAUSE TestSignErrors/invalid_json2660=== RUN TestSignErrors/no_prefix2661=== PAUSE TestSignErrors/no_prefix2662=== RUN TestSignErrors/invalid_base642663=== PAUSE TestSignErrors/invalid_base642664=== CONT TestSignErrors/http_error2665=== CONT TestSignErrors/invalid_base642666=== CONT TestSignErrors/no_prefix2667=== CONT TestSignErrors/invalid_json2668--- PASS: TestServe (0.00s)2669--- PASS: TestSign (0.00s)2670--- PASS: TestSignErrors (0.00s)2671 --- PASS: TestSignErrors/invalid_json (0.00s)2672 --- PASS: TestSignErrors/no_prefix (0.00s)2673 --- PASS: TestSignErrors/invalid_base64 (0.00s)2674 --- PASS: TestSignErrors/http_error (0.00s)2675PASS