niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #357
· raw
1tribuchet: building on jamie2Running 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.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== PAUSE TestEncodeNixBase32/test_string_hash104=== RUN TestEncodeNixBase32/empty_input105=== PAUSE TestEncodeNixBase32/empty_input106=== CONT TestResolveStorePath107=== CONT TestDumpPathSingleFile108=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess109=== CONT TestRateLimiterFeedback1102026/10/05 11:18:45 WARN Rate limiter enabled after throttle name=server-test rate=5111=== 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 TestRunGarbageCollection_NotFoundAfterLocalRun120=== CONT TestPathInfoCACompatibility121=== CONT TestParsePathInfoJSONMultiplePaths122--- PASS: TestResolveStorePath (0.00s)123=== CONT TestScriptTokenScriptFails124=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths125=== CONT TestPathInfoHashCompatibility126=== CONT TestSetClientTLSErrors127=== CONT TestGetStorePathHash128=== CONT TestScriptTokenNoExpiryRerunsEveryCall129=== CONT TestConvertHashToNix32130=== RUN TestConvertHashToNix32/SRI_format_to_Nix32131=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32132=== CONT TestFileTokenEmpty133=== CONT TestFileTokenMissing134=== CONT TestFileTokenReadsAndCaches135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestStaticToken137=== CONT TestUploadMultipart_PartsInParallel138=== CONT TestUploadMultipart_SupersededByPeer139=== CONT TestDumpPathMatchesNix140=== CONT TestDumpPathWriterError141=== CONT TestPartSizeForNAR142=== RUN TestPathInfoCACompatibility/null_ca_field143=== CONT TestParsePathInfoJSON144=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths146=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths147=== CONT TestCaseHackSuffix148=== CONT TestScriptTokenEmptyCommand149=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)151=== RUN TestGetStorePathHash/valid_store_path152=== RUN TestConvertHashToNix32/already_Nix32_format153--- PASS: TestStaticToken (0.00s)154=== CONT TestFilterOversizedClosures155=== RUN TestUploadMultipart_SupersededByPeer/exists156=== CONT TestStreamPushReportsEveryPath1572026/10/05 11:18:45 WARN Rate limiter enabled after throttle name=server-test rate=5158=== PAUSE TestPathInfoCACompatibility/null_ca_field159=== RUN TestParsePathInfoJSON/Nix_format160=== RUN TestSetClientTLSErrors/missing_cert_file161=== RUN TestPartSizeForNAR/zero_stays_at_minimum162=== RUN TestPathInfoCACompatibility/old_string_format_-_text1632026/10/05 11:18:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37365164=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text165=== CONT TestStreamPushIsolatesFailures166=== CONT TestSetClientTLS167=== PAUSE TestConvertHashToNix32/already_Nix32_format1682026/10/05 11:18:46 INFO Garbage collection started169=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1702026/10/05 11:18:46 WARN Rate limiter backed off name=server-test rate=5171=== PAUSE TestGetStorePathHash/valid_store_path1722026/10/05 11:18:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37365173=== PAUSE TestUploadMultipart_SupersededByPeer/exists1742026/10/05 11:18:46 ERROR Upload failed error="bad path" count=3175=== RUN TestUploadMultipart_SupersededByPeer/missing176--- PASS: TestEncodeNixBase32WithRealHash (0.00s)177=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon178=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon179=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI180=== CONT TestClientSignaturesByStorePath181=== CONT TestShellSplitErrors182=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica183=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum184=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI185=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512186=== PAUSE TestSetClientTLSErrors/missing_cert_file187=== CONT TestStreamPushBatchesUnderLoad188=== PAUSE TestParsePathInfoJSON/Nix_format189=== RUN TestParsePathInfoJSON/Lix_format190=== PAUSE TestParsePathInfoJSON/Lix_format191=== RUN TestFilterOversizedClosures/no_limit_keeps_everything192=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything193=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped194=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== RUN TestFilterOversizedClosures/all_closures_skipped196=== PAUSE TestFilterOversizedClosures/all_closures_skipped197=== CONT TestStreamPushGivesUpOnDeadServer198=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1992026/10/05 11:18:46 ERROR Upload failed error="connection refused" count=20200=== CONT TestStreamPushReportsSignatures2012026/10/05 11:18:46 ERROR Server seems unavailable, giving up on batch untried=17202=== RUN TestConvertHashToNix32/invalid_format2032026/10/05 11:18:46 INFO Garbage collection started204=== PAUSE TestConvertHashToNix32/invalid_format205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive206=== RUN TestPathInfoCACompatibility/new_structured_format_-_text207=== CONT TestScriptTokenEmptyToken208--- PASS: TestScriptTokenEmptyCommand (0.00s)209--- PASS: TestFileTokenEmpty (0.00s)210=== CONT TestStreamPushRequestLine2112026/10/05 11:18:46 ERROR Upload failed error=boom count=1212=== RUN TestPartSizeForNAR/small_stays_at_minimum213=== CONT TestShellSplit214=== CONT TestScriptTokenCachesUntilRefresh215=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512216=== RUN TestSetClientTLSErrors/missing_key_file2172026/10/05 11:18:46 ERROR Upload failed error=boom count=1218=== PAUSE TestSetClientTLSErrors/missing_key_file219=== RUN TestSetClientTLSErrors/missing_ca_file220=== CONT TestEncodeNixBase32/test_string_hash221=== CONT TestRegisterUploadedObjectReusesConnections222=== CONT TestEncodeNixBase32/empty_input223=== CONT TestRateLimiterFeedback/429_enables_limiter224=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter225=== RUN TestSetClientTLS/rejects_connection_without_client_cert226=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert227=== CONT TestScriptTokenBadJSON228=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter229=== CONT TestRateLimiterFeedback/503_enables_limiter230=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text231=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method233=== RUN TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error235=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error236=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error237=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error238=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error239=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths240=== PAUSE TestUploadMultipart_SupersededByPeer/missing241=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths242=== CONT TestConvertHashToNix32/SRI_format_to_Nix322432026/10/05 11:18:46 WARN Rate limiter enabled after throttle name=server-test rate=5244=== CONT TestConvertHashToNix32/invalid_format2452026/10/05 11:18:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43987246=== CONT TestConvertHashToNix32/already_Nix32_format2472026/10/05 11:18:46 WARN Rate limiter enabled after throttle name=server-test rate=5248=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2492026/10/05 11:18:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:37043250=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon252=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI253=== CONT TestPathInfoCACompatibility/null_ca_field254=== CONT TestGetStorePathHash/valid_store_path255=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error256=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error257=== CONT TestGetStorePathHash/basename_without_hyphen_should_error258=== CONT TestUploadMultipart_SupersededByPeer/exists259=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2602026/10/05 11:18:46 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=2000261--- PASS: TestFileTokenMissing (0.00s)2622026/10/05 11:18:46 WARN Rate limiter backed off name=server-test rate=5263--- PASS: TestFileTokenReadsAndCaches (0.00s)264--- PASS: TestDoServerRequestAttachesToken (0.03s)265=== RUN TestParsePathInfoJSON/empty_input266=== PAUSE TestParsePathInfoJSON/empty_input267=== RUN TestParsePathInfoJSON/whitespace_only268=== PAUSE TestParsePathInfoJSON/whitespace_only2692026/10/05 11:18:46 WARN Rate limiter backed off name=server-test rate=5270=== RUN TestParsePathInfoJSON/invalid_JSON271=== PAUSE TestParsePathInfoJSON/invalid_JSON272=== PAUSE TestSetClientTLSErrors/missing_ca_file273=== RUN TestSetClientTLSErrors/invalid_ca_file274=== PAUSE TestSetClientTLSErrors/invalid_ca_file275=== CONT TestPathInfoCACompatibility/new_structured_format_-_text276=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== CONT TestSetClientTLSErrors/missing_cert_file278=== CONT TestPathInfoCACompatibility/old_string_format_-_text279=== CONT TestSetClientTLSErrors/invalid_ca_file280=== CONT TestSetClientTLSErrors/missing_key_file281=== CONT TestFilterOversizedClosures/no_limit_keeps_everything282=== CONT TestParsePathInfoJSON/whitespace_only283=== CONT TestParsePathInfoJSON/invalid_JSON284=== CONT TestParsePathInfoJSON/empty_input285=== CONT TestSetClientTLSErrors/missing_ca_file286=== CONT TestParsePathInfoJSON/Lix_format287=== PAUSE TestPartSizeForNAR/small_stays_at_minimum288=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum289=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum290=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts291=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts292=== RUN TestPartSizeForNAR/1_TiB293--- PASS: TestScriptTokenScriptFails (0.03s)294=== CONT TestParsePathInfoJSON/Nix_format295=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA297=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA298=== CONT TestFilterOversizedClosures/all_closures_skipped299=== PAUSE TestPartSizeForNAR/1_TiB300=== RUN TestSetClientTLS/preserves_debug_logging_transport3012026/10/05 11:18:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50302=== PAUSE TestSetClientTLS/preserves_debug_logging_transport303=== CONT TestUploadMultipart_SupersededByPeer/missing304--- PASS: TestStreamPushReportsEveryPath (0.00s)3052026/10/05 11:18:46 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=0306--- PASS: TestStreamPushIsolatesFailures (0.00s)307--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)308--- PASS: TestClientSignaturesByStorePath (0.00s)309--- PASS: TestShellSplitErrors (0.00s)310=== RUN TestPartSizeForNAR/5_TiB_S3_max_object311=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object312=== RUN TestPartSizeForNAR/capped_at_5_GiB313=== PAUSE TestPartSizeForNAR/capped_at_5_GiB314=== CONT TestPartSizeForNAR/zero_stays_at_minimum315=== CONT TestSetClientTLS/rejects_connection_without_client_cert316=== CONT TestPartSizeForNAR/1_TiB317=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts318=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum319=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA320--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)321--- PASS: TestStreamPushReportsSignatures (0.00s)322--- PASS: TestShellSplit (0.00s)323=== CONT TestPartSizeForNAR/small_stays_at_minimum324=== CONT TestPartSizeForNAR/capped_at_5_GiB325=== CONT TestPartSizeForNAR/5_TiB_S3_max_object326=== CONT TestSetClientTLS/preserves_debug_logging_transport3272026/10/05 11:18:46 WARN Garbage collection finished on another replica. Its statistics are not available here328--- PASS: TestEncodeNixBase32 (0.00s)329 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)330 --- PASS: TestEncodeNixBase32/empty_input (0.00s)331--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)332--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)333--- PASS: TestScriptTokenBadJSON (0.00s)334--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)335--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)336 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)337 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)338--- PASS: TestConvertHashToNix32 (0.03s)339 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)340 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)341 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)342--- PASS: TestPathInfoHashCompatibility (0.03s)343 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)344 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)345 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)346 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)347--- PASS: TestGetStorePathHash (0.03s)348 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)351 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)352--- PASS: TestRateLimiterFeedback (0.00s)353 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)357--- PASS: TestDumpPathSingleFile (0.04s)358--- PASS: TestScriptTokenEmptyToken (0.01s)359--- PASS: TestPathInfoCACompatibility (0.03s)360 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)361 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)362 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)363 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)365--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)366--- PASS: TestFilterOversizedClosures (0.00s)367 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)368 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)369 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)370--- PASS: TestParsePathInfoJSON (0.03s)371 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)372 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)373 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)374 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)375 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)376--- PASS: TestPartSizeForNAR (0.04s)377 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)378 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)379 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)383 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)384--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)385 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)386 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)387--- PASS: TestSetClientTLSErrors (0.05s)388 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)390 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)392--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)393--- PASS: TestStreamPushRequestLine (0.03s)3942026/10/05 11:18:46 http: TLS handshake error from 127.0.0.1:38558: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)399--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)400--- PASS: TestCaseHackSuffix (0.07s)401--- PASS: TestDumpPathWriterError (0.07s)402--- PASS: TestDumpPathMatchesNix (0.11s)403--- PASS: TestStreamPushBatchesUnderLoad (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.66s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2653754688/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres2653754688/data -l logfile start434435/build/postgres2653754688:5432 - no response4362026-10-05 11:18:47.821 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-05 11:18:47.822 UTC [129] LOG: listening on Unix socket "/build/postgres2653754688/.s.PGSQL.5432"4382026-10-05 11:18:47.826 UTC [136] LOG: database system was shut down at 2026-10-05 11:18:47 UTC4392026-10-05 11:18:47.830 UTC [129] LOG: database system is ready to accept connections440/build/postgres2653754688:5432 - accepting connections441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/05 11:18:48 INFO lead: acquired remote=192.0.2.1:12344872026/10/05 11:18:49 INFO lead: released remote=192.0.2.1:12344882026/10/05 11:18:49 INFO lead: acquired remote=192.0.2.1:12344892026/10/05 11:18:50 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.28s)491=== RUN TestLeadIncumbentAnnouncesAtOnce492=== PAUSE TestLeadIncumbentAnnouncesAtOnce493=== RUN TestLeadEndsOnShutdown494=== PAUSE TestLeadEndsOnShutdown495=== RUN TestLeadEndsWhenItsConnectionHangs4962026/10/05 11:18:50 INFO lead: acquired remote=192.0.2.1:12344972026-10-05 11:18:52.067 UTC [575] FATAL: terminating connection due to administrator command4982026/10/05 11:18:52 INFO lead: acquired remote=192.0.2.1:12344992026/10/05 11:18:53 WARN lead: lock connection lost error="timeout: context deadline exceeded"5002026/10/05 11:18:53 INFO lead: released remote=192.0.2.1:12345012026/10/05 11:18:53 INFO lead: released remote=192.0.2.1:1234502--- PASS: TestLeadEndsWhenItsConnectionHangs (3.16s)503=== RUN TestGCAdvisoryLockBlocksConcurrentRun504=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun505=== RUN TestGCBugBareHashReferences506=== PAUSE TestGCBugBareHashReferences507=== RUN TestGCMetrics508=== PAUSE TestGCMetrics509=== RUN TestPushDedupSurvivesConcurrentGC510=== PAUSE TestPushDedupSurvivesConcurrentGC511=== RUN TestDeduplicatedObjectsRecordedAsPending512=== PAUSE TestDeduplicatedObjectsRecordedAsPending513=== RUN TestGCSweepSkipsPendingObjects514=== PAUSE TestGCSweepSkipsPendingObjects515=== RUN TestTombstonedObjectOfferedWithoutWaiting516=== PAUSE TestTombstonedObjectOfferedWithoutWaiting517=== RUN TestGCSweepDeliversEachKeyOnce518=== PAUSE TestGCSweepDeliversEachKeyOnce519=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection520=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== RUN TestForceGCDuringPushOffersSweptObject522=== PAUSE TestForceGCDuringPushOffersSweptObject523=== RUN TestFailedS3DeleteKeepsTombstone524=== PAUSE TestFailedS3DeleteKeepsTombstone525=== RUN TestSweepSkipsRowsLockedByPush526=== PAUSE TestSweepSkipsRowsLockedByPush527=== RUN TestRegisterCompletedObjectNeedsPendingRow528=== PAUSE TestRegisterCompletedObjectNeedsPendingRow529=== RUN TestGetExistingObjectsLocksRows530=== PAUSE TestGetExistingObjectsLocksRows531=== RUN TestSweepRechecksPendingAfterLocking532=== PAUSE TestSweepRechecksPendingAfterLocking533=== RUN TestPushWaitsForSweepHoldingRow534=== PAUSE TestPushWaitsForSweepHoldingRow535=== RUN TestCommitRacingPendingCleanupKeepsObjects536=== PAUSE TestCommitRacingPendingCleanupKeepsObjects537=== RUN TestGCEndsOnShutdown538=== PAUSE TestGCEndsOnShutdown539=== RUN TestGCTaskStore_StartNew540=== PAUSE TestGCTaskStore_StartNew541=== RUN TestGCTaskStore_DeduplicateSameParams542=== PAUSE TestGCTaskStore_DeduplicateSameParams543=== RUN TestGCTaskStore_ConflictDifferentParams544=== PAUSE TestGCTaskStore_ConflictDifferentParams545=== RUN TestGCTaskStore_GetEmpty546=== PAUSE TestGCTaskStore_GetEmpty547=== RUN TestGCTaskStore_GetReturnsLatest548=== PAUSE TestGCTaskStore_GetReturnsLatest549=== RUN TestGCTaskStore_CompletedAllowsNewTask550=== PAUSE TestGCTaskStore_CompletedAllowsNewTask551=== RUN TestGCTaskStore_PhaseUpdates552=== PAUSE TestGCTaskStore_PhaseUpdates553=== RUN TestGCTaskStore_Fail554=== PAUSE TestGCTaskStore_Fail555=== RUN TestGracefulShutdownDrainsInflight556=== PAUSE TestGracefulShutdownDrainsInflight557=== RUN TestService_healthCheckHandler558=== PAUSE TestService_healthCheckHandler559=== RUN TestService_readinessHandler560=== PAUSE TestService_readinessHandler561=== RUN TestGenerateLandingPage562=== PAUSE TestGenerateLandingPage563=== RUN TestCacheConfigHandlerMaxNarSize564=== PAUSE TestCacheConfigHandlerMaxNarSize565=== RUN TestCreatePendingClosureRejectsOversizedNAR566=== PAUSE TestCreatePendingClosureRejectsOversizedNAR567=== RUN TestNARDeduplicationMetadataUploadBug568=== PAUSE TestNARDeduplicationMetadataUploadBug569=== RUN TestMetricsInventory570=== PAUSE TestMetricsInventory571=== RUN TestService_NativeMTLS572=== PAUSE TestService_NativeMTLS573=== RUN TestServerTLSConfig574=== PAUSE TestServerTLSConfig575=== RUN TestMultipartCleanup576=== PAUSE TestMultipartCleanup577=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded578=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== RUN TestPendingCleanupUsesOneCutoff580=== PAUSE TestPendingCleanupUsesOneCutoff581=== RUN TestObjectStatsTrigger582=== PAUSE TestObjectStatsTrigger583=== RUN TestOrphanedObjectsGC584=== PAUSE TestOrphanedObjectsGC585=== RUN TestOrphanedObjectsGCStressTest586=== PAUSE TestOrphanedObjectsGCStressTest587=== RUN TestCreatePin_ReservedPins588=== PAUSE TestCreatePin_ReservedPins589=== RUN TestPresentReportsOnlyClosureRoots590=== PAUSE TestPresentReportsOnlyClosureRoots591=== RUN TestPresentNotReportedWhileGCDeletesClosure592=== PAUSE TestPresentNotReportedWhileGCDeletesClosure593=== RUN TestParseSingleRange594=== PAUSE TestParseSingleRange595=== RUN TestProxyHeadersOnlyTrustedOnSocket596=== PAUSE TestProxyHeadersOnlyTrustedOnSocket597=== RUN TestIsValidCachePath598=== PAUSE TestIsValidCachePath599=== RUN TestReadProxyNarinfo600=== PAUSE TestReadProxyNarinfo601=== RUN TestReadProxyNarinfoAlreadyDecompressed602=== PAUSE TestReadProxyNarinfoAlreadyDecompressed603=== RUN TestReadProxyNarStreaming604=== PAUSE TestReadProxyNarStreaming605=== RUN TestReadProxy404606=== PAUSE TestReadProxy404607=== RUN TestReadProxyInvalidPath608=== PAUSE TestReadProxyInvalidPath609=== RUN TestReadProxyHead610=== PAUSE TestReadProxyHead611=== RUN TestReadProxyOutlastsServerWriteTimeout612=== PAUSE TestReadProxyOutlastsServerWriteTimeout613=== RUN TestReadProxyConditionalGet614=== PAUSE TestReadProxyConditionalGet615=== RUN TestReadProxyRootRedirectsToIndexHTML616=== PAUSE TestReadProxyRootRedirectsToIndexHTML617=== RUN TestReadProxyDisabled618=== PAUSE TestReadProxyDisabled619=== RUN TestReadRedirectNar620=== PAUSE TestReadRedirectNar621=== RUN TestReadRedirectKeepsNarinfoProxied622=== PAUSE TestReadRedirectKeepsNarinfoProxied623=== RUN TestReadProxyRangeRequest624=== PAUSE TestReadProxyRangeRequest625=== RUN TestReadRedirectUsesPublicS3URL626=== PAUSE TestReadRedirectUsesPublicS3URL627=== RUN TestPush_OverlappingRootsStoreOneRowPerKey628=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey629=== RUN TestPush_CompleteCommitsEveryRoot630=== PAUSE TestPush_CompleteCommitsEveryRoot631=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit632=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit633=== RUN TestPush_RejectsBadRequests634=== PAUSE TestPush_RejectsBadRequests635=== RUN TestPush_SignsNarinfosOfItsPendingObjects636=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects637=== RUN TestRedundantMultipartUpload638=== PAUSE TestRedundantMultipartUpload639=== RUN TestCompleteMultipartUpload_ErrorButObjectExists640=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists641=== RUN TestCompletedNarNotReofferedAcrossClosures642=== PAUSE TestCompletedNarNotReofferedAcrossClosures643=== RUN TestPresignedUploadRegisteredBeforeCommit644=== PAUSE TestPresignedUploadRegisteredBeforeCommit645=== RUN TestService_Rustfstest646=== PAUSE TestService_Rustfstest647=== RUN TestParseSize648=== PAUSE TestParseSize649=== RUN TestSkippedUploadsHandler650=== PAUSE TestSkippedUploadsHandler651=== RUN TestSystemdListenerNotActivated652--- PASS: TestSystemdListenerNotActivated (0.00s)653=== RUN TestWatchdogBeatsWhenHealthy654--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)655=== RUN TestWatchdogSkipsWhenUnhealthy6562026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/05 11:18:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"666--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)667=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle668=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== RUN TestProxyWriteTimeout670=== PAUSE TestProxyWriteTimeout671=== RUN TestPendingClosureWriteTimeout672=== PAUSE TestPendingClosureWriteTimeout673=== RUN TestIsValidUploadKey674=== PAUSE TestIsValidUploadKey675=== RUN TestUploadHandlersRejectInvalidKeys676=== PAUSE TestUploadHandlersRejectInvalidKeys677=== RUN TestUploadHandlersRejectOversizedBody678=== PAUSE TestUploadHandlersRejectOversizedBody679=== RUN TestService_cleanupPendingClosuresHandler680=== PAUSE TestService_cleanupPendingClosuresHandler681=== RUN TestService_createPendingClosureHandler682=== PAUSE TestService_createPendingClosureHandler683=== RUN TestService_verifyS3Integrity684=== PAUSE TestService_verifyS3Integrity685=== RUN TestCompleteMultipartUnregistered686=== PAUSE TestCompleteMultipartUnregistered687=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT688=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT689=== CONT TestService_AuthMiddleware690=== CONT TestReadProxy404691=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestCompleteMultipartUnregistered693=== CONT TestService_verifyS3Integrity694=== CONT TestService_createPendingClosureHandler695=== CONT TestService_cleanupPendingClosuresHandler696=== CONT TestUploadHandlersRejectOversizedBody697=== CONT TestUploadHandlersRejectInvalidKeys698=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info699=== CONT TestIsValidUploadKey700=== CONT TestPendingClosureWriteTimeout701=== CONT TestProxyWriteTimeout702=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle703=== CONT TestSkippedUploadsHandler704=== CONT TestParseSize705=== CONT TestService_Rustfstest706=== CONT TestPresignedUploadRegisteredBeforeCommit707=== CONT TestCompletedNarNotReofferedAcrossClosures708=== CONT TestCompleteMultipartUpload_ErrorButObjectExists709=== CONT TestRedundantMultipartUpload710=== CONT TestPush_SignsNarinfosOfItsPendingObjects711=== CONT TestPush_RejectsBadRequests712=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit713=== CONT TestPush_CompleteCommitsEveryRoot714=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info715=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal716=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal717=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key718=== RUN TestIsValidUploadKey/narinfo719=== RUN TestPendingClosureWriteTimeout/empty7202026/10/05 11:18:53 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000721=== RUN TestProxyWriteTimeout/narinfo722--- PASS: TestParseSize (0.00s)723=== CONT TestPush_OverlappingRootsStoreOneRowPerKey724=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key725=== PAUSE TestPendingClosureWriteTimeout/empty726=== RUN TestPendingClosureWriteTimeout/400_objects727=== PAUSE TestIsValidUploadKey/narinfo728=== RUN TestIsValidUploadKey/nar_zst729=== PAUSE TestIsValidUploadKey/nar_zst730=== RUN TestIsValidUploadKey/nar_xz731=== PAUSE TestPendingClosureWriteTimeout/400_objects732=== PAUSE TestProxyWriteTimeout/narinfo733=== RUN TestPendingClosureWriteTimeout/670k_objects734=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key735=== PAUSE TestIsValidUploadKey/nar_xz736=== RUN TestIsValidUploadKey/nar_plain737=== RUN TestProxyWriteTimeout/1_GiB_nar738=== PAUSE TestProxyWriteTimeout/1_GiB_nar739=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key740=== PAUSE TestPendingClosureWriteTimeout/670k_objects741=== PAUSE TestIsValidUploadKey/nar_plain742=== RUN TestProxyWriteTimeout/10_GiB_nar743=== PAUSE TestProxyWriteTimeout/10_GiB_nar744=== RUN TestProxyWriteTimeout/unknown_size745=== PAUSE TestProxyWriteTimeout/unknown_size746=== CONT TestReadRedirectUsesPublicS3URL747=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline748=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline749=== RUN TestIsValidUploadKey/listing750=== PAUSE TestIsValidUploadKey/listing751=== RUN TestIsValidUploadKey/build_log752=== PAUSE TestIsValidUploadKey/build_log753=== RUN TestIsValidUploadKey/build_log_home-manager_file754=== PAUSE TestIsValidUploadKey/build_log_home-manager_file755=== RUN TestIsValidUploadKey/build_log_plus_in_name756=== PAUSE TestIsValidUploadKey/build_log_plus_in_name757=== CONT TestReadProxyRangeRequest758=== CONT TestReadRedirectKeepsNarinfoProxied759=== RUN TestIsValidUploadKey/build_log_question_mark760=== PAUSE TestIsValidUploadKey/build_log_question_mark761=== RUN TestIsValidUploadKey/build_log_equals762=== PAUSE TestIsValidUploadKey/build_log_equals763=== RUN TestIsValidUploadKey/realisation764=== PAUSE TestIsValidUploadKey/realisation765=== RUN TestIsValidUploadKey/realisation_plus_in_output766=== PAUSE TestIsValidUploadKey/realisation_plus_in_output767=== RUN TestIsValidUploadKey/nix-cache-info768=== PAUSE TestIsValidUploadKey/nix-cache-info769=== RUN TestIsValidUploadKey/index.html770=== PAUSE TestIsValidUploadKey/index.html771=== RUN TestIsValidUploadKey/narinfo_key,_nar_type772=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type773=== RUN TestIsValidUploadKey/nar_key,_narinfo_type774=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type775=== RUN TestIsValidUploadKey/listing_key,_narinfo_type776=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type777=== RUN TestIsValidUploadKey/traversal778=== PAUSE TestIsValidUploadKey/traversal779=== RUN TestIsValidUploadKey/traversal_nar780=== PAUSE TestIsValidUploadKey/traversal_nar781=== RUN TestIsValidUploadKey/absolute782=== PAUSE TestIsValidUploadKey/absolute783=== RUN TestIsValidUploadKey/empty_key784=== PAUSE TestIsValidUploadKey/empty_key785=== RUN TestIsValidUploadKey/unknown_type786=== PAUSE TestIsValidUploadKey/unknown_type787=== CONT TestReadRedirectNar788--- PASS: TestSkippedUploadsHandler (0.10s)789=== CONT TestReadProxyDisabled790=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure791=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure792=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart793=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart794=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts795=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts796=== CONT TestReadProxyRootRedirectsToIndexHTML7972026/10/05 11:18:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"798--- PASS: TestService_AuthMiddleware (0.66s)799=== CONT TestReadProxyConditionalGet8002026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8012026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8022026/10/05 11:18:54 INFO Received push request method=POST path=/api/pushes803--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.79s)804=== CONT TestReadProxyOutlastsServerWriteTimeout8052026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8062026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8072026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8082026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8092026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8102026/10/05 11:18:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8112026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures8122026/10/05 11:18:54 INFO Received uploads request method=POST path=/api/pending_closures813--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.89s)814=== CONT TestReadProxyHead8152026/10/05 11:18:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8162026/10/05 11:18:55 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst817--- PASS: TestCompleteMultipartUnregistered (1.22s)818=== CONT TestReadProxyInvalidPath8192026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures8202026/10/05 11:18:55 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8212026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures822--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.40s)823=== CONT TestSweepRechecksPendingAfterLocking824--- PASS: TestReadProxy404 (1.44s)825=== CONT TestReadProxyNarStreaming826--- PASS: TestReadRedirectKeepsNarinfoProxied (1.34s)827=== CONT TestReadProxyNarinfoAlreadyDecompressed828--- PASS: TestReadProxyRangeRequest (1.37s)829=== CONT TestReadProxyNarinfo830=== RUN TestPush_RejectsBadRequests/no_roots831=== PAUSE TestPush_RejectsBadRequests/no_roots832=== RUN TestPush_RejectsBadRequests/no_objects833=== PAUSE TestPush_RejectsBadRequests/no_objects834=== RUN TestPush_RejectsBadRequests/bad_root835=== PAUSE TestPush_RejectsBadRequests/bad_root836=== RUN TestPush_RejectsBadRequests/root_not_in_objects837=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects838=== CONT TestIsValidCachePath839=== RUN TestIsValidCachePath/narinfo840=== PAUSE TestIsValidCachePath/narinfo841=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars842=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars843=== RUN TestIsValidCachePath/nar_zst844=== PAUSE TestIsValidCachePath/nar_zst845=== RUN TestIsValidCachePath/nar_xz846=== PAUSE TestIsValidCachePath/nar_xz847=== RUN TestIsValidCachePath/nar_bz2848=== PAUSE TestIsValidCachePath/nar_bz2849=== RUN TestIsValidCachePath/nar_uncompressed850=== PAUSE TestIsValidCachePath/nar_uncompressed851=== RUN TestIsValidCachePath/ls852=== PAUSE TestIsValidCachePath/ls853=== RUN TestIsValidCachePath/log854=== PAUSE TestIsValidCachePath/log855=== RUN TestIsValidCachePath/realisation856=== PAUSE TestIsValidCachePath/realisation857=== RUN TestIsValidCachePath/nix-cache-info858=== PAUSE TestIsValidCachePath/nix-cache-info859=== RUN TestIsValidCachePath/index.html860=== PAUSE TestIsValidCachePath/index.html861=== RUN TestIsValidCachePath/traversal_parent862=== PAUSE TestIsValidCachePath/traversal_parent863=== RUN TestIsValidCachePath/traversal_in_middle864=== PAUSE TestIsValidCachePath/traversal_in_middle865=== RUN TestIsValidCachePath/invalid_char_e866=== PAUSE TestIsValidCachePath/invalid_char_e867=== RUN TestIsValidCachePath/invalid_char_u868=== PAUSE TestIsValidCachePath/invalid_char_u869=== RUN TestIsValidCachePath/random_path870=== PAUSE TestIsValidCachePath/random_path871=== RUN TestIsValidCachePath/empty872=== PAUSE TestIsValidCachePath/empty873=== RUN TestIsValidCachePath/leading_slash874=== PAUSE TestIsValidCachePath/leading_slash875=== RUN TestIsValidCachePath/wrong_extension876=== PAUSE TestIsValidCachePath/wrong_extension877=== RUN TestIsValidCachePath/short_hash878=== PAUSE TestIsValidCachePath/short_hash879=== CONT TestProxyHeadersOnlyTrustedOnSocket8802026/10/05 11:18:55 INFO Received push request method=POST path=/api/pushes8812026/10/05 11:18:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8822026/10/05 11:18:55 INFO Signed narinfos id=1 count=1883--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.44s)884=== CONT TestParseSingleRange885=== RUN TestParseSingleRange/none886=== PAUSE TestParseSingleRange/none887=== RUN TestParseSingleRange/unknown_unit888=== PAUSE TestParseSingleRange/unknown_unit889=== RUN TestParseSingleRange/multi-range_ignored890=== PAUSE TestParseSingleRange/multi-range_ignored891=== RUN TestParseSingleRange/malformed_no_dash892=== PAUSE TestParseSingleRange/malformed_no_dash893=== RUN TestParseSingleRange/malformed_both_empty894=== PAUSE TestParseSingleRange/malformed_both_empty895=== RUN TestParseSingleRange/malformed_end_before_start896=== PAUSE TestParseSingleRange/malformed_end_before_start897=== RUN TestParseSingleRange/closed898=== PAUSE TestParseSingleRange/closed899=== RUN TestParseSingleRange/open-ended900=== PAUSE TestParseSingleRange/open-ended901=== RUN TestParseSingleRange/end_clamped_to_size902=== PAUSE TestParseSingleRange/end_clamped_to_size903=== RUN TestParseSingleRange/suffix904=== PAUSE TestParseSingleRange/suffix905=== RUN TestParseSingleRange/suffix_exceeds_size906=== PAUSE TestParseSingleRange/suffix_exceeds_size907=== RUN TestParseSingleRange/single_byte908=== PAUSE TestParseSingleRange/single_byte909=== RUN TestParseSingleRange/start_past_EOF910=== PAUSE TestParseSingleRange/start_past_EOF911=== RUN TestParseSingleRange/start_far_past_EOF912=== PAUSE TestParseSingleRange/start_far_past_EOF913=== CONT TestPresentNotReportedWhileGCDeletesClosure9142026/10/05 11:18:55 INFO Received push request method=POST path=/api/pushes9152026/10/05 11:18:55 INFO Received complete push request method=POST path=/api/pushes/1/complete916--- PASS: TestPush_CompleteCommitsEveryRoot (1.49s)917=== CONT TestPresentReportsOnlyClosureRoots918--- PASS: TestReadRedirectNar (1.49s)919=== CONT TestCreatePin_ReservedPins9202026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures921--- PASS: TestService_Rustfstest (1.63s)922=== CONT TestOrphanedObjectsGCStressTest9232026/10/05 11:18:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9242026/10/05 11:18:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjRkNzM2ODk5LWQ0ODgtNGQ1ZC04NGI5LWY2NTdjZTE3MzZjMHgxNzkxMTk5MTM1NTIwOTg5NjA09252026/10/05 11:18:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjRkNzM2ODk5LWQ0ODgtNGQ1ZC04NGI5LWY2NTdjZTE3MzZjMHgxNzkxMTk5MTM1NTIwOTg5NjA0 parts=1926--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.57s)927=== CONT TestOrphanedObjectsGC9282026/10/05 11:18:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9292026/10/05 11:18:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38883/oidc930--- PASS: TestReadRedirectUsesPublicS3URL (1.59s)931=== CONT TestObjectStatsTrigger9322026/10/05 11:18:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9332026/10/05 11:18:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9342026/10/05 11:18:55 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LmE4YjlkNGE3LWMwYjAtNGI1YS05MmVkLTcwYTc5YTdjOTY2N3gxNzkxMTk5MTM0NzA1MTA2Njgy parts=109352026/10/05 11:18:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9362026/10/05 11:18:55 INFO Completed upload id=19372026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/05 11:18:55 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjQ3MmVhYTUzLWE1ZGUtNGVlOC04ZjUwLWFmMTA2NTdhYWU5NngxNzkxMTk5MTM0NzMyMTA5NTk0 parts=109402026/10/05 11:18:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9412026/10/05 11:18:55 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9422026/10/05 11:18:55 WARN Found objects in DB but missing from S3, will re-upload count=1943--- PASS: TestService_verifyS3Integrity (2.01s)944=== CONT TestPendingCleanupUsesOneCutoff9452026/10/05 11:18:55 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjZiODU3NjI4LTY2MDYtNGQ5Ni05M2NkLTIxYjFmMjRhNTBiNXgxNzkxMTk5MTM0NjE0ODUxMjEy parts=129462026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/05 11:18:55 INFO Received cleanup request method=DELETE path=/api/pending_closures9482026/10/05 11:18:55 INFO Completed upload id=19492026/10/05 11:18:55 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009502026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures9512026/10/05 11:18:55 INFO Aborted multipart uploads count=0 kept=09522026/10/05 11:18:55 INFO Received uploads request method=POST path=/api/pending_closures953--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.01s)954=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9552026/10/05 11:18:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures9562026/10/05 11:18:55 INFO Received cleanup request method=DELETE path=/api/pending_closures9572026/10/05 11:18:55 INFO Aborted multipart uploads count=0 kept=09582026/10/05 11:18:55 INFO Aborted multipart uploads count=1 kept=09592026/10/05 11:18:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9602026-10-05 11:18:55.936 UTC [673] ERROR: Closure does not exist: id=19612026-10-05 11:18:55.936 UTC [673] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9622026-10-05 11:18:55.936 UTC [673] STATEMENT: -- name: CommitPendingClosure :exec963 SELECT commit_pending_closure($1::bigint)964 965--- PASS: TestService_cleanupPendingClosuresHandler (2.04s)966=== CONT TestMultipartCleanup9672026/10/05 11:18:55 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=09682026/10/05 11:18:55 INFO Vacuumed table table=pending_closures9692026/10/05 11:18:55 INFO Received push request method=POST path=/api/pushes9702026/10/05 11:18:55 INFO Vacuumed table table=pending_objects9712026/10/05 11:18:55 INFO Vacuumed table table=multipart_uploads9722026/10/05 11:18:55 INFO Vacuumed table table=closures9732026/10/05 11:18:55 INFO Vacuumed table table=objects9742026/10/05 11:18:55 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000975--- PASS: TestService_createPendingClosureHandler (2.07s)976=== CONT TestServerTLSConfig977=== RUN TestServerTLSConfig/no_client_CA978=== PAUSE TestServerTLSConfig/no_client_CA979=== RUN TestServerTLSConfig/missing_CA_file980=== PAUSE TestServerTLSConfig/missing_CA_file981=== RUN TestServerTLSConfig/not_a_PEM_file982=== PAUSE TestServerTLSConfig/not_a_PEM_file983=== CONT TestService_NativeMTLS9842026/10/05 11:18:55 INFO Received complete push request method=POST path=/api/pushes/1/complete985--- PASS: TestReadProxyDisabled (1.98s)986=== CONT TestMetricsInventory9872026/10/05 11:18:55 INFO Received push request method=POST path=/api/pushes9882026/10/05 11:18:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete989--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.90s)990=== CONT TestNARDeduplicationMetadataUploadBug9912026/10/05 11:18:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjhiYjEyZjliLWFhY2EtNDExZi05YzRjLWQ1NDk0NWI2NzQwM3gxNzkxMTk5MTM0NzYwNjg1NzQ0 parts=129922026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/05 11:18:56 INFO Aborted multipart uploads count=0 kept=0994--- PASS: TestReadProxyConditionalGet (1.49s)995=== CONT TestCreatePendingClosureRejectsOversizedNAR9962026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures997--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)998=== CONT TestCacheConfigHandlerMaxNarSize999--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1000=== CONT TestGenerateLandingPage10012026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures1002--- PASS: TestGenerateLandingPage (0.00s)1003=== CONT TestService_readinessHandler10042026/10/05 11:18:56 WARN Force mode enabled - objects will be deleted immediately without grace period10052026/10/05 11:18:56 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=010062026/10/05 11:18:56 INFO Vacuumed table table=pending_closures10072026/10/05 11:18:56 INFO Vacuumed table table=pending_objects10082026/10/05 11:18:56 INFO Vacuumed table table=multipart_uploads10092026/10/05 11:18:56 INFO Vacuumed table table=closures10102026/10/05 11:18:56 INFO Vacuumed table table=objects10112026/10/05 11:18:56 INFO Received complete push request method=POST path=/api/pushes/2/complete1012--- PASS: TestReadProxyHead (1.32s)1013=== CONT TestService_healthCheckHandler1014--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.12s)1015=== CONT TestGracefulShutdownDrainsInflight10162026/10/05 11:18:56 INFO Starting HTTP server address=127.0.0.1:4035310172026/10/05 11:18:56 INFO Shutdown signal received, draining in-flight requests timeout=10s1018--- PASS: TestReadProxyInvalidPath (1.02s)1019=== CONT TestGCTaskStore_Fail1020--- PASS: TestGCTaskStore_Fail (0.00s)1021=== CONT TestGCTaskStore_PhaseUpdates1022--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1023=== CONT TestGCTaskStore_CompletedAllowsNewTask1024--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1025=== CONT TestGCTaskStore_GetReturnsLatest1026--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1027=== CONT TestGCTaskStore_GetEmpty1028--- PASS: TestGCTaskStore_GetEmpty (0.00s)1029=== CONT TestGCTaskStore_ConflictDifferentParams1030--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1031=== CONT TestGCTaskStore_DeduplicateSameParams1032--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1033=== CONT TestGCTaskStore_StartNew1034--- PASS: TestGCTaskStore_StartNew (0.00s)1035=== CONT TestPushWaitsForSweepHoldingRow1036--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1037=== CONT TestGCEndsOnShutdown1038=== RUN TestGCEndsOnShutdown/before_the_run1039=== PAUSE TestGCEndsOnShutdown/before_the_run1040=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1041=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1042=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1043=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1044=== CONT TestResolveDBConnectionString1045=== RUN TestResolveDBConnectionString/flag_wins1046=== PAUSE TestResolveDBConnectionString/flag_wins1047=== RUN TestResolveDBConnectionString/file_when_flag_empty1048=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1049=== RUN TestResolveDBConnectionString/missing_file_is_an_error1050=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1051=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1052=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1053=== RUN TestResolveDBConnectionString/nothing_configured1054=== PAUSE TestResolveDBConnectionString/nothing_configured1055=== CONT TestGetExistingObjectsLocksRows10562026/10/05 11:18:56 INFO Aborted multipart uploads count=0 kept=010572026/10/05 11:18:56 WARN Force mode enabled - objects will be deleted immediately without grace period1058--- PASS: TestReadProxyNarStreaming (0.87s)1059=== CONT TestRegisterCompletedObjectNeedsPendingRow10602026/10/05 11:18:56 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=010612026/10/05 11:18:56 INFO Vacuumed table table=pending_closures10622026/10/05 11:18:56 INFO Vacuumed table table=pending_objects10632026/10/05 11:18:56 INFO Vacuumed table table=multipart_uploads10642026/10/05 11:18:56 INFO Vacuumed table table=closures10652026/10/05 11:18:56 INFO Vacuumed table table=objects1066--- PASS: TestSweepRechecksPendingAfterLocking (0.92s)1067=== CONT TestSweepSkipsRowsLockedByPush1068--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.89s)1069=== CONT TestFailedS3DeleteKeepsTombstone10702026/10/05 11:18:56 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1259299778/001/proxy.sock10712026/10/05 11:18:56 INFO Starting HTTP server address=127.0.0.1:3852710722026/10/05 11:18:56 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10732026/10/05 11:18:56 INFO Shutdown signal received, draining in-flight requests timeout=10s1074--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.90s)1075=== CONT TestForceGCDuringPushOffersSweptObject1076=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1077=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1078=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1079=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1080=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10812026/10/05 11:18:56 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1082--- PASS: TestPresentReportsOnlyClosureRoots (1.04s)1083=== CONT TestGCSweepDeliversEachKeyOnce10842026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/05 11:18:56 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721610872026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures1088--- PASS: TestReadProxyNarinfo (1.24s)1089=== CONT TestTombstonedObjectOfferedWithoutWaiting10902026/10/05 11:18:56 INFO Received cleanup request method=DELETE path=/api/pending_closures10912026/10/05 11:18:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10922026/10/05 11:18:56 WARN Refused reserved pin name=worker-x86_64-linux10932026/10/05 11:18:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10942026/10/05 11:18:56 INFO Received create pin request method=POST path=/api/pins/my-app10952026/10/05 11:18:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1096--- PASS: TestCreatePin_ReservedPins (1.16s)1097=== CONT TestGCSweepSkipsPendingObjects1098--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.75s)1099=== CONT TestDeduplicatedObjectsRecordedAsPending1100--- PASS: TestObjectStatsTrigger (1.14s)1101=== CONT TestPushDedupSurvivesConcurrentGC11022026/10/05 11:18:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11032026/10/05 11:18:56 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/05 11:18:56 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LmI2ZjRjN2EyLTkwMTUtNDAzNi05YTllLTgzZDI4NTI1YzliOXgxNzkxMTk5MTM2MDU4NjkxODY3 error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11052026/10/05 11:18:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Yjg4NDIzMDMtZTBkNi00ZmU3LTg0ZDItYTMyMTc5OTg5M2Y4LjM2ZjE4YTc1LTM3M2UtNGZmZC05NzcwLTZkZTQxYTkzMWFhYngxNzkxMTk5MTM2MDQ3NTYwODkx parts=1211062026/10/05 11:18:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11072026/10/05 11:18:56 INFO Aborted multipart uploads count=1 kept=01108--- PASS: TestRedundantMultipartUpload (2.97s)1109=== CONT TestGCMetrics11102026/10/05 11:18:56 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11112026/10/05 11:18:56 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1112--- PASS: TestService_NativeMTLS (0.92s)1113=== CONT TestGCBugBareHashReferences1114--- PASS: TestMetricsInventory (0.96s)1115=== CONT TestGCAdvisoryLockBlocksConcurrentRun1116--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.52s)1117=== CONT TestLeadEndsOnShutdown11182026/10/05 11:18:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11192026/10/05 11:18:56 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket44/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11202026/10/05 11:18:56 INFO Aborted multipart uploads count=0 kept=111212026/10/05 11:18:56 INFO Received cleanup request method=DELETE path=/api/pending_closures11222026/10/05 11:18:56 INFO Aborted multipart uploads count=1 kept=011232026/10/05 11:18:57 WARN readiness check failed error="closed pool"1124--- PASS: TestService_readinessHandler (1.01s)1125=== CONT TestLeadIncumbentAnnouncesAtOnce1126--- PASS: TestMultipartCleanup (1.13s)1127=== CONT TestCommitRacingPendingCleanupKeepsObjects1128=== NAME TestNARDeduplicationMetadataUploadBug1129 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug44579295/001/store/jni96blxj2j096nkq4kk7dbxagr3l00d-file1.txt1130--- PASS: TestService_healthCheckHandler (1.02s)1131=== CONT TestLeadElectsOneAndHandsOver1132=== NAME TestOrphanedObjectsGC1133 orphaned_objects_gc_test.go:290: GC Test Summary:1134 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1135 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1136 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1137 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1138 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1139--- PASS: TestOrphanedObjectsGC (1.57s)1140=== CONT TestConnectWaitsForAPeerMigration11412026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/05 11:18:57 INFO Received push request method=POST path=/api/pushes11432026/10/05 11:18:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11442026/10/05 11:18:57 INFO Uploading jni96blxj2j096nkq4kk7dbxagr3l00d-file1.txt (160B)11452026/10/05 11:18:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11462026/10/05 11:18:57 WARN Failed to register uploaded object key=jni96blxj2j096nkq4kk7dbxagr3l00d.ls error="server returned 404: 404 page not found\n"11472026/10/05 11:18:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11482026/10/05 11:18:57 INFO Signed narinfos id=1 count=111492026/10/05 11:18:57 INFO Uploading 1 narinfos1150--- PASS: TestGetExistingObjectsLocksRows (1.03s)1151=== CONT TestClientErrorHandling1152=== RUN TestClientErrorHandling/InvalidStorePath1153=== PAUSE TestClientErrorHandling/InvalidStorePath1154=== RUN TestClientErrorHandling/InvalidAuthToken1155=== PAUSE TestClientErrorHandling/InvalidAuthToken1156=== RUN TestClientErrorHandling/ServerNotAvailable1157=== PAUSE TestClientErrorHandling/ServerNotAvailable1158=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11592026/10/05 11:18:57 INFO Received complete push request method=POST path=/api/pushes/1/complete11602026/10/05 11:18:57 WARN Failed to register uploaded object key=jni96blxj2j096nkq4kk7dbxagr3l00d.narinfo error="server returned 404: 404 page not found\n"1161--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.02s)1162=== CONT TestService_RequireScope_OIDC11632026/10/05 11:18:57 INFO Upload complete. (78ms)1164=== NAME TestNARDeduplicationMetadataUploadBug1165 metadata_upload_test.go:54: Retrieved narinfo from S3:1166 StorePath: /build/TestNARDeduplicationMetadataUploadBug44579295/001/store/jni96blxj2j096nkq4kk7dbxagr3l00d-file1.txt1167 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1168 Compression: zstd1169 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1170 NarSize: 1601171 References: 1172 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1173 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1174 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1175 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11762026/10/05 11:18:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35959/oidc11772026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures1178 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug44579295/001/store/lh7j7ss0npr4i8cir0f57yzb2rzv7g8a-file2.txt11792026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=011802026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period11822026/10/05 11:18:57 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=011832026/10/05 11:18:57 INFO Vacuumed table table=pending_closures11842026/10/05 11:18:57 INFO Vacuumed table table=pending_objects11852026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads11862026/10/05 11:18:57 INFO Vacuumed table table=closures11872026/10/05 11:18:57 INFO Vacuumed table table=objects11882026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=011892026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period11902026/10/05 11:18:57 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=011912026/10/05 11:18:57 INFO Vacuumed table table=pending_closures11922026/10/05 11:18:57 INFO Vacuumed table table=pending_objects11932026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads11942026/10/05 11:18:57 INFO Vacuumed table table=closures11952026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=011962026/10/05 11:18:57 INFO Vacuumed table table=objects1197--- PASS: TestSweepSkipsRowsLockedByPush (1.12s)1198=== CONT TestClientFallsBackToClosures11992026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period12002026/10/05 11:18:57 INFO Received push request method=POST path=/api/pushes12012026/10/05 11:18:57 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12022026/10/05 11:18:57 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12032026/10/05 11:18:57 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1204--- PASS: TestFailedS3DeleteKeepsTombstone (1.11s)1205=== CONT TestClientCADerivations12062026/10/05 11:18:57 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12072026/10/05 11:18:57 WARN Failed to register uploaded object key=lh7j7ss0npr4i8cir0f57yzb2rzv7g8a.ls error="server returned 404: 404 page not found\n"12082026/10/05 11:18:57 INFO Signed narinfos id=2 count=112092026/10/05 11:18:57 INFO Uploading 1 narinfos12102026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=012112026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period12122026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/05 11:18:57 INFO Received complete push request method=POST path=/api/pushes/2/complete12142026/10/05 11:18:57 WARN Failed to register uploaded object key=lh7j7ss0npr4i8cir0f57yzb2rzv7g8a.narinfo error="server returned 404: 404 page not found\n"12152026/10/05 11:18:57 INFO Upload complete. (56ms)1216=== NAME TestNARDeduplicationMetadataUploadBug1217 metadata_upload_test.go:76: Retrieved narinfo from S3:1218 StorePath: /build/TestNARDeduplicationMetadataUploadBug44579295/001/store/lh7j7ss0npr4i8cir0f57yzb2rzv7g8a-file2.txt1219 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1220 Compression: zstd1221 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1222 NarSize: 1601223 References: 1224 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1225 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1226 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1227 {"version":1,"root":{"type":"regular","size":44}}1228--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.77s)1229=== CONT TestClientPushesUseOnePush12302026/10/05 11:18:57 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=01231--- PASS: TestNARDeduplicationMetadataUploadBug (1.37s)1232=== CONT TestCacheStatsHandler12332026/10/05 11:18:57 INFO Vacuumed table table=pending_closures12342026/10/05 11:18:57 INFO Vacuumed table table=pending_objects12352026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads12362026/10/05 11:18:57 INFO Vacuumed table table=closures12372026/10/05 11:18:57 INFO Vacuumed table table=objects1238--- PASS: TestGCSweepDeliversEachKeyOnce (0.86s)1239=== CONT TestPinProtectsFromGC12402026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures1241--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.74s)1242=== CONT TestClientSharedPathCommittedMidPush12432026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=012452026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period12462026/10/05 11:18:57 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=01247--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.23s)1248=== CONT TestCacheConfigHandler1249=== RUN TestCacheConfigHandler/full_config,_no_issuer1250=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1251=== RUN TestCacheConfigHandler/no_cache_url_configured1252=== PAUSE TestCacheConfigHandler/no_cache_url_configured1253=== RUN TestCacheConfigHandler/no_signing_keys1254=== PAUSE TestCacheConfigHandler/no_signing_keys1255=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1256=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1257=== CONT TestClientWithDependencies12582026/10/05 11:18:57 INFO Vacuumed table table=pending_closures12592026/10/05 11:18:57 INFO Vacuumed table table=pending_objects12602026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads12612026/10/05 11:18:57 INFO Vacuumed table table=closures12622026/10/05 11:18:57 INFO Vacuumed table table=objects1263--- PASS: TestGCSweepSkipsPendingObjects (0.99s)1264=== CONT TestService_ReadScope_PublicByDefault12652026/10/05 11:18:57 INFO Received uploads request method=POST path=/api/pending_closures1266--- PASS: TestPushWaitsForSweepHoldingRow (1.54s)1267=== CONT TestClientMultipleUploads12682026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=012692026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period12702026/10/05 11:18:57 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=012712026/10/05 11:18:57 INFO Vacuumed table table=pending_closures12722026/10/05 11:18:57 INFO Vacuumed table table=pending_objects12732026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads12742026/10/05 11:18:57 INFO Vacuumed table table=closures12752026/10/05 11:18:57 INFO Vacuumed table table=objects1276--- PASS: TestGCMetrics (0.85s)1277=== CONT TestClientIntegration12782026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=012792026/10/05 11:18:57 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"1280--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.81s)1281=== CONT TestService_ReadAuthMiddleware12822026/10/05 11:18:57 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=012832026/10/05 11:18:57 INFO Vacuumed table table=pending_closures12842026/10/05 11:18:57 INFO Vacuumed table table=pending_objects12852026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads12862026/10/05 11:18:57 INFO Vacuumed table table=closures12872026/10/05 11:18:57 INFO lead: acquired remote=192.0.2.1:123412882026/10/05 11:18:57 INFO lead: released remote=192.0.2.1:12341289--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.69s)1290=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12912026/10/05 11:18:57 INFO Vacuumed table table=objects12922026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=012932026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period12942026/10/05 11:18:57 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=012952026/10/05 11:18:57 INFO Vacuumed table table=pending_closures12962026/10/05 11:18:57 INFO Vacuumed table table=pending_objects12972026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads12982026/10/05 11:18:57 INFO Vacuumed table table=closures12992026/10/05 11:18:57 INFO Vacuumed table table=objects1300--- PASS: TestPushDedupSurvivesConcurrentGC (1.05s)1301=== CONT TestService_AuthMiddleware_OIDC13022026/10/05 11:18:57 INFO lead: acquired remote=192.0.2.1:123413032026/10/05 11:18:57 INFO lead: acquired remote=192.0.2.1:123413042026/10/05 11:18:57 INFO Aborted multipart uploads count=0 kept=013052026/10/05 11:18:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39691/oidc13062026/10/05 11:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period13072026/10/05 11:18:57 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=013082026/10/05 11:18:57 INFO Vacuumed table table=pending_closures13092026/10/05 11:18:57 INFO Vacuumed table table=pending_objects13102026/10/05 11:18:57 INFO Vacuumed table table=multipart_uploads13112026/10/05 11:18:57 INFO Vacuumed table table=closures13122026/10/05 11:18:57 INFO Vacuumed table table=objects1313--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.88s)1314=== CONT TestService_AuthMiddleware_MTLSProxyHeader1315--- PASS: TestGCBugBareHashReferences (1.07s)1316=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info13172026/10/05 11:18:57 INFO Received uploads request method=POST path=/1318=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key13192026/10/05 11:18:57 INFO Received request for more parts method=POST path=/1320=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key13212026/10/05 11:18:57 INFO Received complete multipart upload request method=POST path=/1322=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal13232026/10/05 11:18:57 INFO Received uploads request method=POST path=/1324--- PASS: TestUploadHandlersRejectInvalidKeys (0.10s)1325 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1326 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1327 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1328 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1329=== CONT TestProxyWriteTimeout/narinfo1330=== CONT TestProxyWriteTimeout/10_GiB_nar1331=== CONT TestProxyWriteTimeout/1_GiB_nar1332=== CONT TestProxyWriteTimeout/unknown_size1333--- PASS: TestProxyWriteTimeout (0.10s)1334 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1335 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1336 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1337 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1338=== CONT TestPendingClosureWriteTimeout/empty1339=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1340=== RUN TestService_RequireScope_OIDC/builder_may_write1341=== PAUSE TestService_RequireScope_OIDC/builder_may_write1342=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1343=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1344=== RUN TestService_RequireScope_OIDC/ops_may_admin1345=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1346=== RUN TestService_RequireScope_OIDC/ops_may_not_write1347=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1348=== RUN TestService_RequireScope_OIDC/reader_may_not_write1349=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1350=== RUN TestService_RequireScope_OIDC/static_token_may_admin1351=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1352=== RUN TestService_RequireScope_OIDC/static_token_may_write1353=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1354=== RUN TestService_RequireScope_OIDC/reader_may_read1355=== PAUSE TestService_RequireScope_OIDC/reader_may_read1356=== RUN TestService_RequireScope_OIDC/writer_implies_read1357=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1358=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1359=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1360=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1361=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1362=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1363=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1364=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1365=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1366=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1367=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1368=== CONT TestPendingClosureWriteTimeout/670k_objects1369=== CONT TestPendingClosureWriteTimeout/400_objects1370=== CONT TestIsValidUploadKey/narinfo1371=== CONT TestIsValidUploadKey/realisation_plus_in_output1372=== CONT TestIsValidUploadKey/unknown_type1373=== CONT TestIsValidUploadKey/empty_key1374=== CONT TestIsValidUploadKey/absolute1375=== CONT TestIsValidUploadKey/traversal_nar1376=== CONT TestIsValidUploadKey/traversal1377=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1378=== CONT TestIsValidUploadKey/index.html1379=== CONT TestIsValidUploadKey/nix-cache-info1380=== CONT TestIsValidUploadKey/build_log_home-manager_file1381=== CONT TestIsValidUploadKey/realisation1382=== CONT TestIsValidUploadKey/build_log_equals1383=== CONT TestIsValidUploadKey/build_log_question_mark1384=== CONT TestIsValidUploadKey/build_log_plus_in_name1385=== CONT TestIsValidUploadKey/nar_plain1386=== CONT TestIsValidUploadKey/build_log1387=== CONT TestIsValidUploadKey/listing1388=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1389=== CONT TestIsValidUploadKey/nar_xz1390=== CONT TestIsValidUploadKey/nar_zst1391=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1392--- PASS: TestIsValidUploadKey (0.10s)1393 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1394 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1395 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1396 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1397 --- PASS: TestIsValidUploadKey/absolute (0.00s)1398 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1399 --- PASS: TestIsValidUploadKey/traversal (0.00s)1400 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1401 --- PASS: TestIsValidUploadKey/index.html (0.00s)1402 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1403 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1404 --- PASS: TestIsValidUploadKey/realisation (0.00s)1405 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1406 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1407 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1408 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1409 --- PASS: TestIsValidUploadKey/build_log (0.00s)1410 --- PASS: TestIsValidUploadKey/listing (0.00s)1411 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1412 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1413 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1414 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1415=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14162026/10/05 11:18:57 INFO Received uploads request method=POST path=/1417=== NAME TestClientCADerivations1418 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1640569013/001/store/1cvcamfi8nhbxl2ld32vsyw3y70nbgb7-ca-test1419--- PASS: TestCacheStatsHandler (0.74s)1420=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14212026/10/05 11:18:58 INFO Received request for more parts method=POST path=/1422=== NAME TestClientCADerivations1423 client_ca_test.go:139: Found 1 dependencies (including self)1424=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart14252026/10/05 11:18:58 INFO Received complete multipart upload request method=POST path=/1426--- PASS: TestService_ReadScope_PublicByDefault (0.55s)1427=== CONT TestPush_RejectsBadRequests/no_roots14282026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1429=== CONT TestPush_RejectsBadRequests/root_not_in_objects14302026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1431=== CONT TestPush_RejectsBadRequests/bad_root14322026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1433=== CONT TestPush_RejectsBadRequests/no_objects14342026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1435=== CONT TestIsValidCachePath/narinfo1436=== CONT TestIsValidCachePath/index.html1437=== CONT TestIsValidCachePath/nix-cache-info1438=== CONT TestIsValidCachePath/realisation1439=== CONT TestIsValidCachePath/log1440=== CONT TestIsValidCachePath/ls1441--- PASS: TestPush_RejectsBadRequests (1.39s)1442 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1443 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1444 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1445 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1446=== CONT TestIsValidCachePath/nar_uncompressed1447=== CONT TestIsValidCachePath/nar_bz21448=== CONT TestIsValidCachePath/nar_xz1449=== CONT TestIsValidCachePath/nar_zst1450=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1451=== CONT TestIsValidCachePath/empty1452=== CONT TestIsValidCachePath/traversal_parent1453=== CONT TestIsValidCachePath/random_path1454=== CONT TestIsValidCachePath/invalid_char_u1455=== CONT TestIsValidCachePath/invalid_char_e1456=== CONT TestIsValidCachePath/wrong_extension1457=== CONT TestIsValidCachePath/short_hash1458=== CONT TestIsValidCachePath/leading_slash1459=== CONT TestIsValidCachePath/traversal_in_middle1460--- PASS: TestIsValidCachePath (0.00s)1461 --- PASS: TestIsValidCachePath/narinfo (0.00s)1462 --- PASS: TestIsValidCachePath/index.html (0.00s)1463 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1464 --- PASS: TestIsValidCachePath/realisation (0.00s)1465 --- PASS: TestIsValidCachePath/log (0.00s)1466 --- PASS: TestIsValidCachePath/ls (0.00s)1467 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1468 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1469 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1470 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1471 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1472 --- PASS: TestIsValidCachePath/empty (0.00s)1473 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1474 --- PASS: TestIsValidCachePath/random_path (0.00s)1475 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1476 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1477 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1478 --- PASS: TestIsValidCachePath/short_hash (0.00s)1479 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1480 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1481=== CONT TestParseSingleRange/none1482=== CONT TestParseSingleRange/open-ended1483=== CONT TestParseSingleRange/start_far_past_EOF1484=== CONT TestParseSingleRange/start_past_EOF1485=== CONT TestParseSingleRange/single_byte1486=== CONT TestParseSingleRange/suffix_exceeds_size1487=== CONT TestParseSingleRange/suffix1488=== CONT TestParseSingleRange/malformed_both_empty1489=== CONT TestParseSingleRange/end_clamped_to_size1490=== CONT TestParseSingleRange/closed1491=== CONT TestParseSingleRange/malformed_end_before_start1492=== CONT TestParseSingleRange/multi-range_ignored1493=== CONT TestParseSingleRange/malformed_no_dash1494=== CONT TestParseSingleRange/unknown_unit1495--- PASS: TestParseSingleRange (0.00s)1496 --- PASS: TestParseSingleRange/none (0.00s)1497 --- PASS: TestParseSingleRange/open-ended (0.00s)1498 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1499 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1500 --- PASS: TestParseSingleRange/single_byte (0.00s)1501 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1502 --- PASS: TestParseSingleRange/suffix (0.00s)1503 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1504 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1505 --- PASS: TestParseSingleRange/closed (0.00s)1506 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1507 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1508 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1509 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1510=== CONT TestServerTLSConfig/no_client_CA1511=== CONT TestServerTLSConfig/not_a_PEM_file1512=== CONT TestServerTLSConfig/missing_CA_file1513--- PASS: TestServerTLSConfig (0.00s)1514 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1515 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1516 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1517=== CONT TestGCEndsOnShutdown/before_the_run15182026/10/05 11:18:58 INFO Received uploads request method=POST path=/api/pending_closures15192026/10/05 11:18:58 INFO Received uploads request method=POST path=/api/pending_closures15202026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes15212026/10/05 11:18:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15222026/10/05 11:18:58 INFO Uploading jwmiqp71g7rm3m91357r0794lqiyzqqz-a (216B)15232026/10/05 11:18:58 INFO Uploading 13mxxaw7g7r4ca0vs3n3mz9p66rywxrr-shared-dep (136B)1524=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15252026/10/05 11:18:58 WARN Failed to register uploaded object key=6q6bhmw2vdhg8sn970fa7sg0n0jlh0gw.ls error="server returned 404: 404 page not found\n"15262026/10/05 11:18:58 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15272026/10/05 11:18:58 INFO Uploading i2nlhxq8v6rcl539gcspfyzq5qwwdav0-shared-dep (136B)15282026/10/05 11:18:58 INFO Uploading zdzs9z021x5ify6lzzy1d52l2xq1qngl-top (224B)15292026/10/05 11:18:58 WARN Failed to register uploaded object key=jwmiqp71g7rm3m91357r0794lqiyzqqz.ls error="server returned 404: 404 page not found\n"15302026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/19mx47z9kw4wkvs3fhqwsjwxgr0f5cjmqf22iq5lajdfz6sgc5kl.nar.zst error="server returned 404: 404 page not found\n"1531=== NAME TestPinProtectsFromGC15322026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1533 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1441789154/001/store/d1b159fxpz6wfjba87xchpwqs4rjpgv2-pinned-file.txt15342026/10/05 11:18:58 WARN Failed to register uploaded object key=13mxxaw7g7r4ca0vs3n3mz9p66rywxrr.ls error="server returned 404: 404 page not found\n"1535 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1441789154/001/store/81398fa3zp7j2bkbrinflcnjf3vjda2l-unpinned-file.txt15362026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15372026/10/05 11:18:58 INFO Signed narinfos id=1 count=215382026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15392026/10/05 11:18:58 INFO Signed narinfos id=2 count=215402026/10/05 11:18:58 INFO Uploading 4 narinfos15412026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15422026/10/05 11:18:58 WARN Failed to register uploaded object key=i2nlhxq8v6rcl539gcspfyzq5qwwdav0.ls error="server returned 404: 404 page not found\n"15432026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1pp90qrf3gh0qp8j2w38bcrdy3lgkfnhbvycmsms402bjwy9d77a.nar.zst error="server returned 404: 404 page not found\n"15442026/10/05 11:18:58 WARN Failed to register uploaded object key=zdzs9z021x5ify6lzzy1d52l2xq1qngl.ls error="server returned 404: 404 page not found\n"15452026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15462026/10/05 11:18:58 INFO Signed narinfos id=1 count=215472026/10/05 11:18:58 INFO Uploading 2 narinfos15482026/10/05 11:18:58 WARN Failed to register uploaded object key=6q6bhmw2vdhg8sn970fa7sg0n0jlh0gw.narinfo error="server returned 404: 404 page not found\n"15492026/10/05 11:18:58 WARN Failed to register uploaded object key=jwmiqp71g7rm3m91357r0794lqiyzqqz.narinfo error="server returned 404: 404 page not found\n"1550--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.01s)1551=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15522026/10/05 11:18:58 WARN Failed to register uploaded object key=13mxxaw7g7r4ca0vs3n3mz9p66rywxrr.narinfo error="server returned 404: 404 page not found\n"15532026/10/05 11:18:58 WARN Failed to register uploaded object key=zdzs9z021x5ify6lzzy1d52l2xq1qngl.narinfo error="server returned 404: 404 page not found\n"15542026/10/05 11:18:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15552026/10/05 11:18:58 WARN Failed to register uploaded object key=13mxxaw7g7r4ca0vs3n3mz9p66rywxrr.narinfo error="server returned 404: 404 page not found\n"15562026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete15572026/10/05 11:18:58 WARN Failed to register uploaded object key=i2nlhxq8v6rcl539gcspfyzq5qwwdav0.narinfo error="server returned 404: 404 page not found\n"15582026/10/05 11:18:58 INFO Completed upload id=115592026/10/05 11:18:58 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15602026/10/05 11:18:58 INFO Completed upload id=215612026/10/05 11:18:58 INFO Upload complete. (80ms)15622026/10/05 11:18:58 INFO Upload complete. (73ms)1563=== NAME TestClientFallsBackToClosures1564 client_pushes_test.go:112: Retrieved narinfo from S3:1565 StorePath: /build/TestClientFallsBackToClosures2770038320/001/store/13mxxaw7g7r4ca0vs3n3mz9p66rywxrr-shared-dep1566 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1567 Compression: zstd1568 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821569 NarSize: 1361570 References: 1571 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1572=== NAME TestClientSharedPathCommittedMidPush1573 client_integration_test.go:680: Retrieved narinfo from S3:1574 StorePath: /build/TestClientSharedPathCommittedMidPush2516171137/001/store/i2nlhxq8v6rcl539gcspfyzq5qwwdav0-shared-dep1575 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1576 Compression: zstd1577 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821578 NarSize: 1361579 References: 1580 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1581=== NAME TestClientWithDependencies1582 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies647001121/001/store/l2ww6jsxyfbd2000i6z88jn4628d3y6n-test-script1583=== NAME TestClientFallsBackToClosures1584 client_pushes_test.go:112: Retrieved narinfo from S3:1585 StorePath: /build/TestClientFallsBackToClosures2770038320/001/store/jwmiqp71g7rm3m91357r0794lqiyzqqz-a1586 URL: nar/19mx47z9kw4wkvs3fhqwsjwxgr0f5cjmqf22iq5lajdfz6sgc5kl.nar.zst1587 Compression: zstd1588 NarHash: sha256:19mx47z9kw4wkvs3fhqwsjwxgr0f5cjmqf22iq5lajdfz6sgc5kl1589 NarSize: 2161590 References: /build/TestClientFallsBackToClosures2770038320/001/store/13mxxaw7g7r4ca0vs3n3mz9p66rywxrr-shared-dep1591 CA: text:sha256:1h9xvdwiv4p92vqkr6nfjmhk4dxx7fbgwfa9ag2mwi85xv8fg4pp1592=== NAME TestClientSharedPathCommittedMidPush1593 client_integration_test.go:680: Retrieved narinfo from S3:1594 StorePath: /build/TestClientSharedPathCommittedMidPush2516171137/001/store/zdzs9z021x5ify6lzzy1d52l2xq1qngl-top1595 URL: nar/1pp90qrf3gh0qp8j2w38bcrdy3lgkfnhbvycmsms402bjwy9d77a.nar.zst1596 Compression: zstd1597 NarHash: sha256:1pp90qrf3gh0qp8j2w38bcrdy3lgkfnhbvycmsms402bjwy9d77a1598 NarSize: 2241599 References: /build/TestClientSharedPathCommittedMidPush2516171137/001/store/i2nlhxq8v6rcl539gcspfyzq5qwwdav0-shared-dep1600 CA: text:sha256:10snk46h9pgpv40v9n0q12znmc901fnszm85yg271izh8qysyja91601=== NAME TestClientFallsBackToClosures1602 client_pushes_test.go:112: Retrieved narinfo from S3:1603 StorePath: /build/TestClientFallsBackToClosures2770038320/001/store/6q6bhmw2vdhg8sn970fa7sg0n0jlh0gw-b1604 URL: nar/19mx47z9kw4wkvs3fhqwsjwxgr0f5cjmqf22iq5lajdfz6sgc5kl.nar.zst1605 Compression: zstd1606 NarHash: sha256:19mx47z9kw4wkvs3fhqwsjwxgr0f5cjmqf22iq5lajdfz6sgc5kl1607 NarSize: 2161608 References: /build/TestClientFallsBackToClosures2770038320/001/store/13mxxaw7g7r4ca0vs3n3mz9p66rywxrr-shared-dep1609 CA: text:sha256:1h9xvdwiv4p92vqkr6nfjmhk4dxx7fbgwfa9ag2mwi85xv8fg4pp1610=== NAME TestClientMultipleUploads1611 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads793472943/001/store/wp5xwi950qszlycj393gvnkkni04wwwd-test-file-0.txt1612--- PASS: TestClientSharedPathCommittedMidPush (0.85s)1613=== CONT TestResolveDBConnectionString/flag_wins1614=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1615=== CONT TestResolveDBConnectionString/nothing_configured1616=== CONT TestResolveDBConnectionString/missing_file_is_an_error1617--- PASS: TestClientFallsBackToClosures (0.91s)1618=== CONT TestResolveDBConnectionString/file_when_flag_empty1619=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1620=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1621--- PASS: TestResolveDBConnectionString (0.00s)1622 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1623 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1624 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1625 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1626 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)16272026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1628--- PASS: TestService_ReadAuthMiddleware (0.52s)1629=== CONT TestClientErrorHandling/InvalidStorePath16302026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes16312026/10/05 11:18:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16322026/10/05 11:18:58 INFO Uploading 1cvcamfi8nhbxl2ld32vsyw3y70nbgb7-ca-test (144B)16332026/10/05 11:18:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16342026/10/05 11:18:58 INFO Uploading gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd-shared-dep (136B)16352026/10/05 11:18:58 INFO Uploading v6rc2kkp5d0yslpyzg5b78j88khnnq59-b (216B)16362026/10/05 11:18:58 WARN Failed to register uploaded object key=log/i19azf54w96wk48xzqdvqbnfsh8cpg7d-ca-test.drv error="server returned 404: 404 page not found\n"16372026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16382026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1639=== NAME TestClientWithDependencies16402026/10/05 11:18:58 WARN Failed to register uploaded object key=1cvcamfi8nhbxl2ld32vsyw3y70nbgb7.ls error="server returned 404: 404 page not found\n"1641 client_integration_test.go:615: Found 1 dependencies (including self)16422026/10/05 11:18:58 INFO Signed narinfos id=1 count=116432026/10/05 11:18:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16442026/10/05 11:18:58 WARN mTLS auth: bound subjects configured but subject DN unavailable16452026/10/05 11:18:58 INFO Uploading 1 narinfos16462026/10/05 11:18:58 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1647--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.52s)1648=== CONT TestClientErrorHandling/ServerNotAvailable1649=== NAME TestClientIntegration16502026/10/05 11:18:58 WARN Failed to register uploaded object key=2l4j49692aq11wfqr4kgy6dj1c7xrnbf.ls error="server returned 404: 404 page not found\n"1651 client_integration_test.go:286: Created store path: /build/TestClientIntegration2235727455/002/store/qw7l9xqqky4xpdbq4qqmss4yx7nqaswj-test-file.txt16522026/10/05 11:18:58 WARN Failed to register uploaded object key=gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd.ls error="server returned 404: 404 page not found\n"16532026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16542026/10/05 11:18:58 WARN Failed to register uploaded object key=v6rc2kkp5d0yslpyzg5b78j88khnnq59.ls error="server returned 404: 404 page not found\n"16552026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16562026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete16572026/10/05 11:18:58 WARN Failed to register uploaded object key=1cvcamfi8nhbxl2ld32vsyw3y70nbgb7.narinfo error="server returned 404: 404 page not found\n"16582026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1f2rvckdvl3ppm7xjbp06xzjrc8dz2l664h1nb2ycjs9ir2qx80h.nar.zst error="server returned 404: 404 page not found\n"16592026/10/05 11:18:58 INFO Signed narinfos id=1 count=316602026/10/05 11:18:58 INFO Uploading 3 narinfos16612026/10/05 11:18:58 WARN Failed to register uploaded object key=v6rc2kkp5d0yslpyzg5b78j88khnnq59.narinfo error="server returned 404: 404 page not found\n"16622026/10/05 11:18:58 WARN Failed to register uploaded object key=2l4j49692aq11wfqr4kgy6dj1c7xrnbf.narinfo error="server returned 404: 404 page not found\n"1663=== NAME TestClientMultipleUploads16642026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete1665 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads793472943/001/store/9mf0z38nb8b4vlicp2dlkl6vhg7d41xq-test-file-1.txt16662026/10/05 11:18:58 WARN Failed to register uploaded object key=gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd.narinfo error="server returned 404: 404 page not found\n"16672026/10/05 11:18:58 INFO Upload complete. (108ms)16682026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes1669=== NAME TestClientCADerivations1670 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1640569013/001/store/1cvcamfi8nhbxl2ld32vsyw3y70nbgb7-ca-test1671 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1672 Compression: zstd1673 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1674 NarSize: 1441675 References: 1676 Deriver: /build/TestClientCADerivations1640569013/001/store/i19azf54w96wk48xzqdvqbnfsh8cpg7d-ca-test.drv1677 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1678 client_ca_test.go:185: Checking for realisation files in S3...1679 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1680 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16812026/10/05 11:18:58 INFO Upload complete. (75ms)1682=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1683=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token16842026/10/05 11:18:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1685=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16862026/10/05 11:18:58 INFO Uploading d1b159fxpz6wfjba87xchpwqs4rjpgv2-pinned-file.txt (128B)1687=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1688=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1689=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1690=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1691=== NAME TestClientPushesUseOnePush1692 client_pushes_test.go:97: Retrieved narinfo from S3:1693 StorePath: /build/TestClientPushesUseOnePush3257065800/001/store/gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd-shared-dep1694 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1695 Compression: zstd1696 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821697 NarSize: 1361698 References: 1699 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1700=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1701=== CONT TestClientErrorHandling/InvalidAuthToken1702=== NAME TestClientPushesUseOnePush1703 client_pushes_test.go:97: Retrieved narinfo from S3:1704 StorePath: /build/TestClientPushesUseOnePush3257065800/001/store/2l4j49692aq11wfqr4kgy6dj1c7xrnbf-a1705 URL: nar/1f2rvckdvl3ppm7xjbp06xzjrc8dz2l664h1nb2ycjs9ir2qx80h.nar.zst1706 Compression: zstd1707 NarHash: sha256:1f2rvckdvl3ppm7xjbp06xzjrc8dz2l664h1nb2ycjs9ir2qx80h1708 NarSize: 2161709 References: /build/TestClientPushesUseOnePush3257065800/001/store/gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd-shared-dep1710 CA: text:sha256:1mrpgz809rml7jwfyd04j1fa3mkfmk4q1jadpvdjk3s86dsxpfyh17112026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17122026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17132026/10/05 11:18:58 WARN Failed to register uploaded object key=d1b159fxpz6wfjba87xchpwqs4rjpgv2.ls error="server returned 404: 404 page not found\n"17142026/10/05 11:18:58 INFO Signed narinfos id=1 count=117152026/10/05 11:18:58 INFO Uploading 1 narinfos1716 client_pushes_test.go:97: Retrieved narinfo from S3:1717 StorePath: /build/TestClientPushesUseOnePush3257065800/001/store/v6rc2kkp5d0yslpyzg5b78j88khnnq59-b1718 URL: nar/1f2rvckdvl3ppm7xjbp06xzjrc8dz2l664h1nb2ycjs9ir2qx80h.nar.zst1719 Compression: zstd1720 NarHash: sha256:1f2rvckdvl3ppm7xjbp06xzjrc8dz2l664h1nb2ycjs9ir2qx80h1721 NarSize: 2161722 References: /build/TestClientPushesUseOnePush3257065800/001/store/gb0v6sx9v7f76mz8lscwzs8c1wlz0ljd-shared-dep1723 CA: text:sha256:1mrpgz809rml7jwfyd04j1fa3mkfmk4q1jadpvdjk3s86dsxpfyh17242026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete17252026/10/05 11:18:58 WARN Failed to register uploaded object key=d1b159fxpz6wfjba87xchpwqs4rjpgv2.narinfo error="server returned 404: 404 page not found\n"1726--- PASS: TestClientPushesUseOnePush (0.94s)1727=== CONT TestCacheConfigHandler/full_config,_no_issuer1728=== CONT TestCacheConfigHandler/no_signing_keys1729=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1730=== CONT TestCacheConfigHandler/no_cache_url_configured1731--- PASS: TestCacheConfigHandler (0.00s)1732 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1733 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1734 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1735 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1736=== CONT TestService_RequireScope_OIDC/builder_may_write1737=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1738=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1739=== CONT TestService_RequireScope_OIDC/writer_implies_read1740=== CONT TestService_RequireScope_OIDC/reader_may_read1741=== CONT TestService_RequireScope_OIDC/static_token_may_write1742=== CONT TestService_RequireScope_OIDC/static_token_may_admin1743=== CONT TestService_RequireScope_OIDC/reader_may_not_write1744=== CONT TestService_RequireScope_OIDC/ops_may_not_write1745=== CONT TestService_RequireScope_OIDC/ops_may_admin1746=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1747=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1748=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1749=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read17502026/10/05 11:18:58 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]1751=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1752--- PASS: TestService_RequireScope_OIDC (0.76s)1753 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1754 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1755 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1756 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1757 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1758 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1759 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1760 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1761 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1762 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1763 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1764 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1765 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1766 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1767=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected17682026/10/05 11:18:58 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]1769=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1770=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17712026/10/05 11:18:58 INFO Upload complete. (69ms)17722026/10/05 11:18:58 WARN Authentication failed token_preview=eyJhbGciOi...KuhzlFN_8g token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1773--- PASS: TestService_AuthMiddleware_OIDC (0.52s)1774 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1775 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1776 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1777 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1778--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.38s)1779=== NAME TestClientMultipleUploads1780 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads793472943/001/store/vixywnig4rcqicmhzp5p3hmxcbi7zyw8-test-file-2.txt17812026/10/05 11:18:58 INFO Received uploads request method=POST path=/api/pending_closures17822026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes17832026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes17842026/10/05 11:18:58 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17852026/10/05 11:18:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17862026/10/05 11:18:58 INFO Uploading qw7l9xqqky4xpdbq4qqmss4yx7nqaswj-test-file.txt (152B)17872026/10/05 11:18:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17882026/10/05 11:18:58 INFO Uploading l2ww6jsxyfbd2000i6z88jn4628d3y6n-test-script (136B)17892026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17902026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17912026/10/05 11:18:58 WARN Failed to register uploaded object key=qw7l9xqqky4xpdbq4qqmss4yx7nqaswj.ls error="server returned 404: 404 page not found\n"17922026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17932026/10/05 11:18:58 WARN Failed to register uploaded object key=l2ww6jsxyfbd2000i6z88jn4628d3y6n.ls error="server returned 404: 404 page not found\n"17942026/10/05 11:18:58 INFO Signed narinfos id=1 count=117952026/10/05 11:18:58 INFO Uploading 1 narinfos17962026/10/05 11:18:58 WARN Failed to register uploaded object key=log/603zhypd27hwpr4zacxqhn02gxh0lld3-test-script.drv error="server returned 404: 404 page not found\n"17972026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17982026/10/05 11:18:58 INFO Signed narinfos id=1 count=117992026/10/05 11:18:58 INFO Uploading 1 narinfos18002026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete18012026/10/05 11:18:58 WARN Failed to register uploaded object key=qw7l9xqqky4xpdbq4qqmss4yx7nqaswj.narinfo error="server returned 404: 404 page not found\n"18022026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete18032026/10/05 11:18:58 WARN Failed to register uploaded object key=l2ww6jsxyfbd2000i6z88jn4628d3y6n.narinfo error="server returned 404: 404 page not found\n"18042026/10/05 11:18:58 INFO Upload complete. (59ms)18052026/10/05 11:18:58 INFO Upload complete. (59ms)1806=== NAME TestClientWithDependencies1807 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies647001121/001/store) requires matching store prefix1808--- PASS: TestClientWithDependencies (0.85s)18092026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes18102026/10/05 11:18:58 INFO Received push request method=POST path=/api/pushes18112026/10/05 11:18:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18122026/10/05 11:18:58 INFO Uploading 81398fa3zp7j2bkbrinflcnjf3vjda2l-unpinned-file.txt (128B)18132026/10/05 11:18:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18142026/10/05 11:18:58 INFO Uploading vixywnig4rcqicmhzp5p3hmxcbi7zyw8-test-file-2.txt (160B)18152026/10/05 11:18:58 INFO Uploading wp5xwi950qszlycj393gvnkkni04wwwd-test-file-0.txt (160B)18162026/10/05 11:18:58 INFO Uploading 9mf0z38nb8b4vlicp2dlkl6vhg7d41xq-test-file-1.txt (160B)18172026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18182026/10/05 11:18:58 WARN Failed to register uploaded object key=81398fa3zp7j2bkbrinflcnjf3vjda2l.ls error="server returned 404: 404 page not found\n"18192026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18202026/10/05 11:18:58 INFO Signed narinfos id=2 count=118212026/10/05 11:18:58 WARN Failed to register uploaded object key=9mf0z38nb8b4vlicp2dlkl6vhg7d41xq.ls error="server returned 404: 404 page not found\n"18222026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18232026/10/05 11:18:58 INFO Uploading 1 narinfos18242026/10/05 11:18:58 WARN Failed to register uploaded object key=vixywnig4rcqicmhzp5p3hmxcbi7zyw8.ls error="server returned 404: 404 page not found\n"18252026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18262026/10/05 11:18:58 WARN Failed to register uploaded object key=wp5xwi950qszlycj393gvnkkni04wwwd.ls error="server returned 404: 404 page not found\n"18272026/10/05 11:18:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18282026/10/05 11:18:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18292026/10/05 11:18:58 INFO Signed narinfos id=1 count=318302026/10/05 11:18:58 INFO All 1 paths already cached18312026/10/05 11:18:58 INFO Uploading 3 narinfos1832=== NAME TestClientIntegration1833 client_integration_test.go:312: Retrieved narinfo from S3:1834 StorePath: /build/TestClientIntegration2235727455/002/store/qw7l9xqqky4xpdbq4qqmss4yx7nqaswj-test-file.txt1835 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1836 Compression: zstd1837 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11838 NarSize: 1521839 References: 1840 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118412026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/2/complete18422026/10/05 11:18:58 WARN Failed to register uploaded object key=81398fa3zp7j2bkbrinflcnjf3vjda2l.narinfo error="server returned 404: 404 page not found\n"18432026/10/05 11:18:58 WARN Failed to register uploaded object key=vixywnig4rcqicmhzp5p3hmxcbi7zyw8.narinfo error="server returned 404: 404 page not found\n"18442026/10/05 11:18:58 WARN Failed to register uploaded object key=9mf0z38nb8b4vlicp2dlkl6vhg7d41xq.narinfo error="server returned 404: 404 page not found\n"18452026/10/05 11:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete1846 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)18472026/10/05 11:18:58 WARN Failed to register uploaded object key=wp5xwi950qszlycj393gvnkkni04wwwd.narinfo error="server returned 404: 404 page not found\n"1848 client_integration_test.go:313: Decompressed .ls content (64 bytes):18492026/10/05 11:18:58 INFO Upload complete. (59ms)1850 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1851 client_integration_test.go:316: Testing garbage collection...18522026/10/05 11:18:58 INFO Upload complete. (58ms)1853=== NAME TestClientMultipleUploads1854 client_integration_test.go:369: Uploaded 3 paths in 90.328679ms18552026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=018562026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period1857=== NAME TestClientCADerivations1858 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1859 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1860 error: binary cache 's3://bucket71?endpoint=http://localhost:44439®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1640569013/001/store'1861 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11862--- PASS: TestClientMultipleUploads (0.75s)1863--- PASS: TestClientCADerivations (1.08s)18642026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=018652026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period18662026/10/05 11:18:58 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44439/bucket87/?delete=\": context canceled"1867--- PASS: TestGCEndsOnShutdown (0.00s)1868 --- PASS: TestGCEndsOnShutdown/before_the_run (0.19s)1869 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.22s)1870 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)18712026/10/05 11:18:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures18722026/10/05 11:18:58 INFO Garbage collection started18732026/10/05 11:18:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures18742026/10/05 11:18:58 INFO Garbage collection started18752026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=018762026/10/05 11:18:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.081688ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18772026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period18782026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=018792026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period18802026/10/05 11:18:58 INFO Received uploads request method=POST path=/api/pending_closures18812026/10/05 11:18:58 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=018822026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=018832026/10/05 11:18:58 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=018842026/10/05 11:18:58 INFO Vacuumed table table=pending_closures18852026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period18862026/10/05 11:18:58 INFO Vacuumed table table=pending_closures18872026/10/05 11:18:58 INFO Vacuumed table table=pending_objects18882026/10/05 11:18:58 INFO Vacuumed table table=multipart_uploads18892026/10/05 11:18:58 INFO Vacuumed table table=pending_objects18902026/10/05 11:18:58 INFO Vacuumed table table=multipart_uploads18912026/10/05 11:18:58 INFO Vacuumed table table=closures18922026/10/05 11:18:58 INFO Vacuumed table table=closures18932026/10/05 11:18:58 INFO Vacuumed table table=objects18942026/10/05 11:18:58 INFO Vacuumed table table=objects18952026/10/05 11:18:58 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=018962026/10/05 11:18:58 INFO Vacuumed table table=pending_closures18972026/10/05 11:18:58 INFO Vacuumed table table=pending_objects18982026/10/05 11:18:58 INFO Vacuumed table table=multipart_uploads18992026/10/05 11:18:58 INFO Vacuumed table table=closures19002026/10/05 11:18:58 INFO Vacuumed table table=objects19012026/10/05 11:18:58 INFO Received uploads request method=POST path=/api/pending_closures19022026/10/05 11:18:58 INFO Aborted multipart uploads count=0 kept=019032026/10/05 11:18:58 WARN Force mode enabled - objects will be deleted immediately without grace period19042026/10/05 11:18:58 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=019052026/10/05 11:18:58 INFO Vacuumed table table=pending_closures19062026/10/05 11:18:58 INFO Vacuumed table table=pending_objects19072026/10/05 11:18:58 INFO Vacuumed table table=multipart_uploads19082026/10/05 11:18:58 INFO Vacuumed table table=closures19092026/10/05 11:18:58 INFO Vacuumed table table=objects1910=== NAME TestOrphanedObjectsGCStressTest1911 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1912--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1913 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.25s)1914 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)1915=== NAME TestOrphanedObjectsGCStressTest1916 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19172026/10/05 11:18:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19182026/10/05 11:18:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"1919--- PASS: TestUploadHandlersRejectOversizedBody (0.21s)1920 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)1921 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1922 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)19232026/10/05 11:18:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.871619ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19242026/10/05 11:18:58 INFO lead: released remote=192.0.2.1:12341925--- PASS: TestLeadEndsOnShutdown (1.91s)19262026/10/05 11:18:58 WARN Rate limiter enabled after throttle name=s3-test rate=519272026/10/05 11:18:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1928=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1929 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101930 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001931--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.03s)1932=== NAME TestOrphanedObjectsGCStressTest1933 orphaned_objects_gc_test.go:509: Stress test completed successfully:1934 orphaned_objects_gc_test.go:510: - Active objects preserved: 201935 orphaned_objects_gc_test.go:511: - Objects deleted: 2101936 orphaned_objects_gc_test.go:512: - Total GC'd: 2101937--- PASS: TestOrphanedObjectsGCStressTest (3.41s)19382026/10/05 11:18:59 INFO lead: released remote=192.0.2.1:12341939--- PASS: TestPendingClosureWriteTimeout (0.10s)1940 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1941 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1942 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1943 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.19s)19442026/10/05 11:18:59 INFO lead: acquired remote=192.0.2.1:123419452026/10/05 11:18:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=797.858459ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19462026/10/05 11:19:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.738407831s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19472026/10/05 11:19:00 INFO lead: released remote=192.0.2.1:12341948--- PASS: TestLeadElectsOneAndHandsOver (3.14s)1949--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.59s)19502026/10/05 11:19:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019512026/10/05 11:19:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01952=== NAME TestClientIntegration1953 client_integration_test.go:323: Objects in database after GC:1954 client_integration_test.go:323: Successfully deleted all objects with GC --force1955--- PASS: TestClientIntegration (2.73s)19562026/10/05 11:19:00 INFO Received create pin request method=POST path=/api/pins/myapp19572026/10/05 11:19:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1441789154/001/store/d1b159fxpz6wfjba87xchpwqs4rjpgv2-pinned-file.txt narinfo_key=d1b159fxpz6wfjba87xchpwqs4rjpgv2.narinfo19582026/10/05 11:19:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures19592026/10/05 11:19:00 INFO Garbage collection started19602026/10/05 11:19:00 INFO Aborted multipart uploads count=0 kept=019612026/10/05 11:19:00 WARN Force mode enabled - objects will be deleted immediately without grace period19622026/10/05 11:19:00 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=019632026/10/05 11:19:00 INFO Vacuumed table table=pending_closures19642026/10/05 11:19:00 INFO Vacuumed table table=pending_objects19652026/10/05 11:19:00 INFO Vacuumed table table=multipart_uploads19662026/10/05 11:19:00 INFO Vacuumed table table=closures19672026/10/05 11:19:00 INFO Vacuumed table table=objects19682026/10/05 11:19:01 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19692026/10/05 11:19:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.117014ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19702026/10/05 11:19:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.654608ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1971--- PASS: TestConnectWaitsForAPeerMigration (5.27s)1972=== NAME TestPinProtectsFromGC1973 client_integration_test.go:840: Pin successfully protected closure from garbage collection1974--- PASS: TestPinProtectsFromGC (5.10s)19752026/10/05 11:19:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.567124ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19762026/10/05 11:19:02 INFO Aborted multipart uploads count=1 kept=019772026/10/05 11:19:02 INFO Received cleanup request method=DELETE path=/api/pending_closures19782026/10/05 11:19:02 INFO Aborted multipart uploads count=1 kept=01979--- PASS: TestPendingCleanupUsesOneCutoff (6.73s)19802026/10/05 11:19:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.516914674s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19812026/10/05 11:19:04 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"19822026/10/05 11:19:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19832026/10/05 11:19:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.333344ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19842026/10/05 11:19:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.424274ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19852026/10/05 11:19:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=877.525238ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19862026/10/05 11:19:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.593353509s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19872026/10/05 11:19:08 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19882026/10/05 11:19:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=208.400438ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19892026/10/05 11:19:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.782454ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19902026/10/05 11:19:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=853.16181ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19912026/10/05 11:19:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.515773786s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1992--- PASS: TestClientErrorHandling (0.00s)1993 --- PASS: TestClientErrorHandling/InvalidStorePath (0.22s)1994 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.53s)1995 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.82s)1996PASS1997{"timestamp":"2026-10-05T11:19:11.104906598Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53486","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(396)"}19982026-10-05 11:19:11.490 UTC [129] LOG: received smart shutdown request19992026-10-05 11:19:11.494 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120002026-10-05 11:19:11.505 UTC [134] LOG: shutting down20012026-10-05 11:19:11.506 UTC [134] LOG: checkpoint starting: shutdown immediate20022026-10-05 11:19:13.295 UTC [134] LOG: checkpoint complete: wrote 11054 buffers (67.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.345 s, sync=1.394 s, total=1.790 s; sync files=31000, longest=0.009 s, average=0.001 s; distance=428533 kB, estimate=428533 kB; lsn=0/1B9E30F8, redo lsn=0/1B9E30F820032026-10-05 11:19:13.387 UTC [129] LOG: database system is shut down2004Running OIDC tests...2005=== RUN TestAudienceForIssuer2006=== PAUSE TestAudienceForIssuer2007=== RUN TestGlobMatch2008=== PAUSE TestGlobMatch2009=== RUN TestValidateToken_ValidToken2010=== PAUSE TestValidateToken_ValidToken2011=== RUN TestValidateToken_WrongAudience2012=== PAUSE TestValidateToken_WrongAudience2013=== RUN TestValidateToken_Expired2014=== PAUSE TestValidateToken_Expired2015=== RUN TestValidateToken_BoundClaimsMismatch2016=== PAUSE TestValidateToken_BoundClaimsMismatch2017=== RUN TestValidateToken_BoundSubjectMismatch2018=== PAUSE TestValidateToken_BoundSubjectMismatch2019=== RUN TestValidateToken_MultipleProviders2020=== PAUSE TestValidateToken_MultipleProviders2021=== RUN TestValidateToken_NoMatchingProvider2022=== PAUSE TestValidateToken_NoMatchingProvider2023=== RUN TestValidateToken_KubernetesServiceAccount2024=== PAUSE TestValidateToken_KubernetesServiceAccount2025=== RUN TestNewValidator_KubernetesRequiresCA2026=== PAUSE TestNewValidator_KubernetesRequiresCA2027=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2028=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2029=== RUN TestPins_ReservedForMatchingRule2030=== PAUSE TestPins_ReservedForMatchingRule2031=== RUN TestPins_TopLevelShorthand2032=== PAUSE TestPins_TopLevelShorthand2033=== RUN TestPins_ConfigValidation2034=== PAUSE TestPins_ConfigValidation2035=== RUN TestScopes_LegacyProviderDefaultsToWrite2036=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2037=== RUN TestScopes_Rules2038=== PAUSE TestScopes_Rules2039=== RUN TestScopes_ConfigValidation2040=== PAUSE TestScopes_ConfigValidation2041=== CONT TestAudienceForIssuer2042=== CONT TestValidateToken_KubernetesServiceAccount2043=== CONT TestPins_ConfigValidation2044=== CONT TestValidateToken_BoundClaimsMismatch2045=== CONT TestValidateToken_NoMatchingProvider2046=== CONT TestValidateToken_MultipleProviders2047=== CONT TestValidateToken_BoundSubjectMismatch2048=== CONT TestValidateToken_Expired2049--- PASS: TestAudienceForIssuer (0.00s)2050=== CONT TestPins_ReservedForMatchingRule2051--- PASS: TestPins_ConfigValidation (0.00s)2052=== CONT TestValidateToken_ValidToken2053=== CONT TestGlobMatch2054=== CONT TestPins_TopLevelShorthand2055=== CONT TestScopes_Rules2056=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2057=== CONT TestScopes_ConfigValidation2058--- PASS: TestScopes_ConfigValidation (0.00s)2059=== CONT TestNewValidator_KubernetesRequiresCA2060=== CONT TestScopes_LegacyProviderDefaultsToWrite2061=== CONT TestValidateToken_WrongAudience2062=== RUN TestGlobMatch/foo_foo2063=== PAUSE TestGlobMatch/foo_foo2064=== RUN TestGlobMatch/foo_bar2065=== PAUSE TestGlobMatch/foo_bar2066=== RUN TestGlobMatch/*_2067=== PAUSE TestGlobMatch/*_2068=== RUN TestGlobMatch/*_anything2069=== PAUSE TestGlobMatch/*_anything2070=== RUN TestGlobMatch/foo*_foo2071=== PAUSE TestGlobMatch/foo*_foo2072=== RUN TestGlobMatch/foo*_foobar2073=== PAUSE TestGlobMatch/foo*_foobar2074=== RUN TestGlobMatch/foo*_bar2075=== PAUSE TestGlobMatch/foo*_bar2076=== RUN TestGlobMatch/*bar_bar2077=== PAUSE TestGlobMatch/*bar_bar2078=== RUN TestGlobMatch/*bar_foobar2079=== PAUSE TestGlobMatch/*bar_foobar2080=== RUN TestGlobMatch/*bar_foo2081=== PAUSE TestGlobMatch/*bar_foo2082=== RUN TestGlobMatch/foo*bar_foobar2083=== PAUSE TestGlobMatch/foo*bar_foobar2084=== RUN TestGlobMatch/foo*bar_foo123bar2085=== PAUSE TestGlobMatch/foo*bar_foo123bar2086=== RUN TestGlobMatch/foo*bar_foobarbaz2087=== PAUSE TestGlobMatch/foo*bar_foobarbaz2088=== RUN TestGlobMatch/*/*_foo/bar2089=== PAUSE TestGlobMatch/*/*_foo/bar2090=== RUN TestGlobMatch/*/*_foo2091=== PAUSE TestGlobMatch/*/*_foo2092=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2093=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2094=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02095=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02096=== RUN TestGlobMatch/refs/*/main_refs/heads/main2097=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2098=== RUN TestGlobMatch/fo?_foo2099=== PAUSE TestGlobMatch/fo?_foo2100=== RUN TestGlobMatch/fo?_fo2101=== PAUSE TestGlobMatch/fo?_fo2102=== RUN TestGlobMatch/fo?_fooo2103=== PAUSE TestGlobMatch/fo?_fooo2104=== RUN TestGlobMatch/?oo_foo2105=== PAUSE TestGlobMatch/?oo_foo2106=== RUN TestGlobMatch/?oo_boo2107=== PAUSE TestGlobMatch/?oo_boo2108=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2109=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2110=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2111=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2112=== CONT TestGlobMatch/foo_foo2113=== CONT TestGlobMatch/fo?_foo2114=== CONT TestGlobMatch/refs/*/main_refs/heads/main2115=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02116=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2117=== CONT TestGlobMatch/*/*_foo2118=== CONT TestGlobMatch/*/*_foo/bar2119=== CONT TestGlobMatch/fo?_fo2120=== CONT TestGlobMatch/*_anything2121=== CONT TestGlobMatch/*_2122=== CONT TestGlobMatch/foo_bar2123=== CONT TestGlobMatch/foo*bar_foobarbaz2124=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2125=== CONT TestGlobMatch/foo*bar_foo123bar2126=== CONT TestGlobMatch/foo*bar_foobar2127=== CONT TestGlobMatch/*bar_foo2128=== CONT TestGlobMatch/*bar_foobar2129=== CONT TestGlobMatch/*bar_bar2130=== CONT TestGlobMatch/foo*_bar2131=== CONT TestGlobMatch/foo*_foobar2132=== CONT TestGlobMatch/foo*_foo2133=== CONT TestGlobMatch/?oo_boo2134=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2135=== CONT TestGlobMatch/?oo_foo2136=== CONT TestGlobMatch/fo?_fooo2137--- PASS: TestGlobMatch (0.01s)2138 --- PASS: TestGlobMatch/foo_foo (0.00s)2139 --- PASS: TestGlobMatch/fo?_foo (0.00s)2140 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2141 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2142 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2143 --- PASS: TestGlobMatch/*/*_foo (0.00s)2144 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2145 --- PASS: TestGlobMatch/fo?_fo (0.00s)2146 --- PASS: TestGlobMatch/*_anything (0.00s)2147 --- PASS: TestGlobMatch/*_ (0.00s)2148 --- PASS: TestGlobMatch/foo_bar (0.00s)2149 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2150 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2151 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2152 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2153 --- PASS: TestGlobMatch/*bar_foo (0.00s)2154 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2155 --- PASS: TestGlobMatch/*bar_bar (0.00s)2156 --- PASS: TestGlobMatch/foo*_bar (0.00s)2157 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2158 --- PASS: TestGlobMatch/foo*_foo (0.00s)2159 --- PASS: TestGlobMatch/?oo_boo (0.00s)2160 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2161 --- PASS: TestGlobMatch/?oo_foo (0.00s)2162 --- PASS: TestGlobMatch/fo?_fooo (0.00s)21632026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45885/oidc2164--- PASS: TestValidateToken_Expired (0.02s)21652026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45921/oidc21662026/10/05 11:19:15 http: TLS handshake error from 127.0.0.1:49952: remote error: tls: bad certificate2167--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)2168--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)21692026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39623/oidc2170--- PASS: TestPins_ReservedForMatchingRule (0.06s)21712026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46273/oidc2172--- PASS: TestValidateToken_WrongAudience (0.06s)21732026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41523/oidc21742026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40767/oidc2175--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2176--- PASS: TestPins_TopLevelShorthand (0.07s)21772026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46137/oidc2178--- PASS: TestValidateToken_ValidToken (0.07s)21792026/10/05 11:19:15 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:386632180--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)21812026/10/05 11:19:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232182--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)21832026/10/05 11:19:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42545/oidc21842026/10/05 11:19:15 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34625/oidc2185--- PASS: TestValidateToken_MultipleProviders (0.14s)21862026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35389/oidc21872026/10/05 11:19:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40233/oidc2188--- PASS: TestValidateToken_BoundClaimsMismatch (0.18s)2189--- PASS: TestValidateToken_NoMatchingProvider (0.18s)21902026/10/05 11:19:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43559/oidc2191--- PASS: TestScopes_Rules (0.20s)2192PASS2193Running hook tests...2194=== RUN TestSendPathsEmpty2195=== PAUSE TestSendPathsEmpty2196=== RUN TestQueueEnqueueAndFetch2197=== PAUSE TestQueueEnqueueAndFetch2198=== RUN TestQueueDeduplication2199=== PAUSE TestQueueDeduplication2200=== RUN TestQueueRemove2201=== PAUSE TestQueueRemove2202=== RUN TestQueueFetchBatchLimit2203=== PAUSE TestQueueFetchBatchLimit2204=== RUN TestQueueRetryMovesToBack2205=== PAUSE TestQueueRetryMovesToBack2206=== RUN TestQueueFetchRemoveLifecycle2207=== PAUSE TestQueueFetchRemoveLifecycle2208=== RUN TestQueueConcurrentWriters2209=== PAUSE TestQueueConcurrentWriters2210=== RUN TestQueueRemoveLargeClosure2211=== PAUSE TestQueueRemoveLargeClosure2212=== RUN TestServerClientIntegration2213=== PAUSE TestServerClientIntegration2214=== RUN TestServerQueueError2215=== PAUSE TestServerQueueError2216=== RUN TestGetListenerSocketActivation2217 server_test.go:210: === RUN TestGetListenerSocketActivation2218 --- PASS: TestGetListenerSocketActivation (0.00s)2219 PASS2220 2221--- PASS: TestGetListenerSocketActivation (0.01s)2222=== RUN TestDrainIsolatesPoisonPath2223=== PAUSE TestDrainIsolatesPoisonPath2224=== RUN TestRunNotBlockedByPoisonHead2225=== PAUSE TestRunNotBlockedByPoisonHead2226=== RUN TestDrainGivesUpWhenServerDown2227=== PAUSE TestDrainGivesUpWhenServerDown2228=== RUN TestFailedPathPrunedByLaterClosure2229=== PAUSE TestFailedPathPrunedByLaterClosure2230=== RUN TestWorkerUploadsAndRemoves2231=== PAUSE TestWorkerUploadsAndRemoves2232=== RUN TestWorkerSkipsGCdPaths2233=== PAUSE TestWorkerSkipsGCdPaths2234=== RUN TestWorkerPrunesClosureDeps2235=== PAUSE TestWorkerPrunesClosureDeps2236=== RUN TestDrainTimeout2237=== PAUSE TestDrainTimeout2238=== CONT TestSendPathsEmpty2239=== CONT TestServerQueueError2240--- PASS: TestSendPathsEmpty (0.00s)2241=== CONT TestQueueFetchBatchLimit2242=== CONT TestQueueRemove2243=== CONT TestQueueRetryMovesToBack2244=== CONT TestQueueDeduplication2245=== CONT TestWorkerUploadsAndRemoves2246=== CONT TestDrainTimeout2247=== CONT TestServerClientIntegration22482026/10/05 11:19:15 ERROR Failed to queue paths error="permission denied" count=12249=== CONT TestWorkerPrunesClosureDeps2250=== CONT TestQueueRemoveLargeClosure2251--- PASS: TestServerQueueError (0.00s)2252=== CONT TestQueueConcurrentWriters2253=== CONT TestWorkerSkipsGCdPaths2254=== CONT TestDrainGivesUpWhenServerDown2255=== CONT TestQueueFetchRemoveLifecycle2256=== CONT TestFailedPathPrunedByLaterClosure2257=== CONT TestDrainIsolatesPoisonPath2258=== CONT TestRunNotBlockedByPoisonHead2259=== CONT TestQueueEnqueueAndFetch2260--- PASS: TestServerClientIntegration (0.00s)22612026/10/05 11:19:15 INFO Uploading batch count=122622026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=122632026/10/05 11:19:15 INFO Upload queue status pending=222642026/10/05 11:19:15 INFO Uploading batch count=122652026/10/05 11:19:15 INFO Uploading batch count=222662026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=222672026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/a2268--- PASS: TestQueueRetryMovesToBack (0.15s)22692026/10/05 11:19:15 INFO Upload queue status pending=322702026/10/05 11:19:15 INFO Upload queue status pending=222712026/10/05 11:19:15 INFO Uploading batch count=422722026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=422732026/10/05 11:19:15 INFO Uploading batch count=122742026/10/05 11:19:15 INFO Upload queue status pending=222752026/10/05 11:19:15 INFO Uploading batch count=122762026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=122772026/10/05 11:19:15 INFO Uploading batch count=22278--- PASS: TestQueueFetchRemoveLifecycle (0.15s)22792026/10/05 11:19:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3088706542/002/nonexistent22802026/10/05 11:19:15 INFO Uploading batch count=22281--- PASS: TestQueueEnqueueAndFetch (0.15s)22822026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/b2283--- PASS: TestQueueRemove (0.15s)22842026/10/05 11:19:15 INFO Uploading batch count=12285--- PASS: TestQueueFetchBatchLimit (0.15s)22862026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath859877143/002/bbb22872026/10/05 11:19:15 INFO Uploading batch count=122882026/10/05 11:19:15 INFO Uploading batch count=222892026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=22290--- PASS: TestQueueDeduplication (0.15s)22912026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/c22922026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/d22932026/10/05 11:19:15 INFO Uploading batch count=222942026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=222952026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/e2296--- PASS: TestFailedPathPrunedByLaterClosure (0.15s)22972026/10/05 11:19:15 INFO Uploading batch count=122982026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=122992026/10/05 11:19:15 INFO Uploading batch count=123002026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=123012026/10/05 11:19:15 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1594815513/002/f23022026/10/05 11:19:15 INFO Uploading batch count=123032026/10/05 11:19:15 ERROR Upload failed error="upload failed" count=123042026/10/05 11:19:15 ERROR Drain finished with paths left in queue remaining=123052026/10/05 11:19:15 ERROR Drain finished with paths left in queue remaining=102306--- PASS: TestDrainIsolatesPoisonPath (0.16s)2307--- PASS: TestDrainGivesUpWhenServerDown (0.16s)2308--- PASS: TestWorkerPrunesClosureDeps (0.16s)2309--- PASS: TestWorkerSkipsGCdPaths (0.17s)2310--- PASS: TestWorkerUploadsAndRemoves (0.17s)2311--- PASS: TestQueueRemoveLargeClosure (0.26s)23122026/10/05 11:19:15 ERROR Upload failed error="context deadline exceeded" count=223132026/10/05 11:19:15 ERROR Drain finished with paths left in queue remaining=42314--- PASS: TestDrainTimeout (0.35s)2315--- PASS: TestQueueConcurrentWriters (0.61s)23162026/10/05 11:19:16 INFO Uploading batch count=123172026/10/05 11:19:16 INFO Uploading batch count=123182026/10/05 11:19:16 INFO Uploading batch count=123192026/10/05 11:19:16 ERROR Upload failed error="upload failed" count=123202026/10/05 11:19:16 INFO Uploading batch count=123212026/10/05 11:19:16 ERROR Upload failed error="upload failed" count=123222026/10/05 11:19:16 INFO Uploading batch count=123232026/10/05 11:19:16 ERROR Upload failed error="upload failed" count=123242026/10/05 11:19:16 INFO Uploading batch count=123252026/10/05 11:19:16 ERROR Upload failed error="upload failed" count=123262026/10/05 11:19:16 ERROR Drain finished with paths left in queue remaining=12327--- PASS: TestRunNotBlockedByPoisonHead (1.17s)2328PASS