Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

The metadata invoker is destroyed too early #2321

Closed
justxuewei opened this issue May 28, 2023 · 0 comments · Fixed by #2322
Closed

The metadata invoker is destroyed too early #2321

justxuewei opened this issue May 28, 2023 · 0 comments · Fixed by #2322

Comments

@justxuewei
Copy link
Member

justxuewei commented May 28, 2023

Environment

  • Server: Dubbo-go, the latest main branch
  • Client: Dubbo-go, the latest main branch
  • Protocol: Triple
  • Registry: Zookeeper

Issue description

The failure of CI testing is caused by the problem, see: https://github.com/apache/dubbo-go/actions/runs/5086376932/jobs/9164858889?pr=2320.

The logs were copied into the below section. Here is a brief summary of the timeline:

  1. The metadata invoker was initialized.
  2. The metadata invoker was destroyed after a series of requests.
  3. The UserProvider invoker was initialized.
  4. The UserProvider invoker was destroyed, the reason is unknown currently.
  5. The client wants to access to the metadata again, then the program panics.

The problem was introduced by #2166. And I can't understand what problem was being described in the issue #2159. So a temporary workaround is to restore it. Please @bobtthp, take a look at this problem and review the code. If you think it is required, please file a new issue and describe the problem you faced more detailed.

Logs

Click me to check logs
2023-05-27T09:08:07.831Z	INFO	directory/directory.go:252	[Registry Directory] selector add service url{tri://10.1.0.70:20001/org.apache.dubbo.samples.UserProvider?application=dubbo.io&cluster=failover&interface=org.apache.dubbo.samples.UserProvider&loadbalance=random&release=dubbo-golang-3.0.4&serialization=hessian2&timestamp=1685178479}
2023-05-27T09:08:07.832Z	INFO	zookeeper/client.go:53	[Zookeeper Client] New zookeeper client with name = 127.0.0.1:2181, zkAddress = 127.0.0.1:2181, timeout = 5s
2023-05-27T09:08:07.832Z	INFO	config/root_config.go:138	[Config Center] Config center doesn't start
2023-05-27T09:08:07.833Z	INFO	servicediscovery/service_discovery_registry.go:235	Synchronized instance notification on subscription, instance list size %!s(int=1)
2023-05-27T09:08:07.833Z	INFO	servicediscovery/service_instances_changed_listener_impl.go:71	Received instance notification event of service dubbo.io, instance list size %!s(int=1)
2023-05-27T09:08:07.834Z	WARN	prometheus/reporter.go:425	new prometheus reporter with error = listen tcp :9090: bind: address already in use
2023-05-27T09:08:07.836Z	INFO	dubbo/dubbo_protocol.go:99	[DUBBO Protocol] Refer service: dubbo://10.1.0.70:41763/org.apache.dubbo.metadata.MetadataService?application=dubbo.io&group=dubbo.io&interface=org.apache.dubbo.metadata.MetadataService&port=41763&protocol=dubbo&release=dubbo-golang-3.0.4&timestamp=1685178479&version=1.0.0
2023-05-27T09:08:07.837Z	INFO	protocol/invoker.go:93	Destroy invoker: dubbo://10.1.0.70:41763/org.apache.dubbo.metadata.MetadataService?application=dubbo.io&group=dubbo.io&interface=org.apache.dubbo.metadata.MetadataService&port=41763&protocol=dubbo&release=dubbo-golang-3.0.4&serialization=hessian2&timestamp=1685178479&version=1.0.0
2023-05-27T09:08:07.837Z	INFO	directory/directory.go:252	[Registry Directory] selector add service url{dubbo://10.1.0.70:20000/org.apache.dubbo.samples.UserProvider?application=dubbo.io&cluster=failover&interface=org.apache.dubbo.samples.UserProvider&loadbalance=random&release=dubbo-golang-3.0.4&serialization=hessian2&timestamp=1685178479}
2023-05-27T09:08:07.837Z	INFO	dubbo-getty@v1.4.9/client.go:460	session-closed closed now. its current gr num is 1
2023-05-27T09:08:07.838Z	INFO	getty/pool.go:310	close client session{session session-closed, Read Bytes: 2575, Write Bytes: 272, Read Pkgs: 1, Write Pkgs: 1, last active:2023-05-27 09:08:07.837675252 +0000 UTC m=+0.057655344, request number:1}
2023-05-27T09:08:07.838Z	INFO	getty/pool.go:312	session-closed closed now. its current gr num is 1
2023-05-27T09:08:07.838Z	INFO	zookeeper/listener.go:464	[Zookeeper Listener] listen dubbo path{/services/dubbo.io}
2023-05-27T09:08:07.840Z	INFO	servicediscovery/service_instances_changed_listener_impl.go:71	Received instance notification event of service dubbo.io, instance list size %!s(int=1)
2023-05-27T09:08:07.840Z	INFO	protocol/rpc_status.go:241	Remove invoker key = dubbo://:@10.1.0.70:20000/?interface=org.apache.dubbo.samples.UserProviderTriple&group=&version=&timestamp=&meshClusterID= from black list
2023-05-27T09:08:07.841Z	INFO	protocol/invoker.go:93	Destroy invoker: dubbo://10.1.0.70:20000/org.apache.dubbo.samples.UserProviderTriple?app.version=&application=dubbo.io&async=false&bean.name=dubbo.io&cluster=failover&config.tracing=&environment=&generic=true&group=&interface=org.apache.dubbo.samples.UserProviderTriple&loadbalance=random&metadata-type=local&module=sample&name=dubbo.io&organization=dubbo-go&owner=dubbo-go&provided-by=&reference.filter=generic%2Ccshutdown&registry.role=0&release=dubbo-golang-3.0.4&retries=&serialization=hessian2&side=consumer&sticky=false&timestamp=1685178479&version=
2023-05-27T09:08:08.127Z	WARN	dubbo-getty@v1.4.9/client.go:419	client{peer:10.1.0.70:41763} goroutine exit now.
2023-05-27T09:08:08.127Z	WARN	dubbo-getty@v1.4.9/client.go:419	client{peer:10.1.0.70:41763} goroutine exit now.
2023-05-27T09:08:08.828Z	INFO	dubbo-getty@v1.4.9/session.go:614	session-closed, [session.handlePackage] gr will exit now, left gr num 0
2023-05-27T09:08:08.828Z	INFO	getty/listener.go:90	session{session session-closed, Read Bytes: 2575, Write Bytes: 272, Read Pkgs: 1, Write Pkgs: 1} is closing......
2023-05-27T09:08:08.829Z	INFO	getty/pool.go:221	after remove session{session session-closed, Read Bytes: 2575, Write Bytes: 272, Read Pkgs: 1, Write Pkgs: 1}, left session number:0
2023-05-27T09:08:08.837Z	WARN	dubbo/dubbo_protocol.go:94	can't dial the server: 10.1.0.70:41763
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x1409cb4]

justxuewei added a commit to justxuewei/dubbo-go that referenced this issue May 28, 2023
The PR fixes the problem that the metadata invoker is destroyed too early.
Please refer to the issue for more details. Plus, this PR updates some logs
about registering services.

Fixes: apache#2321

Signed-off-by: Xuewei Niu <justxuewei@apache.org>
justxuewei added a commit that referenced this issue May 28, 2023
The PR fixes the problem that the metadata invoker is destroyed too early.
Please refer to the issue for more details. Plus, this PR updates some logs
about registering services.

Fixes: #2321

Signed-off-by: Xuewei Niu <justxuewei@apache.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant