History | Log In     View a printable version of the current page.  
Issue Details (XML | Word | Printable)

Key: QB-3106
Type: Bug Bug
Status: Closed Closed
Resolution: Incomplete
Priority: Critical Critical
Assignee: Steve Luo
Reporter: Piotr Jedrys
Votes: 0
Watchers: 0
Operations

If you were logged in you would be able to see more operations.
QuickBuild

Long query inserts to QB_MEASUREMENTS

Created: 22/Dec/17 12:39 PM   Updated: 25/Jan/19 08:49 AM
Component/s: None
Affects Version/s: 7.0.28
Fix Version/s: None

Original Estimate: Unknown Remaining Estimate: Unknown Time Spent: Unknown
File Attachments: 1. Text File jvm4.log (5.79 Mb)

Image Attachments:

1. Screen Shot 2018-01-22 at 16.43.37.png
(468 kb)

2. Screen Shot 2018-01-22 at 16.43.58.png
(493 kb)

3. Screen Shot 2018-01-22 at 16.44.17.png
(367 kb)

4. Screen Shot 2018-01-22 at 16.44.36.png
(430 kb)

5. Screen Shot 2018-01-22 at 16.49.39.png
(380 kb)
Environment: Linux


 Description  « Hide
Slow query results shows that insert to QB_MEASUREMENT_DATAR03 is taking much time.
# Query 2: 0.00 QPS, 0.01x concurrency, ID 0xA77BB2A9D02C43ED at byte 13078
# Scores: V/M = 0.64
# Time range: 2017-12-21T17:30:33 to 2017-12-21T21:33:01
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 21 12
# Exec time 17 182s 11s 21s 15s 19s 3s 15s
# Lock time 40 1ms 50us 384us 85us 69us 85us 57us
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 8 2.06k 176 176 176 176 0 176
# String:
# Hosts quickbuild_master
# Users quickbuild_db
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS LIKE 'QB_MEASUREMENT_DATAR03'\G
# SHOW CREATE TABLE `QB_MEASUREMENT_DATAR03`\G
/* insert com.pmease.quickbuild.model.MeasurementDataR03 */ insert into QB_MEASUREMENT_DATAR03 (QB_METRIC_NAME, QB_SOURCE, QB_TIMESTAMP, QB_VALUE, QB_ID) values (?, ?, ?, ?, ?)\G


This is actual status of the table:
mysql> SHOW TABLE STATUS LIKE 'QB_MEASUREMENT_DATAR03'
    -> ;
+------------------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+------------+-----------+----------+----------------+---------+
| Name | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time | Update_time | Check_time | Collation | Checksum | Create_options | Comment |
+------------------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+------------+-----------+----------+----------------+---------+
| QB_MEASUREMENT_DATAR03 | InnoDB | 10 | Dynamic | 108211 | 121 | 13123584 | 0 | 35831808 | 5242880 | NULL | 2017-12-10 16:18:20 | 2017-12-22 00:28:13 | NULL | utf8_bin | NULL | | |
+------------------------+--------+---------+------------+--------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+------------+-----------+----------+----------------+---------+


How do you suggest to optimize it?

 All   Comments   Work Log   Change History      Sort Order:
Piotr Jedrys [22/Dec/17 01:06 PM]
Additional question:

how many maximum open connections should be set for QB hibernate config?

Steve Luo [23/Dec/17 04:16 PM]
Seems your data is huge. How many agents are there in your site?

Piotr Jedrys [03/Jan/18 08:58 AM]
Yes our data is huge. Around 120 agents running.

Steve Luo [05/Jan/18 03:46 AM]
120 agents should not be a problem. As far as I know, there are some companies running 1500+ agents without problem.

Is it possible your database instance can't handle so much data? How about to use some more powerful machine for your database?

Piotr Jedrys [05/Jan/18 10:31 AM]
So what are the recommended values for database and for server?

Piotr Jedrys [09/Jan/18 11:03 AM]
Any answer?

After upgrade to 7.x QB, we encounter a slow down.
Our QB server is 30GB of RAM (and still using swap? that is strange)
around 120 nodes connected
DB is MySQL with 2GB of RAM

How can we check what is causing the problems of random slowdowns. What do you recommend to profile the application

Steve Luo [09/Jan/18 11:56 AM]
Hi Piotr,

I think 30GB of RAM is more than enough for QuickBuild, I'd suggest you just give 8-10GB to QuickBuild. Instead you need add more RAM to MySQL. In your case, I think you can give 8GB or more RAM to MySQL.

And you'd better run your builds on the agents instead of running them on server node, server node is just used for dispatching jobs to the agents and used for displaying the web UI.

Piotr Jedrys [10/Jan/18 02:19 PM]
Previously we had 16GB RAM dedicated to QB server, and the Heap meater was going to 99% quite fast. Even with 30GB we still see it going up to 85% once per hour. It all happened after moving from 6.x to 7.x .

We do not run any builds on master server. All of them are running on the nodes.

What else can we check?

