Search code examples
mysqlhibernateehcachemysql-slow-query-log

Mysql, hibernate slow_query_log logs set timestamp

I'm running a load test on java application which uses hibernate framework in DAO layer. I found several occurrences of following in slow query log.

# Time: 170704 15:06:47
# User@Host: user[user] @ localhost [127.0.0.1]  Id:   163
# Query_time: 0.428159  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1499161007;
commit;

I'm using mysql Ver 14.14 Distrib 5.1.73, for redhat-linux-gnu (x86_64) using readline 5.1 on Cent OS. EhCache has been used as the caching provider for hibernate for some entities. I'm using 3GB inno_db_buffer_pool_size for 199.6MB database with 32-64 pooled mysql connections in my application. Additionally server has 16GB of total RAM and application JVM is configured to use 4GB heap.

I found this article written back in 2007. I'm not sure whether hibernate involves in calling NOW() or any other problem causing action in my case. Anything like that has not been explicitly done in the code. Any idea about the root cause of this log line?

Solution

  • According to this stackoverflow question commit; statement is the reason to be this record in slow query log. SET timestamp=1499161007; has been executed prior to get statistical details.

    I also needed to find what queries were executed in the transaction that has taken long time to commit. Digging little deeper I found mysql query log and suggestions provided in this question can be used.