apache/dubbo

Performance issue of NetUtils in Apple M2

Open

#13,743 opened on Feb 5, 2024

View on GitHub
 (3 comments) (0 reactions) (0 assignees)Java (26,453 forks)batch import
component/sdkhelp wantedtype/enhancement

Repository metrics

Stars
 (41,524 stars)
PR merge metrics
 (Avg merge 7d 14h) (20 merged PRs in 30d)

Description

Environment

  • Dubbo version: 3.2.11
  • Operating System version: Apple M2 chip macOS 14.2.1
  • Java version: OpenJDK 64-Bit Server VM (build 21.0.2+13-58, mixed mode, sharing)

Reproduction method 1

public static void main(String[] args) throws Exception {
         NetUtils.getLocalHost();
         long l = System.currentTimeMillis();
         NetUtils.getLocalHost();
         System.out.println("use " + (System.currentTimeMillis() - l) + "ms");
         System.out.println();
}

In most cases, the second call to NetUtils.getLocalHost() will take a very short time because HOST_ADDRESS has cached the results of the previous call. However, in the Apple M2 chip macOS 14.2.1 environment, non-root users will always return false when executing InetAddress.isReachable, which causes the HOST_ADDRESS assignment to fail.

Reproduction method 2

Because almost every line of logs uses NetUtils.getLocalHost(), this ultimately leads to a significant increase in dubbo's overall startup time.

The following log is the difference between the root user and ordinary users calling FrameworkModel.defaultModel() (pay attention to the timestamp of the log)

Java code

import org.apache.dubbo.rpc.model.FrameworkModel;

public class FrameworkModelDemo {

public static void main(String[] args) throws Exception {
long l = System.currentTimeMillis();
FrameworkModel.defaultModel();
System.out.println("use " + (System.currentTimeMillis() - l) + "ms");
}

}

general user