Robin Shen [11/Jan/18 02:01 AM]
It is abnormal that so much memory is consumed by QB. Please reduce the maxmemory setting to 8G (so we can get the memory dump not too large), and then edit "conf/wrapper.conf" to add below setting:
wrapper.java.additional.4=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.5=-XX:HeapDumpPath=./heapdump.bin

This will make QB dumps memory when there is an OOE. Then please upload the heapdump to DropBox and send me a link for diagnostics.

Robin Shen [11/Jan/18 02:03 AM]
Also make sure that you do not have scripts or restful programs querying QB database for all builds/all configurations or large sets of data frequently, which will consume a lot of resources.

Piotr Jedrys [22/Jan/18 03:43 PM]
OutOfMemory did not occur even on small Heap size, as the GC is freeing it up, so unfortunately I do not have a heap dump.

Nevertheless we have increased memory for database up to 10GB, and reduced the QB server memory to 16GB

Based on the jvm.log produced for GC runs we can clearly see that memory usage is growing and growing, and after some time Full GC run is executed. (attached jvm.log and screenshot)

Additionally we tried as well JProfiler to check what is happening there. Here are our investigation points:
- there is a bunch (up to 70% of memory) instances of char[], most of which comes from EhCache (should it be growing so high? )
- each entrance/even refresh to the web ui generates 3000 instances of Configuration class (maybe Dashboard queries are not good in case of caching and performance?)
- sometimes we get up to 700 threads (a big amount of them is H2 log, or a H2 database storage JUnit)
- sometimes we can be blocked threads with name: qtp... (why ? )

Our setup :

additional wrapper config:
wrapper.java.additional.auto_bits=TRUE
wrapper.java.additional.1=-Djava.awt.headless=true
wrapper.java.additional.2=-Xverify:none
#wrapper.java.additional.3=-Dreset
wrapper.java.initmemory=16384
wrapper.java.maxmemory=16384
wrapper.app.parameter.1=com.pmease.quickbuild.bootstrap.Bootstrap
wrapper.app.parameter.2=1
wrapper.app.parameter.3=start
wrapper.app.parameter.4=com.pmease.quickbuild.bootstrap.Bootstrap
wrapper.app.parameter.5=FALSE
wrapper.app.parameter.6=1
wrapper.app.parameter.7=stop
wrapper.console.format=PM
wrapper.console.loglevel=INFO
wrapper.logfile=../logs/console.log
wrapper.logfile.format=PM
wrapper.logfile.loglevel=INFO
wrapper.logfile.maxsize=20M
wrapper.logfile.maxfiles=10
wrapper.java.additional.3=-XX:MaxPermSize=512m
wrapper.java.additional.4=-Xss300k # in order to avoid the 'unable to create new native thread' exception
wrapper.java.additional.5=-XX:+UseParallelOldGC
wrapper.java.additional.6=-XX:ParallelGCThreads=8
wrapper.java.additional.7=-XX:MaxGCPauseMillis=2000
wrapper.java.additional.8=-Xloggc:../logs/jvm.log
wrapper.java.additional.9=-XX:+PrintGCDetails
wrapper.java.additional.10=-XX:+PrintGCTimeStamps
wrapper.java.additional.11=-XX:+PrintGCDateStamps
wrapper.java.additional.12=-XX:+StartAttachListener
wrapper.java.additional.13=-XX:+HeapDumpOnOutOfMemoryError
wrapper.java.additional.14=-XX:HeapDumpPath=./heapdump.bin
wrapper.java.additional.16=-Dcom.sun.management.jmxremote
wrapper.java.additional.17=-Dcom.sun.management.jmxremote.ssl=false
wrapper.java.additional.18=-Dcom.sun.management.jmxremote.authenticate=false
wrapper.java.additional.19=-Dcom.sun.management.jmxremote.port=1099

hibernate:
hibernate.connection.autocommit=true
hibernate.c3p0.min_size=5
hibernate.c3p0.max_size=125
hibernate.c3p0.max_statements=0
hibernate.c3p0.idle_test_period=600

hibernate.show_sql=false
hibernate.format_sql=true
hibernate.use_sql_comments=true
javax.persistence.validation.mode=none
hibernate.validator.apply_to_ddl=false
hibernate.cache.provider_class=org.hibernate.cache.EhCacheProvider
hibernate.cache.use_query_cache=true


Jetty:

  <Set name="ThreadPool">
    <New class="org.eclipse.jetty.util.thread.QueuedThreadPool">
      <Set name="minThreads">64</Set>
      <Set name="maxThreads">1024</Set>
    </New>
  </Set>

  <Ref id="SocketConnector">
    <Set name="acceptors">16</Set>
    <Set name="acceptQueueSize">256</Set>
    <Set name="StatsOn">true</Set>
  </Ref>


Are we missing something? What else could we check?

And finally can we have a direct contact to the person who can help us with performance issues with QB server?

Steve Luo [23/Jun/18 02:47 AM]
This issue seems to related to issue QB-3183.

You may consider to upgrade to QB8.0.10 to see if this issue still exist.