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?
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.