java -cp .:build:./target/dependency/* FrameworkModelDemo
2024-02-05 21:19:34.661 INFO org.apache.dubbo.rpc.model.FrameworkModel [<init>:86] [main] - [DUBBO] Dubbo Framework[1] is created, dubbo version: 3.2.11 , current host: 127.0.0.1
2024-02-05 21:19:35.098 INFO org.apache.dubbo.common.resource.GlobalResourcesRepository [getExecutorService:96] [main] - [DUBBO] Creating global shared handler ..., dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:35.569 INFO org.apache.dubbo.rpc.model.ApplicationModel [<init>:107] [main] - [DUBBO] Dubbo Application[1.0](unknown) is created, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:35.980 INFO org.apache.dubbo.rpc.model.ScopeModel [<init>:63] [main] - [DUBBO] Dubbo Module[1.0.0] is created, dubbo version: 3.2 .11, current host: 127.0.0.1
2024-02-05 21:19:36.416 INFO org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] - [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config. ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:36.828 INFO org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] - [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config. ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:37.248 INFO org.apache.dubbo.common.utils.SerializeSecurityManager [setCheckSerializable:107] [main] - [DUBBO] Serialize check serializable: true, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:37.660 INFO org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadAllow:135] [main] - [DUBBO] Read serialize allow list from jar:file:/Users/fzming/workspace/ demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.allowlist, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:38.118 INFO org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadBlocked:159] [main] - [DUBBO] Read serialize blocked list from jar:file:/Users/fzming/workspace/ demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.blockedlist, dubbo version: 3.2.11, current host: 127.0.0.1
use 4077ms

root user

sudo java -cp .:build:./target/dependency/* FrameworkModelDemo
2024-02-05 21:20:36.077 INFO org.apache.dubbo.rpc.model.FrameworkModel [<init>:86] [main] - [DUBBO] Dubbo Framework[1] is created, dubbo version: 3.2.11 , current host: 100.85.129.227
2024-02-05 21:20:36.087 INFO org.apache.dubbo.common.resource.GlobalResourcesRepository [getExecutorService:96] [main] - [DUBBO] Creating global shared handler ..., dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.127 INFO org.apache.dubbo.rpc.model.ApplicationModel [<init>:107] [main] - [DUBBO] Dubbo Application[1.0](unknown) is created, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.128 INFO org.apache.dubbo.rpc.model.ScopeModel [<init>:63] [main] - [DUBBO] Dubbo Module[1.0.0] is created, dubbo version: 3.2 .11, current host: 100.85.129.227
2024-02-05 21:20:36.139 INFO org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] - [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config. ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.139 INFO org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] - [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config. ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.144 INFO org.apache.dubbo.common.utils.SerializeSecurityManager [setCheckSerializable:107] [main] -  [DUBBO] Serialize check serializable: true, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.144 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadAllow:135] [main] -  [DUBBO] Read serialize allow list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.allowlist, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.166 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadBlocked:159] [main] -  [DUBBO] Read serialize blocked list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.blockedlist, dubbo version: 3.2.11, current host: 100.85.129.227
use 284ms

Environment

  • Dubbo version: 3.2.11
  • Operating System version: Apple M2芯片 macOS 14.2.1
  • Java version: OpenJDK 64-Bit Server VM (build 21.0.2+13-58, mixed mode, sharing)

复现方式1

public static void main(String[] args) throws Exception {
        NetUtils.getLocalHost();
        long l = System.currentTimeMillis();
        NetUtils.getLocalHost();
        System.out.println("use " + (System.currentTimeMillis() - l) + "ms");
        System.out.println();
}

多数情况下,第二次调用NetUtils.getLocalHost() 会使用极短时间,因为HOST_ADDRESS已经缓存了上次调用的结果 但是在Apple M2芯片 macOS 14.2.1 环境下,非root用户执行 InetAddress.isReachable 会一直返回false,这导致了HOST_ADDRESS赋值失败。

复现方式2

因为几乎每行日志都使用了NetUtils.getLocalHost(),这最终导致了dubbo整体启动时间的大幅度上涨

下面日志是 root用户和普通用户调用FrameworkModel.defaultModel() 的区别(注意观察日志的时间戳)

Java代码

import org.apache.dubbo.rpc.model.FrameworkModel;

public class FrameworkModelDemo {

	public static void main(String[] args) throws Exception {
		long l = System.currentTimeMillis();
		FrameworkModel.defaultModel();
		System.out.println("use " + (System.currentTimeMillis() - l) + "ms");
	}

}

普通用户

java -cp .:build:./target/dependency/* FrameworkModelDemo
2024-02-05 21:19:34.661 INFO  org.apache.dubbo.rpc.model.FrameworkModel [<init>:86] [main] -  [DUBBO] Dubbo Framework[1] is created, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:35.098 INFO  org.apache.dubbo.common.resource.GlobalResourcesRepository [getExecutorService:96] [main] -  [DUBBO] Creating global shared handler ..., dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:35.569 INFO  org.apache.dubbo.rpc.model.ApplicationModel [<init>:107] [main] -  [DUBBO] Dubbo Application[1.0](unknown) is created, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:35.980 INFO  org.apache.dubbo.rpc.model.ScopeModel [<init>:63] [main] -  [DUBBO] Dubbo Module[1.0.0] is created, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:36.416 INFO  org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] -  [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config.ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:36.828 INFO  org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] -  [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config.ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:37.248 INFO  org.apache.dubbo.common.utils.SerializeSecurityManager [setCheckSerializable:107] [main] -  [DUBBO] Serialize check serializable: true, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:37.660 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadAllow:135] [main] -  [DUBBO] Read serialize allow list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.allowlist, dubbo version: 3.2.11, current host: 127.0.0.1
2024-02-05 21:19:38.118 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadBlocked:159] [main] -  [DUBBO] Read serialize blocked list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.blockedlist, dubbo version: 3.2.11, current host: 127.0.0.1
use 4077ms

root用户

sudo java -cp .:build:./target/dependency/* FrameworkModelDemo
2024-02-05 21:20:36.077 INFO  org.apache.dubbo.rpc.model.FrameworkModel [<init>:86] [main] -  [DUBBO] Dubbo Framework[1] is created, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.087 INFO  org.apache.dubbo.common.resource.GlobalResourcesRepository [getExecutorService:96] [main] -  [DUBBO] Creating global shared handler ..., dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.127 INFO  org.apache.dubbo.rpc.model.ApplicationModel [<init>:107] [main] -  [DUBBO] Dubbo Application[1.0](unknown) is created, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.128 INFO  org.apache.dubbo.rpc.model.ScopeModel [<init>:63] [main] -  [DUBBO] Dubbo Module[1.0.0] is created, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.139 INFO  org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] -  [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config.ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.139 INFO  org.apache.dubbo.config.context.AbstractConfigManager [initialize:143] [main] -  [DUBBO] Config settings: {dubbo.config.mode=STRICT, dubbo.config.ignore-duplicated-interface=false}, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.144 INFO  org.apache.dubbo.common.utils.SerializeSecurityManager [setCheckSerializable:107] [main] -  [DUBBO] Serialize check serializable: true, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.144 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadAllow:135] [main] -  [DUBBO] Read serialize allow list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.allowlist, dubbo version: 3.2.11, current host: 100.85.129.227
2024-02-05 21:20:36.166 INFO  org.apache.dubbo.common.utils.SerializeSecurityConfigurator [loadBlocked:159] [main] -  [DUBBO] Read serialize blocked list from jar:file:/Users/fzming/workspace/demos/alibaba.com/dubbo3/performance_init_test/target/dependency/dubbo-3.2.11.jar!/security/serialize.blockedlist, dubbo version: 3.2.11, current host: 100.85.129.227
use 284ms

Contributor guide