spring mvc + wildfly + postgresql performance tunning

Question

I have spent plenty of hours trying to figure out what is causing my application to work really slow, maybe someone will help me to check what is the problem.

versions:

spring mvc: 4.2.5.RELEASE

hibernate: 4.3.11.Final

spring-data-jpa: 1.8.2.RELEASE

wildfly: 10

PostgreSQL Server: 9.4

OS: Debian GNU/Linux 7.9 (wheezy)

Server configuration: VPS, 1 proc, 4GB RAM

About my app:

Simple web application with static JSP landing page, information page and login which redirect to private area. Public pages are static, first query to database is being done during login and then trying to get content for logged user.

What is the problem:

When I navigate through pages which are configured like this:

<http auto-config="true"> 
        <intercept-url pattern="/" access="permitAll"/>
        <intercept-url pattern="favicon.ico" access="permitAll"/>
        <intercept-url pattern="/login/**" access="permitAll"/>
        <intercept-url pattern="/info" access="permitAll"/>
...
</http>

there is no problem, everything is being loaded on he fly, there are no pauses. It works smooth. When I Post on /login (which redirect me to /main) and then when I navigate on each site configured like this:

<intercept-url pattern="/main/**" access="hasRole('ROLE_USER')"/>
<intercept-url pattern="/statistic/**" access="hasRole('ROLE_USER')"/>
<intercept-url pattern="/admin/**" access="hasRole('ROLE_ADMIN')" />

there are some extreme delays sometimes even up to 1 minute.

Hibernate configuration

<bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <property name="driverClassName" value="${jdbc.driverClassName}"/>
        <property name="url" value="${jdbc.url}"/>
        <property name="username" value="${jdbc.username}"/>
        <property name="password" value="${jdbc.password}"/>
    </bean>

    <!-- Configure the entity manager factory bean -->
    <bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
        <property name="dataSource" ref="dataSource"/>
        <property name="packagesToScan" value="pl.portal.model"/>
        <property name="jpaVendorAdapter">
            <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter"/>
        </property>
        <property name="jpaProperties">
            <props>
                <!-- <prop key="hibernate.dialect">pl.portal.sql.ProjectPsqlDialect</prop> -->
                <prop key="hibernate.show_sql">false</prop>
                <prop key="hibernate.enable_lazy_load_no_trans">true</prop>
                <prop key="hibernate.jdbc.use_streams_for_binary">false</prop>
                <prop key="hibernate.connection.useUnicode">true</prop>
                <prop key="hibernate.connection.characterEncoding">UTF-8</prop>
                <prop key="hibernate.connection.characterSet">UTF-8</prop>

            </props>
        </property>
    </bean>

Can anyone give me a hint how to determine what is causing that delays? Checking on webinspect in my browser -> /admin, size 7,89KB, size : 54secons (where each js or css not exced 100ms)

EDIT2: removed invalid fragment of thread dump, pasted full dump of thread which start after invoking action /admin on app. Thread took 61s

Thread dump

thread on visualvm console:

