I cannot say it is unnecessary or not for now. There are indeed many db connections when get resource limtiation/count of domains.
A workaound is (1) listDomainChildren gets id of domain and sub-domains, then (2) listDomains with specified id. -Wei 2016-11-06 17:23 GMT+01:00 Cloud List <cloud-l...@sg.or.id>: > Hi Sergey, > > Thanks for your reply. The grep result is a bit long, total 64K lines, so > I have uploaded it here: > > https://dl.dropboxusercontent.com/u/24788636/ctx-3f3ff343.txt > > It seems there are a lot of unnecessary creating and closing of > connections to the DB, causing the delay? > > Looking forward to your reply, thank you. > > Cheers. > > > On Sun, Nov 6, 2016 at 11:30 PM, Sergey Levitskiy < > sergey.levits...@autodesk.com> wrote: > >> Can you grep for this line ‘ctx-3f3ff343’ in your log and post it here? >> >> >> On 11/5/16, 11:01 PM, "Cloud List" <cloud-l...@sg.or.id> wrote: >> >> Dear all, >> >> After researching further, I found out that our problem is exactly >> the one >> reported on this JIRA bug: >> >> https://issues.apache.org/jira/browse/CLOUDSTACK-9405 >> >> I am cc-ing dsclose and Wei Zhou on this email. Anyone know if >> there's any >> resolution to the above problem/bug? >> >> On the bug report, Wei Zhou mentioned that he added domain level >> resource >> limitation, may I know if this limitation is configurable? I can't >> find it >> on the Global Settings. >> >> Looking forward to your reply, thank you. >> >> Cheers. >> >> >> On Sun, Nov 6, 2016 at 10:30 AM, Cloud List <cloud-l...@sg.or.id> >> wrote: >> >> > Thanks Sergey for your assistance. >> > >> > I have enabled the TRACE logs as requested. After the listDomains >> API >> > call, I see a lot of DB connections being created to the database, >> > preparing SELECT statements and then immediately being closed >> thereafter. >> > This happens many many times in the loop in the course of 10-15 >> seconds. >> > For example: >> > >> > Creating a DB connection with no txn >> > Preparing: SELECT >> > Closing: com.mysql.jdbc.PreparedStatement >> > Closing DB connection >> > >> > The above continues in a loop for 10-15 seconds, sometimes more. Is >> it >> > normal? Could it be something wrong during the database schema >> upgrade when >> > I upgraded from 4.2 to 4.8? >> > >> > Excerpts of the TRACE logs are below. Any advice on how I can >> resolve the >> > problem is highly appreciated. >> > >> > === >> > 2016-11-06 09:36:04,893 DEBUG [c.c.a.ApiServlet] >> > (http-8080-10:ctx-3f3ff343) (logid:0429eaf0) ===START=== X.X.X.X >> -- GET >> > apikey=XXXX&command=listDomains&response=json&signature=YYYY >> > 2016-11-06 09:36:04,893 TRACE [c.c.u.d.T.Transaction] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Using >> current >> > transaction: http-8080-10 : http-8080-10, >> > 2016-11-06 09:36:04,893 TRACE [c.c.u.d.T.Transaction] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Using >> current >> > transaction: http-8080-10 : http-8080-10, >> > 2016-11-06 09:36:04,894 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing: com.mysql.jdbc.JDBC4PreparedSt >> atement@1bda5f56: >> > SELECT vm_instance.id, vm_instance.name, vm_instance.vnc_password, >> > vm_instance.proxy_id, vm_instance.proxy_assign_time, >> vm_instance.state, >> > vm_instance.private_ip_address, vm_instance.instance_name, >> > vm_instance.vm_template_id, vm_instance.guest_os_id, >> vm_instance.host_id, >> > vm_instance.last_host_id, vm_instance.pod_id, >> vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = 4088 AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,894 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing DB connection: dbconn1208177431 >> > 2016-11-06 09:36:04,894 TRACE [c.c.u.d.T.Transaction] >> > (StatsCollector-2:ctx-293a2a9e) (logid:725b6dd7) Using current >> > transaction: StatsCollector-2 : StatsCollector-2, >> > 2016-11-06 09:36:04,895 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Creating >> a DB >> > connection with no txn: for 0: dbconn1379204259. Stack: >> > -TransactionLegacy.prepareStatement:457-TransactionLegacy. >> > prepareAutoCloseStatement:450-AccountDaoImpl.findUserAccount >> ByApiKey:129- >> > GeneratedMethodAccessor234.invoke:-1-DelegatingMethodAccessorImpl. >> > invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingRef >> lection:317- >> > ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMet >> hodInvocation. >> > proceed:150-TransactionContextInterceptor.invoke:34- >> > ReflectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor. >> > invoke:91 >> > 2016-11-06 09:36:04,895 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) >> Preparing: SELECT >> > u.id, u.username, u.account_id, u.secret_key, u.state, a.id, >> > a.account_name, a.type, a.domain_id, a.state FROM `cloud`.`user` u, >> > `cloud`.`account` a WHERE u.account_id = a.id AND u.api_key = ? and >> > u.removed IS NULL >> > 2016-11-06 09:36:04,895 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Creating a DB connection with no txn: for 0: >> > dbconn710552474. Stack: -TransactionLegacy.prepareStatement:457- >> > TransactionLegacy.prepareAutoCloseStatement:450- >> > GenericDaoBase.findById:1005-GenericDaoBase.lockRow:991- >> > GenericDaoBase.findById:949-GeneratedMethodAccessor42.invoke:-1- >> > DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils. >> > invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation. >> > invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150- >> > TransactionContextInterceptor.invoke:34 >> > 2016-11-06 09:36:04,895 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Preparing: SELECT vm_instance.id, vm_instance.name >> , >> > vm_instance.vnc_password, vm_instance.proxy_id, >> > vm_instance.proxy_assign_time, vm_instance.state, >> vm_instance.private_ip_address, >> > vm_instance.instance_name, vm_instance.vm_template_id, >> > vm_instance.guest_os_id, vm_instance.host_id, >> vm_instance.last_host_id, >> > vm_instance.pod_id, vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = ? AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,896 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Closing: >> > com.mysql.jdbc.PreparedStatement@727fe420: SELECT u.id, u.username, >> > u.account_id, u.secret_key, u.state, a.id, a.account_name, a.type, >> > a.domain_id, a.state FROM `cloud`.`user` u, `cloud`.`account` a >> WHERE >> > u.account_id = a.id AND u.api_key = 'XXXX' and u.removed IS NULL >> > 2016-11-06 09:36:04,897 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Closing DB >> > connection: dbconn1379204259 >> > 2016-11-06 09:36:04,897 TRACE [c.c.u.d.T.Transaction] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Using >> current >> > transaction: http-8080-10 : http-8080-10, >> > 2016-11-06 09:36:04,897 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing: com.mysql.jdbc.JDBC4PreparedSt >> atement@4dff949a: >> > SELECT vm_instance.id, vm_instance.name, vm_instance.vnc_password, >> > vm_instance.proxy_id, vm_instance.proxy_assign_time, >> vm_instance.state, >> > vm_instance.private_ip_address, vm_instance.instance_name, >> > vm_instance.vm_template_id, vm_instance.guest_os_id, >> vm_instance.host_id, >> > vm_instance.last_host_id, vm_instance.pod_id, >> vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = 4130 AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,897 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing DB connection: dbconn710552474 >> > 2016-11-06 09:36:04,898 TRACE [c.c.u.d.T.Transaction] >> > (StatsCollector-2:ctx-293a2a9e) (logid:725b6dd7) Using current >> > transaction: StatsCollector-2 : StatsCollector-2, >> > 2016-11-06 09:36:04,898 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Creating >> a DB >> > connection with no txn: for 0: dbconn1500776736. Stack: >> > -TransactionLegacy.prepareStatement:457-TransactionLegacy. >> > prepareAutoCloseStatement:450-GenericDaoBase.findById:1005-G >> enericDaoBase. >> > findByIdIncludingRemoved:972-GeneratedMethodAccessor115.invoke:-1- >> > DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils. >> > invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation. >> > invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150- >> > TransactionContextInterceptor.invoke:34-ReflectiveMethodInvocation. >> > proceed:161 >> > 2016-11-06 09:36:04,898 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) >> Preparing: SELECT >> > account.id, account.account_name, account.type, account.domain_id, >> > account.state, account.removed, account.cleanup_needed, >> > account.network_domain, account.uuid, account.default_zone_id, >> > account.default FROM account WHERE account.id = ? >> > 2016-11-06 09:36:04,899 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Creating a DB connection with no txn: for 0: >> > dbconn1143455433. Stack: -TransactionLegacy.prepareStatement:457- >> > TransactionLegacy.prepareAutoCloseStatement:450- >> > GenericDaoBase.findById:1005-GenericDaoBase.lockRow:991- >> > GenericDaoBase.findById:949-GeneratedMethodAccessor42.invoke:-1- >> > DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils. >> > invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation. >> > invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150- >> > TransactionContextInterceptor.invoke:34 >> > 2016-11-06 09:36:04,899 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Closing: >> > com.mysql.jdbc.PreparedStatement@7cc28d54: SELECT account.id, >> > account.account_name, account.type, account.domain_id, >> account.state, >> > account.removed, account.cleanup_needed, account.network_domain, >> > account.uuid, account.default_zone_id, account.default FROM account >> WHERE >> > account.id = 2 >> > 2016-11-06 09:36:04,899 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b) (logid:0429eaf0) Closing DB >> > connection: dbconn1500776736 >> > 2016-11-06 09:36:04,899 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Preparing: SELECT vm_instance.id, vm_instance.name >> , >> > vm_instance.vnc_password, vm_instance.proxy_id, >> > vm_instance.proxy_assign_time, vm_instance.state, >> vm_instance.private_ip_address, >> > vm_instance.instance_name, vm_instance.vm_template_id, >> > vm_instance.guest_os_id, vm_instance.host_id, >> vm_instance.last_host_id, >> > vm_instance.pod_id, vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = ? AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,900 TRACE [c.c.u.d.T.Transaction] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Using current transaction: http-8080-10 : http-8080-10, >> > 2016-11-06 09:36:04,900 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing: com.mysql.jdbc.JDBC4PreparedSt >> atement@1259275a: >> > SELECT vm_instance.id, vm_instance.name, vm_instance.vnc_password, >> > vm_instance.proxy_id, vm_instance.proxy_assign_time, >> vm_instance.state, >> > vm_instance.private_ip_address, vm_instance.instance_name, >> > vm_instance.vm_template_id, vm_instance.guest_os_id, >> vm_instance.host_id, >> > vm_instance.last_host_id, vm_instance.pod_id, >> vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = 4191 AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,901 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing DB connection: dbconn1143455433 >> > 2016-11-06 09:36:04,901 TRACE [c.c.u.d.T.Transaction] >> > (StatsCollector-2:ctx-293a2a9e) (logid:725b6dd7) Using current >> > transaction: StatsCollector-2 : StatsCollector-2, >> > 2016-11-06 09:36:04,901 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Creating a DB connection with no txn: for 0: dbconn1688317537. >> Stack: >> > -TransactionLegacy.prepareStatement:457-TransactionLegacy. >> > prepareAutoCloseStatement:450-GenericDaoBase.findById:1005- >> > GenericDaoBase.lockRow:991-GenericDaoBase.findById:949- >> > GeneratedMethodAccessor42.invoke:-1-DelegatingMethodAccessorImpl. >> > invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingRef >> lection:317- >> > ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMet >> hodInvocation. >> > proceed:150-TransactionContextInterceptor.invoke:34 >> > 2016-11-06 09:36:04,901 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Preparing: SELECT account.id, account.account_name, account.type, >> > account.domain_id, account.state, account.removed, >> account.cleanup_needed, >> > account.network_domain, account.uuid, account.default_zone_id, >> > account.default FROM account WHERE account.id = ? AND >> account.removed IS >> > NULL >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.d.T.Statement] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Closing: com.mysql.jdbc.JDBC4PreparedStatement@7efdf10: SELECT >> account.id, >> > account.account_name, account.type, account.domain_id, >> account.state, >> > account.removed, account.cleanup_needed, account.network_domain, >> > account.uuid, account.default_zone_id, account.default FROM account >> WHERE >> > account.id = 2 AND account.removed IS NULL >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.d.T.Connection] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Closing DB connection: dbconn1688317537 >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Creating a DB connection with no txn: for 0: >> > dbconn1632185236. Stack: -TransactionLegacy.prepareStatement:457- >> > TransactionLegacy.prepareAutoCloseStatement:450- >> > GenericDaoBase.findById:1005-GenericDaoBase.lockRow:991- >> > GenericDaoBase.findById:949-GeneratedMethodAccessor42.invoke:-1- >> > DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils. >> > invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation. >> > invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150- >> > TransactionContextInterceptor.invoke:34 >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.AccountManagerImpl] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) Root >> > Access granted to Acct[0bb6751b-eaa1-11e2-b078-6d70ed52d122-admin] >> by >> > AffinityGroupAccessChecker >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Preparing: SELECT vm_instance.id, vm_instance.name >> , >> > vm_instance.vnc_password, vm_instance.proxy_id, >> > vm_instance.proxy_assign_time, vm_instance.state, >> vm_instance.private_ip_address, >> > vm_instance.instance_name, vm_instance.vm_template_id, >> > vm_instance.guest_os_id, vm_instance.host_id, >> vm_instance.last_host_id, >> > vm_instance.pod_id, vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = ? AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,902 TRACE [c.c.u.d.T.Transaction] >> > (http-8080-10:ctx-3f3ff343 ctx-e486fd2b ctx-f5ec429d) >> (logid:0429eaf0) >> > Using current transaction: http-8080-10 : http-8080-10, >> > 2016-11-06 09:36:04,903 TRACE [c.c.u.d.T.Statement] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing: com.mysql.jdbc.JDBC4PreparedSt >> atement@107795cb: >> > SELECT vm_instance.id, vm_instance.name, vm_instance.vnc_password, >> > vm_instance.proxy_id, vm_instance.proxy_assign_time, >> vm_instance.state, >> > vm_instance.private_ip_address, vm_instance.instance_name, >> > vm_instance.vm_template_id, vm_instance.guest_os_id, >> vm_instance.host_id, >> > vm_instance.last_host_id, vm_instance.pod_id, >> vm_instance.private_mac_address, >> > vm_instance.data_center_id, vm_instance.vm_type, >> vm_instance.ha_enabled, >> > vm_instance.display_vm, vm_instance.limit_cpu_use, >> > vm_instance.update_count, vm_instance.created, vm_instance.removed, >> > vm_instance.update_time, vm_instance.domain_id, >> vm_instance.account_id, >> > vm_instance.user_id, vm_instance.service_offering_id, >> > vm_instance.reservation_id, vm_instance.hypervisor_type, >> > vm_instance.dynamically_scalable, vm_instance.uuid, >> > vm_instance.disk_offering_id, vm_instance.power_state, >> > vm_instance.power_state_update_time, vm_instance.power_state_update >> _count, >> > vm_instance.power_host, user_vm.iso_id, user_vm.user_data, >> > user_vm.display_name, user_vm.update_parameters FROM user_vm INNER >> JOIN >> > vm_instance ON user_vm.id=vm_instance.id WHERE >> vm_instance.type='User' >> > AND user_vm.id = 4221 AND vm_instance.removed IS NULL >> > 2016-11-06 09:36:04,904 TRACE [c.c.u.d.T.Connection] >> (StatsCollector-2:ctx-293a2a9e) >> > (logid:725b6dd7) Closing DB connection: dbconn1632185236 >> > >> > >> > >> > On Sun, Nov 6, 2016 at 9:37 AM, Sergey Levitskiy < >> > sergey.levits...@autodesk.com> wrote: >> > >> >> Please change DEBUG to TRACE for the following classes so they >> look like >> >> below. You don’t need to restart Cloudstack since it will >> dynamically >> >> switch log level. Once switched it will start generating enormous >> amount of >> >> logging so once you capture the slowness switch it back to DEBUG. >> >> >> >> <category name="com.cloud"> >> >> <priority value="TRACE"/> >> >> </category> >> >> >> >> <category name="org.apache.cloudstack"> >> >> <priority value="TRACE"/> >> >> </category> >> >> >> >> >> >> Thanks, >> >> Sergey >> >> >> >> >> >> >> >> >> >> On 11/5/16, 6:11 PM, "Cloud List" <cloud-l...@sg.or.id> wrote: >> >> >> >> Hi Sergey, >> >> >> >> Thanks for your reply. May I know logging for which class I >> need to >> >> modify >> >> to TRACE? Is it for the c.c.a.ApiServelet class? Not too sure >> what >> >> does the >> >> c.c.a stands for -- how do I check that? So I can put the >> correct >> >> full name >> >> of the class category on /etc/cloudstack/management/log >> 4j-cloud.xml. >> >> >> >> Looking forward to your reply, thank you. >> >> >> >> Cheers. >> >> >> >> >> >> On Sun, Nov 6, 2016 at 5:50 AM, Sergey Levitskiy < >> >> sergey.levits...@autodesk.com> wrote: >> >> >> >> > You will probably need to enable TRACE logging and see what >> SQL >> >> query took >> >> > long time to execute. >> >> > >> >> > On 11/5/16, 1:21 PM, "Cloud List" <cloud-l...@sg.or.id> >> wrote: >> >> > >> >> > Hi, >> >> > >> >> > We have upgraded ACS from 4.2 to 4.8.1.1. We noted that a >> >> > "listDomains" API >> >> > call from our billing system took 21 seconds for our >> CloudStack >> >> to >> >> > reply, >> >> > resulting in time-out. >> >> > >> >> > ==== >> >> > 2016-11-06 03:40:42,891 DEBUG [c.c.a.ApiServlet] >> >> > (http-8080-2:ctx-faa0bcbd) >> >> > (logid:86b581fc) ===START=== X.X.X.X -- GET >> >> > apikey=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX& >> command= >> >> > listDomains&response=json&signature=YYYYYYYYYYYYYYYYYYY >> >> > 2016-11-06 03:41:03,850 DEBUG [c.c.a.ApiServlet] >> >> > (http-8080-2:ctx-faa0bcbd >> >> > ctx-5653f761 ctx-cb1e1f59) (logid:86b581fc) ===END=== >> X.X.X.X >> >> -- GET >> >> > apikey=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX& >> command= >> >> > listDomains&response=json&signature=YYYYYYYYYYYYYYYYYYY >> >> > ==== >> >> > >> >> > Any advice on what caused the delay in the API reply and >> how we >> >> can >> >> > expedite? >> >> > >> >> > Thank you. >> >> > >> >> > >> >> > >> >> >> >> >> >> >> > >> >> >> >
