环境: vmware 虚拟机, centos7, JDK1.8
操作:按照通用流量录制回放工具 jvm-sandbox-repeater 尝鲜记录中步骤进行操作
执行完 attach sanbox 到目标进程,查看 repeater 日志时发现不对: 没有拉取 repeater config, 事件注册失败
本地情况
2019-09-16 16:12:39 INFO initializing logback success. file=/root/.sandbox-module/cfg/repeater-logback.xml;
2019-09-16 16:12:39 INFO module on loaded,id=repeater,version=1.0.0,mode=ATTACH
2019-09-16 16:12:39 INFO onActive
正常情况:
2019-07-07 10:24:14 INFO initializing logback success. file=/Users/hengjiechen/.sandbox-module/cfg/repeater-logback.xml;
2019-07-07 10:24:14 INFO module on loaded,id=repeater,version=1.0.0,mode=ATTACH
2019-07-07 10:24:14 INFO onActive
2019-07-07 10:24:14 INFO pull repeater config success,config=com.alibaba.jvm.sandbox.repeater.plugin.domain.RepeaterConfig@4dddeb36
2019-07-07 10:24:15 INFO enable plugin http success
2019-07-07 10:24:15 INFO add watcher success,type=http,watcherId=1000
2019-07-07 10:24:16 INFO register event bus success in repeat-register
repeater 日志出现异常了,那 sanbox 的日志呢
2019-09-16 16:12:39 default INFO loading module, module=repeater;class=com.alibaba.jvm.sandbox.repeater.module.RepeaterModule;module-jar=/root/.sandbox-module/repeater-module.jar;
2019-09-16 16:12:39 default INFO active module when OnLoad, module=repeater
2019-09-16 16:12:39 default INFO active module, module=repeater;class=com.alibaba.jvm.sandbox.repeater.module.RepeaterModule;module-jar=/root/.sandbox-module/repeater-module.jar;
2019-09-16 16:12:39 default WARN loading module occur error when load-completed. module=repeater;
java.lang.ExceptionInInitializerError: null
at com.alibaba.jvm.sandbox.repeater.module.RepeaterModule.loadCompleted(RepeaterModule.java:122)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultCoreModuleManager.callAndFireModuleLifeCycle(DefaultCoreModuleManager.java:135)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultCoreModuleManager.load(DefaultCoreModuleManager.java:189)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultCoreModuleManager.access$300(DefaultCoreModuleManager.java:36)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultCoreModuleManager$InnerModuleLoadCallback.onLoad(DefaultCoreModuleManager.java:563)
at com.alibaba.jvm.sandbox.core.manager.impl.ModuleJarLoader.loadingModules(ModuleJarLoader.java:88)
at com.alibaba.jvm.sandbox.core.manager.impl.ModuleJarLoader.load(ModuleJarLoader.java:126)
at com.alibaba.jvm.sandbox.core.manager.impl.ModuleLibLoader.load(ModuleLibLoader.java:76)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultCoreModuleManager.reset(DefaultCoreModuleManager.java:590)
at com.alibaba.jvm.sandbox.core.server.jetty.JettyCoreServer.bind(JettyCoreServer.java:196)
at com.alibaba.jvm.sandbox.core.server.ProxyCoreServer.bind(ProxyCoreServer.java:39)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.alibaba.jvm.sandbox.agent.AgentLauncher.install(AgentLauncher.java:255)
at com.alibaba.jvm.sandbox.agent.AgentLauncher.agentmain(AgentLauncher.java:108)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:386)
at sun.instrument.InstrumentationImpl.loadClassAndCallAgentmain(InstrumentationImpl.java:411)
Caused by: java.lang.IllegalArgumentException: null
at java.util.concurrent.ThreadPoolExecutor.<init>(ThreadPoolExecutor.java:1314)
at com.alibaba.jvm.sandbox.repeater.plugin.core.util.ExecutorInner.<clinit>(ExecutorInner.java:24)
... 23 common frames omitted
2019-09-16 16:12:39 default INFO loaded module-jar completed, loaded 1 module in module-jar=/root/.sandbox-module/repeater-module.jar, modules=[repeater]
2019-09-16 16:12:39 default INFO initialized server. actual bind to 0.0.0.0:12580
2019-09-16 16:12:39 default INFO server[0.0.0.0:12580] bind success.
原来,sanbox 进行启动的时候就出了问题,repeater 这边拉取配置还没有走到。
Caused by: java.lang.IllegalArgumentException: null
at java.util.concurrent.ThreadPoolExecutor.<init>(ThreadPoolExecutor.java:1314)
at com.alibaba.jvm.sandbox.repeater.plugin.core.util.ExecutorInner.<clinit>(ExecutorInner.java:24)
/**
* 通用线程池(非执行单一任务)
* <p>
*
* @author zhaoyb1990
*/
public class ExecutorInner {
private static ExecutorService executor = new ThreadPoolExecutor(8,
4 * Runtime.getRuntime().availableProcessors(),
30L, TimeUnit.SECONDS, new LinkedBlockingDeque<Runnable>(4096),
new BasicThreadFactory.Builder().namingPattern("repeater-common-pool-%d").build(),
new ThreadPoolExecutor.CallerRunsPolicy());
public static void execute(Runnable r) {
executor.execute(r);
}
public static Executor getExecutor() {
return executor;
}
public static <T> Future<T> submit(Callable<T> callable) {
return executor.submit(callable);
}
}
通过看 ExecutorInner 代码的 24 行可以看出是第一句代码执行就失败了
private static ExecutorService executor = new ThreadPoolExecutor(8,
4 * Runtime.getRuntime().availableProcessors(),
30L, TimeUnit.SECONDS, new LinkedBlockingDeque<Runnable>(4096),
new BasicThreadFactory.Builder().namingPattern("repeater-common-pool-%d").build(),
new ThreadPoolExecutor.CallerRunsPolicy());
点击 ThreadPoolExecutor 中看一下是什么情况,为什么跑异常
public ThreadPoolExecutor(int corePoolSize,
int maximumPoolSize,
long keepAliveTime,
TimeUnit unit,
BlockingQueue<Runnable> workQueue,
ThreadFactory threadFactory,
RejectedExecutionHandler handler) {
if (corePoolSize < 0 ||
maximumPoolSize <= 0 ||
maximumPoolSize < corePoolSize ||
keepAliveTime < 0)
throw new IllegalArgumentException();
if (workQueue == null || threadFactory == null || handler == null)
throw new NullPointerException();
this.acc = System.getSecurityManager() == null ?
null :
AccessController.getContext();
this.corePoolSize = corePoolSize;
this.maximumPoolSize = maximumPoolSize;
this.workQueue = workQueue;
this.keepAliveTime = unit.toNanos(keepAliveTime);
this.threadFactory = threadFactory;
this.handler = handler;
}
找到了 throw new IllegalArgumentException();的位置了,通过代码可以看出下面的几种情况一个满足就会抛出异常
corePoolSize < 0
maximumPoolSize <= 0
maximumPoolSize < corePoolSize
keepAliveTime < 0
那么我们就来看一下,到底是满足了哪个条件导致抛出的异常呢?
private static ExecutorService executor = new ThreadPoolExecutor(8,
4 * Runtime.getRuntime().availableProcessors(),
30L, TimeUnit.SECONDS, new LinkedBlockingDeque<Runnable>(4096),
new BasicThreadFactory.Builder().namingPattern("repeater-common-pool-%d").build(),
new ThreadPoolExecutor.CallerRunsPolicy());
从代码中可以看出:
corePoolSize = 8 那么 corePoolSize < 0 不满足
maximumPoolSize =4 * Runtime.getRuntime().availableProcessors() 具体多少不知道 maximumPoolSize <= 0 不确定
maximumPoolSize < corePoolSize 不确定
keepAliveTime = 30L 那么 keepAliveTime < 0 不满足
现在就一个参数不确定是多少:maximumPoolSize
搜了一下 Runtime.getRuntime().availableProcessors() 看到这个方法有一个问题就是并非都能返回你期望的数值
然后我灵机一动,会不会是我用的虚拟机,处理器核心数量有问题!!!!
vmware 可以在虚拟机点击编辑虚拟机设置, 处理器中查看的可用处理器数量为 1
如果你不是 vmware 你可以通过一个简单的 java 程序进行验证, HelloWorld.java
public class HelloWorld {
public static void main(String[] args) {
System.out.println(Runtime.getRuntime().availableProcessors());
}
}
然后执行编译和运行,打印出当前的处理器核心数
javac HelloWorld.java
java HelloWorld
这里可以知道 maximumPoolSize =4 * Runtime.getRuntime().availableProcessors() =4 那么 maximumPoolSize <= 0 不满足
maximumPoolSize < corePoolSize 满足!
所以这里满足抛出了异常, 原来 repeater 必须要至少要 2 个处理器核心数量!!!!
所以需要给虚拟机增加处理器的核心数量。系统处理器的核心总数至少为 2,我修改为 4。 repeater 启动正常,可以正常的录制回放了。