SonarQube MySQL read time out

361 views Asked by At

My system consists of:

SonarQube 5.1, MySQL 5.6.19, Sonar-Qube Runner 2.4

I have a project with 20 submodules and 2,7 million lines of code.

When I try to execute an analysis it randomly fails with the following error:

ERROR: Caused by: Unable to request: /batch/project?key=XXX ERROR: Caused by: Read timed out

Log-File:

2015.06.19 11:25:20 TRACE web[sql] time=2ms | sql=SELECT * FROM `users` WHERE (login='admin' AND active=1)  LIMIT 1
2015.06.19 11:25:20 TRACE web[sql] time=1ms | sql=SELECT * FROM `groups`  INNER JOIN `groups_users` ON `groups`.id = `groups_users`.group_id WHERE (`groups_users`.user_id = 1 ) 
2015.06.19 11:25:20 DEBUG web[http] GET /api/server | time=42ms
2015.06.19 11:25:22 TRACE web[sql] time=1ms | sql=SELECT * FROM `users` WHERE (login='admin' AND active=1)  LIMIT 1
2015.06.19 11:25:22 TRACE web[sql] time=1ms | sql=SELECT * FROM `groups`  INNER JOIN `groups_users` ON `groups`.id = `groups_users`.group_id WHERE (`groups_users`.user_id = 1 ) 
2015.06.19 11:25:22 TRACE web[sql] time=3ms | sql=SELECT gr.role        FROM group_roles gr        INNER JOIN groups_users gu on gu.group_id=gr.group_id        INNER JOIN users u on u.id=gu.user_id         WHERE  u.login=?          and gr.resource_id is null         UNION        SELECT gr.role        FROM group_roles gr        WHERE gr.group_id IS NULL AND gr.resource_id IS NULL        UNION        SELECT ur.role        FROM user_roles ur        INNER JOIN users u on u.id=ur.user_id         WHERE  u.login=?          and ur.resource_id is null
2015.06.19 11:25:22 TRACE web[sql] time=1ms | sql=SELECT      p.id,    p.uuid as uuid,    p.project_uuid as projectUuid,    p.module_uuid as moduleUuid,    p.module_uuid_path as moduleUuidPath,    p.kee as kee,    p.deprecated_kee as deprecatedKey,    p.name as name,    p.long_name as longName,    p.qualifier as qualifier,    p.scope as scope,    p.language as language,    p.root_id as parentProjectId,    p.path as path,    p.enabled as enabled,    p.copy_resource_id as copyResourceId,    p.authorization_updated_at as authorizationUpdatedAt,    p.created_at as createdAt       FROM projects p     WHERE  p.kee=?
2015.06.19 11:25:29 TRACE web[sql] time=1ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc
2015.06.19 11:25:29 TRACE web[sql] time=7105ms | sql=SELECT      p.id,    p.uuid as uuid,    p.project_uuid as projectUuid,    p.module_uuid as moduleUuid,    p.module_uuid_path as moduleUuidPath,    p.kee as kee,    p.deprecated_kee as deprecatedKey,    p.name as name,    p.long_name as longName,    p.qualifier as qualifier,    p.scope as scope,    p.language as language,    p.root_id as parentProjectId,    p.path as path,    p.enabled as enabled,    p.copy_resource_id as copyResourceId,    p.authorization_updated_at as authorizationUpdatedAt,    p.created_at as createdAt       FROM projects p         INNER JOIN projects module ON module.project_uuid = p.project_uuid AND module.uuid = ? AND module.scope='PRJ' AND module.enabled = true     WHERE p.enabled = true            AND p.scope = ?      AND                p.module_uuid_path LIKE concat(module.module_uuid_path, '%')
2015.06.19 11:25:36 TRACE web[sql] time=6092ms | sql=SELECT prop.id as id, prop.prop_key as "key", prop.text_value as value, prop.resource_id as resourceId, prop.user_id as userId    FROM properties prop    INNER JOIN (SELECT p.id FROM projects p     INNER JOIN projects module ON module.project_uuid = p.project_uuid AND module.uuid = ? AND module.scope='PRJ' AND module.enabled = true     WHERE p.enabled = true            AND p.scope = ?      AND                p.module_uuid_path LIKE concat(module.module_uuid_path, '%')    ) modules on modules.id=prop.resource_id    WHERE prop.user_id IS NULL
2015.06.19 11:25:39 TRACE web[sql] time=1ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc
2015.06.19 11:25:48 WARN   es[o.e.c.r.a.decider]  [sonar-1434705179964] high disk watermark [10%] exceeded on [KsoLp6GbTqmey19kQXz4qA][sonar-1434705179964] free: 5.5gb[9.3%], shards will be relocated away from this node
2015.06.19 11:25:49 TRACE web[sql] time=0ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc
2015.06.19 11:25:49 TRACE web[sql] time=13656ms | sql=SELECT p.uuid, p.path, p.module_uuid as moduleUuid, fs.src_hash as srcHash    FROM projects p    INNER JOIN file_sources fs ON fs.file_uuid=p.uuid     WHERE  p.project_uuid=?      AND p.enabled=true      AND p.scope='FIL'
2015.06.19 11:25:50 TRACE web[sql] time=2ms | sql=SELECT      p.id as id,    p.kee as kee,    p.name as name,    p.language as language,    p.parent_kee as parentKee,    p.created_at as createdAt,    p.updated_at as updatedAt,    p.rules_updated_at as rulesUpdatedAt       FROM rules_profiles p, projects project    INNER JOIN properties prop ON prop.resource_id=project.id     WHERE  p.language=?      AND prop.prop_key LIKE ?      AND prop.text_value LIKE p.name      AND project.kee=?
2015.06.19 11:25:50 TRACE web[sql] time=2ms | sql=SELECT      p.id as id,    p.kee as kee,    p.name as name,    p.language as language,    p.parent_kee as parentKee,    p.created_at as createdAt,    p.updated_at as updatedAt,    p.rules_updated_at as rulesUpdatedAt       FROM rules_profiles p    INNER JOIN properties prop ON prop.prop_key=?      AND prop.resource_id IS NULL      AND prop.text_value LIKE p.name      AND p.language=?
2015.06.19 11:25:50 TRACE web[es] ES search request '{"from":0,"size":100,"query":{"filtered":{"query":{"match_all":{}},"filter":{"bool":{"must":[{"bool":{"must_not":{"term":{"status":"REMOVED"}}}},{"terms":{"lang":["java"]}}]}}}},"_source":{"includes":["templateKey","internalKey","name","key"],"excludes":[]},"sort":[{"updatedAt":{"order":"desc"}},{"key.sort":{"order":"asc"}}]}' on indices '[rules]' on types '[rule]' | time=42ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@4965453a' | time=107ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@17a4087b' | time=55ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@1228cf5d' | time=100ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@3545ebfb' | time=61ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@187c710' | time=47ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@791dec38' | time=46ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@1b7f8ea7' | time=24ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@536e840b' | time=23ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@7c9f18f7' | time=23ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@3120400c' | time=22ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@3c4ced06' | time=22ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@5e5d43d7' | time=24ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@3d1108a7' | time=23ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@294f2b43' | time=14ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@48dbf596' | time=4ms
2015.06.19 11:25:50 TRACE web[es] ES search request '{"size":100,"query":{"filtered":{"query":{"match_all":{}},"filter":{"bool":{"must":{"term":{"profile":"java-r7-quality-profile-66231"}},"must_not":{"has_parent":{"filter":{"term":{"status":"REMOVED"}},"parent_type":"rule"}}}}}}}' on indices '[rules]' on types '[activeRule]' | time=79ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@493ff1bd' | time=8ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@5e7eb49f' | time=2ms
2015.06.19 11:25:50 TRACE web[es] ES search request '{"from":0,"size":10,"query":{"filtered":{"query":{"match_all":{}},"filter":{"bool":{"must":[{"bool":{"must_not":{"term":{"status":"REMOVED"}}}},{"terms":{"repo":["manual"]}}]}}}},"_source":{"includes":["name","key"],"excludes":[]},"sort":[{"updatedAt":{"order":"desc"}},{"key.sort":{"order":"asc"}}]}' on indices '[rules]' on types '[rule]' | time=4ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@50846330' | time=2ms
2015.06.19 11:25:50 TRACE web[es] ES search scroll request for scroll id 'org.elasticsearch.search.Scroll@238c0d9c' | time=2ms
2015.06.19 11:25:50 DEBUG web[http] GET /batch/project?key=T3000-Build-LATEST&preview=false | **time=28226ms**
2015.06.19 11:25:57 TRACE web[sql] time=1ms | sql=select id, data    from notifications    order by id asc    limit ?
2015.06.19 11:25:59 TRACE web[sql] time=1ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc
2015.06.19 11:26:09 TRACE web[sql] time=1ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc
2015.06.19 11:26:18 WARN   es[o.e.c.r.a.decider]  [sonar-1434705179964] high disk watermark [10%] exceeded on [KsoLp6GbTqmey19kQXz4qA][sonar-1434705179964] free: 5.5gb[9.3%], shards will be relocated away from this node
2015.06.19 11:26:18 INFO   es[o.e.c.r.a.decider]  [sonar-1434705179964] high disk watermark exceeded on one or more nodes, rerouting shards
2015.06.19 11:26:19 TRACE web[sql] time=4ms | sql=select ar.id    from analysis_reports ar    where ar.report_status=?    and not exists(    select 1    from analysis_reports ar2    where ar.project_key = ar2.project_key    and ar2.report_status=?    )    order by ar.created_at asc, ar.id asc

I know it fails, because the read time is > 20 ms. How can I increase the read time? Or what else can I do, that the error will not come up anymore?

1

There are 1 answers

3
Fabrice - SonarSource Team On

This is a known limitation that you can indeed encounter under the conjunction of some circumstances (project with lots of modules and/or files, heavy load on the SQ server, ...).

There is an open ticket on this limitation, and we'll soon be working on this: SONAR-6604.