AsperforMias commented on issue #3615:
URL: https://github.com/apache/dubbo-go/issues/3615#issuecomment-5226228151
## Reproduced on v3.3.2 — deterministic docker repro + a second recovery
blocker (closing tombstone)
I reproduced this issue deterministically on `v3.3.2` (docker compose: Nacos
2.5.1 + single Triple provider + consumer, application-level discovery,
**local** metadata storage). The reproduction confirms the root cause described
above, and surfaced a **second, stacked recovery blocker** that the proposed
fix should take into account: the graceful-shutdown **closing tombstone** in
`RegistryDirectory`.
### Deterministic repro (no timing race)
The trick is to apply the network block **before** restarting the provider
and hold it until the metadata failure is logged — so the "transient
MetadataService failure" is guaranteed, not probabilistic:
1. Start Nacos; start the provider (app `demo-provider`, tri `:20001`);
start the consumer (app `demo-consumer`, calls `SayHello` every 2s and logs
`CALL #n OK/FAIL`). Wait until calls succeed (baseline).
2. `docker compose stop provider` (SIGTERM → graceful shutdown). Wait until
the consumer logs `received instance notification event, service=demo-provider
size=0` and calls start failing.
3. In the consumer container: `iptables -A OUTPUT -d <provider-ip> -j DROP`.
4. `docker compose start provider` — a new `timestamp` guarantees a **new
revision**.
5. Wait until the consumer logs `failed to get metadata from instance ...
skipping this instance` (guaranteed: the metadata RPC to the blocked address
times out), then sleep 3s.
6. `iptables -D OUTPUT -d <provider-ip> -j DROP` — from here on, Nacos and
the provider (incl. MetadataService) are fully healthy.
7. Observe 60s: **consumer keeps failing `No provider available`**. Then
`docker compose restart consumer` → calls succeed immediately.
Full runnable package (provider/consumer/compose/script) at the bottom of
this comment.
### Observed timeline (consumer log, v3.3.2)
```text
11:38:33 INFO received instance notification event, service=demo-provider
size=1 # baseline, metadata RPC ok
11:38:36 INFO received instance notification event, service=demo-provider
size=0 # provider stopped
# iptables DROP consumer -> provider
11:38:40 INFO received instance notification event, service=demo-provider
size=1 # provider restarted, new revision
11:38:46 WARN failed to get metadata from instance 172.30.0.11 (revision
fc54e9e8...),
err=...: can not connect to remote metadata service host:
172.30.0.11, skipping this instance
# iptables unblock — provider/nacos fully healthy
11:38:51 INFO [Dubbo] refer service,
url=dubbo://172.30.0.11:43537/org.apache.dubbo.metadata.MetadataService... #
a later push DID re-fetch metadata successfully
11:38:51 INFO [Registry][Directory] skip rebuilding closing instance due
to tombstone, instance key: ... # <-- second blocker
11:38:52 INFO [Registry][Directory] skip rebuilding closing instance due
to tombstone
11:38:52→11:39:10 CALL #22..#29 FAIL: No provider available ... (provider
healthy)
# docker compose restart consumer
11:39:33 CALL #1..#14 OK
# restart recovers
```
### Second recovery blocker: closing tombstone
`docker stop` (SIGTERM) triggers the provider's graceful shutdown, which
makes the consumer's `RegistryDirectory` mark a **closing tombstone** for the
instance key (`registry/directory/directory.go` `markClosingTombstone`, default
TTL 30s via `ClosingInvokerExpireTime`). In this run a later Nacos push arrived
**after** the network was restored and the metadata re-fetch **succeeded** —
but `doCacheInvoker` vetoed the invoker rebuild:
https://github.com/apache/dubbo-go/blob/v3.3.2/registry/directory/directory.go#L683-L687
```go
if dir.hasActiveClosingTombstone(key) {
logger.Infof("[Registry][Directory] skip rebuilding closing instance due
to tombstone, instance key: %s", key)
return nil, true
}
```
After the 30s TTL expired, no further instance event arrived, so the
consumer stayed empty until restart. In other words, the "no retry source" gap
is what makes it permanent, and the tombstone is what vetoed the one
spontaneous recovery chance.
### Control experiment (SIGKILL instead of graceful stop)
Same steps, but `docker kill` (SIGKILL) the provider in step 2 → no closing
event → **no tombstone**. The blocked first metadata fetch fails identically,
but the next Nacos push after unblocking re-fetches metadata and rebuilds the
invoker — **the consumer self-heals ~3s after the network is restored**:
```text
11:47:19 WARN failed to get metadata from instance ... skipping this
instance # blocked
11:47:24 INFO [Registry][Directory] selector add service
url{tri://172.30.0.11:20001/...} # rebuilt, no tombstone
11:47:25 CALL #237 OK
# self-recovered
```
So the permanent failure needs both: (a) no metadata retry (this issue's
root cause), and (b) no *effective* event afterwards — either because Nacos
never pushes again, or because a closing tombstone vetoes the rebuild.
### Implication for the fix (section 11.1)
A revision retry queue alone is **not sufficient** for same-address restarts
(hostNetwork / NodePort / IP-reused pods, docker, single-node dev): retries
that succeed within the tombstone TTL (default 30s) will still be vetoed by
`doCacheInvoker`, and if no event arrives after the TTL expires the consumer
stays down anyway. Suggest either:
- clearing/bypassing the closing tombstone when the registry reports the
same instance key healthy again with a **new revision** (the provider is
demonstrably back, not a stale closing event), or
- having the metadata-retry scheduler drive `RegistryDirectory` rebuilds in
a way that is not gated by the tombstone (or extending the tombstone semantics
to expire on new-revision registration).
### Reproduction package
<details><summary>docker-compose.yml</summary>
```yaml
services:
nacos:
image: nacos/nacos-server:v2.5.1-slim
environment:
MODE: standalone
NACOS_AUTH_ENABLE: "false"
JVM_XMS: 256m
JVM_XMX: 256m
networks:
repro-net:
ipv4_address: 172.30.0.10
ports:
- "8848:8848"
- "9848:9848"
provider:
build:
context: .
target: provider
environment:
NACOS_ADDR: nacos:8848
depends_on:
- nacos
networks:
repro-net:
ipv4_address: 172.30.0.11
consumer:
build:
context: .
target: consumer
cap_add:
- NET_ADMIN
environment:
NACOS_ADDR: nacos:8848
depends_on:
- nacos
networks:
repro-net:
ipv4_address: 172.30.0.12
networks:
repro-net:
driver: bridge
ipam:
config:
- subnet: 172.30.0.0/24
```
</details>
<details><summary>Dockerfile</summary>
```dockerfile
FROM golang:1.26-bookworm AS build
WORKDIR /app
COPY go.mod go.sum ./
RUN go mod download
COPY provider ./provider
COPY consumer ./consumer
RUN CGO_ENABLED=0 go build -o /out/provider ./provider \
&& CGO_ENABLED=0 go build -o /out/consumer ./consumer
FROM debian:bookworm-slim AS provider
COPY --from=build /out/provider /provider
ENTRYPOINT ["/provider"]
FROM debian:bookworm-slim AS consumer
RUN apt-get update && apt-get install -y --no-install-recommends iptables \
&& rm -rf /var/lib/apt/lists/*
COPY --from=build /out/consumer /consumer
ENTRYPOINT ["/consumer"]
```
</details>
<details><summary>provider/main.go</summary>
```go
package main
import (
"context"
"os"
"os/signal"
"syscall"
)
import (
"github.com/dubbogo/gost/log/logger"
)
import (
"google.golang.org/protobuf/types/known/emptypb"
"google.golang.org/protobuf/types/known/wrapperspb"
)
import (
"dubbo.apache.org/dubbo-go/v3/common"
"dubbo.apache.org/dubbo-go/v3/common/constant"
"dubbo.apache.org/dubbo-go/v3/global"
"dubbo.apache.org/dubbo-go/v3/protocol"
"dubbo.apache.org/dubbo-go/v3/registry"
"dubbo.apache.org/dubbo-go/v3/server"
_ "dubbo.apache.org/dubbo-go/v3/imports"
tri "dubbo.apache.org/dubbo-go/v3/protocol/triple/triple_protocol"
)
const interfaceName = "com.example.GreetService"
type GreetService struct{}
func (s *GreetService) Reference() string { return interfaceName }
func (s *GreetService) SayHello(context.Context, *emptypb.Empty)
(*wrapperspb.StringValue, error) {
return wrapperspb.String("hello from provider"), nil
}
func main() {
nacosAddr := os.Getenv("NACOS_ADDR")
if nacosAddr == "" {
nacosAddr = "127.0.0.1:8848"
}
srv, err := server.NewServer(
server.WithServerProtocol(
protocol.WithTriple(),
protocol.WithPort(20001),
),
server.WithServerRegistry(
registry.WithNacos(),
registry.WithAddress(nacosAddr),
registry.WithRegisterService(), // application-level
service discovery
),
server.SetServerApplication(&global.ApplicationConfig{Name:
"demo-provider"}),
)
if err != nil {
panic(err)
}
svc := &GreetService{}
info := &common.ServiceInfo{
InterfaceName: interfaceName,
ServiceType: svc,
Methods: []common.MethodInfo{
{
Name: "SayHello",
Type: constant.CallUnary,
ReqInitFunc: func() any {
return &emptypb.Empty{}
},
MethodFunc: func(ctx context.Context, args
[]any, handler any) (any, error) {
req := args[0].(*emptypb.Empty)
res, callErr :=
handler.(*GreetService).SayHello(ctx, req)
if callErr != nil {
return nil, callErr
}
return tri.NewResponse(res), nil
},
},
},
}
if err := srv.Register(svc, info, server.WithInterface(interfaceName));
err != nil {
panic(err)
}
logger.Infof("provider starting, nacos=%s port=20001", nacosAddr)
if err := srv.Serve(); err != nil {
panic(err)
}
sig := make(chan os.Signal, 1)
signal.Notify(sig, syscall.SIGINT, syscall.SIGTERM)
<-sig
}
```
</details>
<details><summary>consumer/main.go</summary>
```go
package main
import (
"context"
"fmt"
"os"
"time"
)
import (
"github.com/dubbogo/gost/log/logger"
)
import (
"google.golang.org/protobuf/types/known/emptypb"
"google.golang.org/protobuf/types/known/wrapperspb"
)
import (
"dubbo.apache.org/dubbo-go/v3/client"
"dubbo.apache.org/dubbo-go/v3/global"
"dubbo.apache.org/dubbo-go/v3/registry"
_ "dubbo.apache.org/dubbo-go/v3/imports"
)
const interfaceName = "com.example.GreetService"
func main() {
nacosAddr := os.Getenv("NACOS_ADDR")
if nacosAddr == "" {
nacosAddr = "127.0.0.1:8848"
}
cli, err := client.NewClient(
client.WithClientRegistry(
registry.WithNacos(),
registry.WithAddress(nacosAddr),
registry.WithRegisterService(), // application-level
service discovery
),
client.SetClientApplication(&global.ApplicationConfig{Name:
"demo-consumer"}),
)
if err != nil {
panic(err)
}
conn, err := cli.DialWithInfo(
interfaceName,
&client.ClientInfo{
InterfaceName: interfaceName,
MethodNames: []string{"SayHello"},
},
)
if err != nil {
panic(err)
}
logger.Infof("consumer dialed %s via nacos=%s, starting call loop",
interfaceName, nacosAddr)
for i := 1; ; i++ {
ctx, cancel := context.WithTimeout(context.Background(),
3*time.Second)
resp := &wrapperspb.StringValue{}
callErr := conn.CallUnary(ctx, []any{&emptypb.Empty{}}, resp,
"SayHello")
cancel()
if callErr != nil {
fmt.Printf("CALL #%d FAIL: %v\n", i, callErr)
} else {
fmt.Printf("CALL #%d OK: %s\n", i, resp.GetValue())
}
time.Sleep(2 * time.Second)
}
}
```
</details>
<details><summary>repro.sh (orchestration: block → restart → unblock →
observe → restart consumer)</summary>
```bash
#!/usr/bin/env bash
# Reproduce: application-level Nacos discovery stays permanently empty after
a
# transient MetadataService fetch failure during provider restart (dubbo-go
v3.3.2).
set -u
cd "$(dirname "$0")"
PROVIDER_IP=172.30.0.11
COMPOSE="docker compose"
say() { printf '\n\033[1;34m== %s\033[0m\n' "$*"; }
fail() { printf '\033[1;31mFAIL: %s\033[0m\n' "$*" >&2; exit 1; }
wait_log() { # service, pattern, timeout_seconds
local deadline=$(( $(date +%s) + $3 ))
while [ "$(date +%s)" -lt "$deadline" ]; do
if $COMPOSE logs "$1" 2>&1 | grep -q "$2"; then return 0; fi
sleep 2
done
return 1
}
wait_url() { # url, pattern, timeout_seconds
local deadline=$(( $(date +%s) + $3 ))
while [ "$(date +%s)" -lt "$deadline" ]; do
if curl -sf "$1" 2>/dev/null | grep -q "$2"; then return 0; fi
sleep 2
done
return 1
}
say "0. clean slate & build"
$COMPOSE down -v --remove-orphans >/dev/null 2>&1
$COMPOSE build || fail "docker build"
say "1. start nacos"
$COMPOSE up -d nacos || fail "start nacos"
wait_url "http://127.0.0.1:8848/nacos/v1/console/health/readiness"; 'OK' 180 \
|| fail "nacos not ready"
echo "nacos ready"
say "2. start provider, wait for registration"
$COMPOSE up -d provider || fail "start provider"
wait_url
"http://127.0.0.1:8848/nacos/v1/ns/instance/list?serviceName=demo-provider";
'"healthy":true' 90 \
|| fail "provider not registered in nacos"
echo "provider registered"
say "3. start consumer, wait for baseline CALL OK"
$COMPOSE up -d consumer || fail "start consumer"
wait_log consumer "CALL #[0-9]* OK" 120 || { $COMPOSE logs --tail=50
consumer; fail "baseline call never succeeded"; }
echo "baseline OK: consumer can call provider"
say "4. stop provider, wait for consumer to see empty instance list"
$COMPOSE stop provider >/dev/null
wait_log consumer "No provider available" 120 || fail "consumer never saw
provider go down"
echo "consumer directory is now empty (provider offline) — expected"
say "5. BLOCK consumer -> provider network (simulate transient failure
window)"
$COMPOSE exec -T consumer iptables -A OUTPUT -d "$PROVIDER_IP" -j DROP ||
fail "iptables block"
say "6. restart provider (new timestamp => new metadata revision)"
$COMPOSE start provider >/dev/null
wait_url
"http://127.0.0.1:8848/nacos/v1/ns/instance/list?serviceName=demo-provider";
'"healthy":true' 90 \
|| fail "provider not re-registered in nacos"
echo "provider re-registered with new revision"
say "7. wait for consumer's first metadata fetch to fail behind the block"
wait_log consumer "failed to get metadata" 90 || { $COMPOSE logs --tail=80
consumer; fail "metadata failure not observed — window missed"; }
echo "observed: metadata fetch failed, instance skipped"
sleep 3
say "8. UNBLOCK network (provider and nacos are now fully healthy)"
$COMPOSE exec -T consumer iptables -D OUTPUT -d "$PROVIDER_IP" -j DROP ||
fail "iptables unblock"
say "9. observe 40s: consumer should KEEP FAILING with 'No provider
available'"
sleep 40
RECENT="$($COMPOSE logs --since=40s consumer 2>&1)"
echo "$RECENT" | grep "CALL #" | tail -8
if echo "$RECENT" | grep -q "CALL #[0-9]* OK"; then
fail "consumer recovered on its own — bug NOT reproduced"
fi
echo "$RECENT" | grep -q "No provider available" || fail "unexpected state:
neither OK nor No provider"
echo "confirmed: consumer permanently stuck at 'No provider available'
despite healthy provider"
say "10. restart consumer => expect immediate recovery"
$COMPOSE restart consumer >/dev/null
wait_log consumer "CALL #[0-9]* OK" 90 || { $COMPOSE logs --tail=50
consumer; fail "consumer did not recover after restart"; }
$COMPOSE logs --since=20s consumer 2>&1 | grep "CALL #" | tail -3
say "BUG REPRODUCED: transient metadata failure => permanent No provider;
consumer restart recovers"
```
</details>
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