One cheap way to discover what it is doing to perform a Java thread dump while waiting for one of your slow responses. The thread performing the slow operation will likely show a long stack trace pointing back through the slow part of your application. — Steve C, Aug 30 '17 at 08:42
The other relatively cheap way is to use VisualVM and thread sampling (https://dzone.com/articles/visualvm-12-great-java). Btw. doing thread dump on linux can be achieved via `kill -QUIT YOUR_PROCESS_PID` or `jstack YOUR_PROCESS_PID`. — Pavel Horal, Sep 01 '17 at 08:06
Btw. if this is a new project I highly recommend getting rid of old and leaky DBCP and going for HikariCP (or at least switch to DBCP2). — Pavel Horal, Sep 01 '17 at 08:09
You can use VisualVM to monitor the thread status (All threads simultaneously). In the thread tab, if you see some red area, that means your threads are blocked. Take a thread dump as soon as you see that your threads are in the blocked state for a long period of time and analyze it. — Abhinav P, Sep 01 '17 at 12:52
@PavelHoral, the OP is using WildFly so he should *not* be using any third party connection pooling at all. — Steve C, Sep 03 '17 at 07:21
Check: "select * from pg_stat_activity" for hanging "idle in the transaction". Why are you using true? — Justinas Jakavonis, Sep 06 '17 at 08:18
@Justas when I remove lazy load i get exceptions `"Failed to lazily initialize a collection (...)"` after selecting query You have provided, i find 4 results — Mithrand1r, Sep 06 '17 at 08:32
Ok, it seems there is no problem in this area but it is recommended to avoid enable_lazy_load_no_trans (https://stackoverflow.com/questions/25362831/solve-hibernate-lazy-init-issue-with-hibernate-enable-lazy-load-no-trans) and use @Transactional — Justinas Jakavonis, Sep 06 '17 at 10:09

score 2 · Accepted Answer · answered Sep 01 '17 at 14:09

There can be many reasons for such delays, some of the most common ones are stated below.

Threads are waiting for a lock.
Database performance issues.
CPU intensive task.
Network delays

Network delays between the web server and client can be ruled out in your case as you mentioned that the server response time for static pages and page resources such as CSS is in milliseconds.

For the rest of the things, a remote management system like VisualVM is the best tool to find out what is causing delays and which process is taking a lot of CPU time. You can also go for commercial profilers like JProfiler, but VisualVm can also do the job perfectly.

To connect to ViusalVM you need to have access to your server and add JMX options in JAVA_OPTS or wherever your options go and restart the web application.

Threads waiting for lock - There may be a piece of code where have you have a synchronized method that locks on a static field. If that method lets assume takes about 5 seconds for processing a DB query. And there are 10 requests queued up. Then the last request will be processed in 50 seconds or more.

How to detect this bottleneck situation?

You can go through the code and find out all the places where there are acquiring locks and add some debug logs. But what if the problem is not within your code and probably arising from some third party library?

I once faced a situation where the Logger (log4j library) would block all threads(for around 10 seconds) when the log file was rolled over. There was no way that this situation could have been detected with code review.

Profilers to the rescue. VisualVM is probably the best profiler to detect delays caused by thread locking. Here is what you can do.

Monitor the thread.
When you see many threads in blocked state.
Take thread dump.
Analyze the thread dump to see which function is causing this issue and solve the problem accordingly.

CPU Intensive task - If a process is taking a lot of CPU time, it can also cause delays. Again you can use VisualVM's sampler and find out which thread is taking the most amount of CPU time.

Hope this will help find you the reason for the delay!

I have edited my question providing thread dump from thread that takes the longes time. I Have no idea how to read it :/ — Mithrand1r, Sep 05 '17 at 09:40
@Mithrand1r. How did know that this is the thread that takes the longest time? Can you please attach the full thread dump in an external link. Also, you may have to add more logs in the request that takes a lot of time. For example, add a log when you get the request, before DB call, after you get the response from DB, just before you send back the response. Using the timestamp from these log entries, you will be able to figure out which part is taking the most time. — Abhinav P, Sep 05 '17 at 11:29
All I can tell from the attached thread dump of the single thread is - the thread is reading the response of a JDBC query at the time of thread dump. Maybe the DB query is taking up a lot of time. — Abhinav P, Sep 05 '17 at 11:33
Checked the thread dump, everything looks fine. You seem to have taken the thread dump when the thread task was completed. As the thread that you mentioned in the EDIT was in Waiting state instead of Runnable. — Abhinav P, Sep 06 '17 at 10:55
Can you add some logs that I mentioned earlier? Add the logs at various points like. Just after the "/admin" request method is called. Before and after any IO operations, for example, database query. Just before sending out the response from your method back to the browser. Make sure there is a timestamp with each log entry. You can analyze that to see which area takes the most time and narrow the focus on that area. For instance, just before you execute a DB query the timestamp is 13:00:00 and after getting the response of that query the timestamp is 13:01:00 (1 minute) which is problematic. — Abhinav P, Sep 06 '17 at 11:02
@Mithrand1r did you try adding logs? You can share the logs if you did. — Abhinav P, Sep 07 '17 at 19:25
@AbhinavP just note. To search locks you could use PrintConcurrentLocks option. — egorlitvinenko, Sep 07 '17 at 22:32

Alexander Petrov · Answer 2 · 2017-09-01T11:39:55.567

With respect to how to analyse the performance you can focus on several aspects:

DB
Network
Application layer
Memory

Monitoring the DB is plane simple use a RDBMS monitoring tool like Query Monitor for DB2 or something else depending on the vendor.

Analysing the BNetwork, there are many different Tools but what you need to do is to figure out what is Your latency and what is Your network speed.

I believe we can presume that in Your case the Network is OK or at least it is not very likly that there is problem.

The Third thing to analyse is Your Application layer, this is where you need a proper profiling tool. You can use visualVM which is free and comes With the jdk or alternativly you can use yourkit which is paid. But you can get a trial Version.

The memory you can also analyse With a profiling tool.

Once you perform CPU sampling you will be able to figure out which areas of Your Application are causing the delays. Yourkit is also capable of monitoring the executed SQLs from the Application layer side. This way you will get in one measurement the SQL speed + the latency to execute it + the time to transfer the resultset.

Common performance tunning opitions are:

Hibernate. Use batching for Collections loading, do not join relations instead favour FetchStrategy.SELECT.

Make sure you don't perform any cartesian Products and such.

egorlitvinenko · Answer 3 · 2017-09-07T17:38:40.403

Server configuration: VPS, 1 proc, 4GB RAM

Do you have access to the server? Try run top command also and see CPU usage. You have only one proc, maybe something huge is running.

Typical way to start find performance problems:

Condition 1 You could connect with profiler Do it. jvisualvm, jconsole, NetBeans Profiler, perf, etc.

Connect to your process with profiler;
Run task, which you think is slow and wait;
Save profiler results to analyse;

You should be attentive to total CPU time.

Condition 2 You can not connect with profiler

Yes, here you can use jstack to get thread dumps. jps to get java process ID.

Prepare cmd/bash;
Run jps and find your process pid, remember;
Run task, which you think is slow;
Run jstack multiple times and save output (jstack pid > output.1, jstack pid > output.2, etc.);
Analyse all results and see, which methods are most frequent.

Don't make pre-optimizations, meausure performance before. :)

UPDATE for answer after new information.

In Thread dump you can see a lot of "sun.nio.ch.EPollArrayWrapper.epollWait", try to look some links:

Maybe it is your case. There was a bug with epoll. But something similar occurs in nowadays too.

score 0 · Answer 4 · answered Sep 06 '17 at 07:15

In my experience you may have db lock problem. There is an sql locking your table for a while. Your code is waiting then the lock is released and your code continues. You may monitor db locks to find which sql locks your table while your code is hanging.

spring mvc + wildfly + postgresql performance tunning

4 Answers4