今天一个同学Demo项目中使用到了skywalking包
在使用chaosblade后发现JVM类型的故障注入失败.
日志没有报错,也没有什么有效错误信息
time="2022-01-05 17:23:05.20323428 CST" level=debug msg="process info" cmdline="java -XX:+UseG1GC -server -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=60 -XX:+UnlockExperimentalVMOptions -XX:+UnlockDiagnosticVMOptions -XX:+UseCGroupMemoryLimitForHeap -Djava.security.edg=file:/dev/./urandom -Duser.timezone=GMT+8 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/mnt/logs/micro-scm-mes/micro-scm-mes-java.hprof -XX:ErrorFile=/mnt/logs/micro-scm-mes/micro-scm-mes-hs_err_pid_%p.log -verbose:gc -Xloggc:/mnt/logs/micro-scm-mes/micro-scm-mes-gc-202201051720.log -XX:+PrintHeapAtGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=50M -XX:-UseCompressedOops -Djava.awt.headless=true -Dio.netty.leakDetection.level=advanced -Dsun.net.client.defaultConnectTimeout=10000 -Dsun.net.client.defaultReadTimeout=60000 -Dapp.id=micro-scm-mes -Denv=FAT -Dapollo.cluster=test -Dapollo.meta=http://10.10.201.248:8761 -Dapollo.bootstrap.enabled=true -Dapollo.bootstrap.eagerLoad.enabled=true -javaagent:/root/skywalking-agent-8.5.0/skywalking-agent.jar -Dlog.box.sourceHost=10.10.201.237 -jar /root/app.jar --spring.profiles.active=dev" excludeProcesses="[blade chaos_killprocess chaos_stopprocess]" otherConditionProcessName= processCommand=java processName=scm-mes
time="2022-01-05 17:23:05.208799018 CST" level=info msg="javaBin: /usr/lib/jvm/default-jvm/bin/java, javaHome: /usr/lib/jvm/default-jvm, toolsJar: /usr/lib/jvm/default-jvm/lib/tools.jar"
time="2022-01-05 17:23:05.208836999 CST" level=debug msg="Command: date | head | cksum | sed 's/ //g'"
time="2022-01-05 17:23:05.211046261 CST" level=debug msg="Command Result, output: 400816026329\n, err: <nil>"
time="2022-01-05 17:23:05.211116289 CST" level=debug msg="decode 400816026329 err, return default value, {"code":60000,"success":false,"error":"400816026329
: exec result unmarshal failed, err: json: cannot unmarshal number into Go value of type spec.Response"}"
time="2022-01-05 17:23:05.211139077 CST" level=debug msg="Command: /usr/lib/jvm/default-jvm/bin/java -Xms128M -Xmx128M -Xnoclassgc -ea -Xbootclasspath/a:/usr/lib/jvm/default-jvm/lib/tools.jar -jar /chaosblade-1.4.0/lib/sandbox/lib/sandbox-core.jar 1 "/chaosblade-1.4.0/lib/sandbox/lib/sandbox-agent.jar" "home=/chaosblade-1.4.0/lib/sandbox;token=400816026329;server.ip=127.0.0.1;server.port=46607;namespace=chaosblade""
time="2022-01-05 17:23:06.264152199 CST" level=debug msg="Command Result, output: , err: <nil>"
time="2022-01-05 17:23:06.264200301 CST" level=debug msg="Command: grep 400816026329 /root/.sandbox.token | grep chaosblade | tail -1 | awk -F ";" '{print 4}'"
time="2022-01-05 17:23:06.267832764 CST" level=debug msg="Command Result, output: localhost;46607\n, err: <nil>"
time="2022-01-05 17:23:06.267923675 CST" level=debug msg="decode localhost;46607 err, return default value, {"code":60000,"success":false,"error":"localhost;46607
: exec result unmarshal failed, err: invalid character 'l' looking for beginning of value"}"
time="2022-01-05 17:23:11.268029597 CST" level=info msg="http://127.0.0.1:46607/sandbox/chaosblade/module/http/sandbox-module-mgr/active?1=1&ids=chaosblade"
time="2022-01-05 17:23:19.571854121 CST" level=info msg="http://127.0.0.1:46607/sandbox/chaosblade/module/http/chaosblade/status?1=1"
查看~/logs/sandbox/sandbox.log信息后发现报错:
2022-01-05 17:25:12 chaosblade INFO transform com/inclution/microscmmes/controller/workorder/WorkOrderReplaceController finished, by module=chaosblade in loader=org.springframework.boot.loader.LaunchedURLClassLoader@7c18432b
2022-01-05 17:25:12 chaosblade WARN watch=1056 in module=chaosblade single reTransform class com.inclution.microscmmes.controller.workorder.WorkOrderReplaceController failed, at index=0;total=1. ignore this class.
java.lang.UnsupportedOperationException: class redefinition failed: attempted to change the schema (add/remove fields)
at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultModuleEventWatcher.reTransformClasses(DefaultModuleEventWatcher.java:119)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultModuleEventWatcher.watch(DefaultModuleEventWatcher.java:200)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultModuleEventWatcher.watch(DefaultModuleEventWatcher.java:158)
at com.alibaba.jvm.sandbox.core.manager.impl.DefaultModuleEventWatcher.watch(DefaultModuleEventWatcher.java:150)
at sun.reflect.GeneratedMethodAccessor214.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.alibaba.jvm.sandbox.core.util.SandboxProtectorProxy382.watch(Unknown Source)
at com.alibaba.chaosblade.exec.bootstrap.jvmsandbox.SandboxModule.add(SandboxModule.java:216)
at com.alibaba.chaosblade.exec.plugin.jvm.MethodPreInjectHandler.preHandleInjection(MethodPreInjectHandler.java:48)
at com.alibaba.chaosblade.exec.plugin.jvm.JvmModelSpec.preCreate(JvmModelSpec.java:98)
at com.alibaba.chaosblade.exec.service.handler.CreateHandler.applyPreInjectionModelHandler(CreateHandler.java:167)
at com.alibaba.chaosblade.exec.service.handler.CreateHandler.handleInjection(CreateHandler.java:145)
at com.alibaba.chaosblade.exec.service.handler.CreateHandler.handle(CreateHandler.java:102)
at com.alibaba.chaosblade.exec.service.handler.DefaultDispatchService.dispatch(DefaultDispatchService.java:64)
at com.alibaba.chaosblade.exec.bootstrap.jvmsandbox.SandboxModule.service(SandboxModule.java:158)
at com.alibaba.chaosblade.exec.bootstrap.jvmsandbox.SandboxModule.create(SandboxModule.java:136)
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.core.server.jetty.servlet.ModuleHttpServlet.doMethod(ModuleHttpServlet.java:133)
at com.alibaba.jvm.sandbox.core.server.jetty.servlet.ModuleHttpServlet.doPost(ModuleHttpServlet.java:60)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:594)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111)
at org.eclipse.jetty.server.Server.handle(Server.java:351)
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454)
at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:900)
at org.eclipse.jetty.server.AbstractHttpConnection1.run(SelectChannelEndPoint.java:45)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534)
at java.lang.Thread.run(Thread.java:748)
2022-01-05 17:25:12 chaosblade INFO activated listener[id=1057;target=com.alibaba.chaosblade.exec.bootstrap.jvmsandbox.BeforeEventListener@1206451a;] event=BEFORE
发现retransform失败了,非常有意思的问题
其根本原因是agent冲突了,skywalking使用的bytebuddy(字节的好朋友)导致的
ByteBuddy generates auxiliary classes with different random names every time. When other javaagent executes retransform, it will trigger the SkyWalking agent to enhance the class again.
The bytecode regenerated by ByteBuddy is changed, the fields and imports are modified, and the retransform fails.
解决方案:
- skywalking支持class cache. -Dskywalking.agent.is_cache_enhanced_class=true
原因分析:使用了class cache, skywalking会将增强的class信息放到缓存中,当其他agent retransform class后,触发skywalking增强时,skywalking会先从cache中查询,当查询到后就不会再增强,因此可以解决此问题;
此外,由于此问题也会导致arthas(另一款字节码工具)功能失效:https://github.com/alibaba/arthas/issues/1141
https://github.com/SkyAPMTest/retransform-conflict-demo
网友评论