08 Jan 2019 09:55 AM - last edited on 10 Dec 2021 11:05 AM by MaciejNeumann
Hi there,
We're having a situation on some weblogic managed servers. It seems that it takes more time to start when having OneAgent monitoring enabled than when it's disabled and running without monitoring.
Java version 1.6.0_31,
Weblogic 12.1.1.0
We did some testing and without OneAgent it takes ~6.5 minutes to start. With OneAgent it takes more than 10 minutes to start.
I can understand that instrumenting the java process could impact the start time a little bit, but why this much (>50%)?
Thanks!
08 Jan 2019 10:01 AM
Hello, did you checked agent logs? Any unusual messages there?
Sebastian
08 Jan 2019 02:54 PM
nothing too unusual. just these errors between the begining of start (20:13) and actual start (20:24):
20:13:38.673 UTC [b8eed84f] info [native] weblogic.jdbc.wrapper.Connection::createStatement "ALOAD requires OBJECT but var contains top @400" - StackMapTable creation failed - switching to old ClassFileFormat.
20:13:41.220 UTC [b8eed84f] info [native] weblogic.servlet.utils.FastSwapFilter::doFilter "ALOAD requires OBJECT but var contains top @461" - StackMapTable creation failed - switching to old ClassFileFormat.
20:13:41.606 UTC [b8eed84f] info [native] weblogic.servlet.internal.RequestEventsFilter::doFilter "ALOAD requires OBJECT but var contains top @405" - StackMapTable creation failed - switching to old ClassFileFormat.
20:13:42.521 UTC [b8eed84f] info [native] weblogic.jdbc.wrapper.Statement::executeQuery "ALOAD requires OBJECT but var contains top @426" - StackMapTable creation failed - switching to old ClassFileFormat.
20:13:47.035 UTC [b8eed84f] info [native] weblogic.jdbc.jts.Driver::connect "ALOAD requires OBJECT but var contains top @2034" - StackMapTable creation failed - switching to old ClassFileFormat.
20:13:47.081 UTC [b8eed84f] info [native] weblogic.jdbc.wrapper.JTSConnection::commit "ALOAD requires OBJECT but var contains top @253" - StackMapTable creation failed - switching to old ClassFileFormat.
20:14:30.206 UTC [78bf3850] info [java ] [agent ] Detected the following GCs: Garbage collection optimized for throughput Young Collector, Garbage collection optimized for throughput Old Collector
20:14:30.213 UTC [78bf3850] info [java ] [agent ] GetInternalThreadCpuTimes can't be called in this JVM
20:14:30.213 UTC [78bf3850] info [native] Measuring JVM GC background CPU time will be disabled as it seems ConcMarkSweep is not set
20:14:32.931 UTC [b8eed84f] info [native] weblogic.jdbc.wrapper.PreparedStatement::execute "ALOAD requires OBJECT but var contains top @420" - StackMapTable creation failed - switching to old ClassFileFormat.
08 Jan 2019 02:56 PM
20:16:33.955 UTC [b8eed84f] info [native] Couldn't retrieve class file for final that triggered a VerifyError
20:18:22.159 UTC [7b3ff850] info [native] ... last message repeated 22 times ...
20:18:22.159 UTC [7b3ff850] info [native] URL https://xxx.xxx.xxx.xxx:9999/communication not working (Connection timed out after 2000 milliseconds)
20:18:23.100 UTC [b8eed84f] info [native] Couldn't retrieve class file for final that triggered a VerifyError
20:21:34.316 UTC [b8eed84f] info [native] ... last message repeated 100 times ...
20:21:34.316 UTC [b8eed84f] info [native] Couldn't retrieve class file for final that triggered a VerifyError
20:24:28.010 UTC [aa17584e] info [native] ... last message repeated 86 times ...
20:24:28.010 UTC [aa17584e] info [native] weblogic.diagnostics.accessor.AccessorServlet::doGet "ALOAD requires OBJECT but var contains top @905" - StackMapTable creation failed - switching to old ClassFileFormat.
08 Jan 2019 03:13 PM
This is something interesting in this example:
20:18:22.159 UTC [7b3ff850] info [native] URL <a href="https://xxx.xxx.xxx.xxx:9999/communication">https://xxx.xxx.xxx.xxx:9999/communication</a> not working (Connection timed out after 2000 milliseconds)
There is problem with communication between your server and ActiveGate / Cluster. But this not be reason of delay in startup.
I think here should talk somebody from Dynatrace side. I have client with weblogic and appmon and I know that there is some impact while starting but actually I don't know how big because they didn't report me this as an issue. If it is urgent for you, you can alway open support ticket.
Sebastian
08 Jan 2019 03:44 PM
hmm.. that's just one of the activegates that this server does not have access to. it's only 2 sec. timeout.
09 Jan 2019 08:05 AM
Do you have any custom services defined?
I think it is related to parts of deep monitoring instrumentation. Can you try to turn off all individual features in deep monitoring settings for this server and see if this makes any difference?
Startup time of 6.5 minutes without OneAgent is definitely not fast anyway. How many applications are deployed in this Application Server and how big is the code part in the deployed wars/ears?
09 Jan 2019 08:14 AM
There are no custom services defined.
I was thinking about deep monitoring beeing the issue, but could not pinpoint the problem.
I know startup is slow even without OneAgent. Unfortunately I cannot tell you how many applications are deployed or how big the code part is because it's a customer's environment and I don't have access to that info.
09 Jan 2019 11:17 AM
Well if you have the possibility to restart it several times, I'd recommend to turn off the all the java features such as JDBC, PurePath capturing in deep monitoring setting for this process group and see if this makes any difference.
09 Jan 2019 02:25 PM
I don't know if they will agree to do this, but we'll try to do it.
10 Jan 2019 05:40 PM
Just try to turn off everything and see if it makes any difference. Otherwise if it really matters, I suggest to open a support ticket.