search

perfana / jfr-exporter

Capture and analyse JDK Flight Recorder events in time series.
https://www.perfana.io
Apache License 2.0
7 stars 1 forks source link

InfluxDB works slow with stacktraces #4

Open polarnik opened 2 months ago

polarnik commented 2 months ago

JFR uses a stack trace size 64 by default. 64 lines of code are not enough for some projects, Spring for example.

I have added two options for my application:

The key option is stackdepth=1024. Grafana dashboard is not working well with long stack trace. It works slowly

Issues:

Expected results

Is it possible to add some additional fields and tags?

It will improve report performance

Is it possible to have the stacktrace field value without additional symbols " --- "?

It will simplify stacktrace usage.

Is it possible to add some additional filters into the agent?

For example, an option filters: `filters=com.example,org.hibernate.persister

Stacktrace example with libraries

For we have a stacktrace (from the message https://stackoverflow.com/questions/3988788/what-is-a-stack-trace-and-how-can-i-use-it-to-debug-my-application-errors) ```java at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:60) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.example.myproject.ExceptionHandlerFilter.doFilter(ExceptionHandlerFilter.java:28) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at com.example.myproject.OutputBufferFilter.doFilter(OutputBufferFilter.java:33) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157) at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388) at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216) at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418) at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) at org.mortbay.jetty.Server.handle(Server.java:326) at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:943) at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756) at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) at org.mortbay.jetty.bio.SocketConnector$Connection.run(SocketConnector.java:228) at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) at com.example.myproject.MyServlet.doPost(MyServlet.java:169) at javax.servlet.http.HttpServlet.service(HttpServlet.java:727) at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166) at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:30) at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:96) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) at org.hibernate.id.insert.AbstractSelectingDelegate.performInsert(AbstractSelectingDelegate.java:64) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2329) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2822) at org.hibernate.action.EntityIdentityInsertAction.execute(EntityIdentityInsertAction.java:71) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:268) at org.hibernate.event.def.AbstractSaveEventListener.performSaveOrReplicate(AbstractSaveEventListener.java:321) at org.hibernate.event.def.AbstractSaveEventListener.performSave(AbstractSaveEventListener.java:204) at org.hibernate.event.def.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:130) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.saveWithGeneratedOrRequestedId(DefaultSaveOrUpdateEventListener.java:210) at org.hibernate.event.def.DefaultSaveEventListener.saveWithGeneratedOrRequestedId(DefaultSaveEventListener.java:56) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.entityIsTransient(DefaultSaveOrUpdateEventListener.java:195) at org.hibernate.event.def.DefaultSaveEventListener.performSaveOrUpdate(DefaultSaveEventListener.java:50) at org.hibernate.event.def.DefaultSaveOrUpdateEventListener.onSaveOrUpdate(DefaultSaveOrUpdateEventListener.java:93) at org.hibernate.impl.SessionImpl.fireSave(SessionImpl.java:705) at org.hibernate.impl.SessionImpl.save(SessionImpl.java:693) at org.hibernate.impl.SessionImpl.save(SessionImpl.java:689) at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:344) at $Proxy19.save(Unknown Source) at com.example.myproject.MyEntityService.save(MyEntityService.java:59) <-- relevant call (see notes below) at com.example.myproject.MyServlet.doPost(MyServlet.java:164) at org.hsqldb.jdbc.Util.throwError(Unknown Source) at org.hsqldb.jdbc.jdbcPreparedStatement.executeUpdate(Unknown Source) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105) at org.hibernate.id.insert.AbstractSelectingDelegate.performInsert(AbstractSelectingDelegate.java:57) ```

and the agent will provide a short stacktrace value too:

Stacktrace example without some libraries

```java at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:60) at com.example.myproject.ExceptionHandlerFilter.doFilter(ExceptionHandlerFilter.java:28) at com.example.myproject.OutputBufferFilter.doFilter(OutputBufferFilter.java:33) at com.example.myproject.MyServlet.doPost(MyServlet.java:169) at com.example.myproject.OpenSessionInViewFilter.doFilter(OpenSessionInViewFilter.java:30) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2329) at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2822) at com.example.myproject.MyEntityService.save(MyEntityService.java:59) <-- relevant call (see notes below) at com.example.myproject.MyServlet.doPost(MyServlet.java:164) ```

PeterPaul-Perfana commented 1 month ago

Hi @polarnik , good suggestions! We recognize the need for longer stacktraces when using Spring for example.

Curious to the impact of changing from tag to field for stacktrace, i will look into that.

Using hashes for similar stack traces will also save a lot, but we need some lookup from the hash to the actual trace I assume.

Filters would be very doable, we can skip many unneccesary stacktrace lines. Main point is that we can direct developers to where issues like large object allocations are happening.

The " --- " is used because we could not get the line protocol of influx to deal with newlines. Suggestions to get around this are welcome.

Let's discuss possible solutions and create smaller and focussed issues for those.

Thanks!