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.JDBC4PreparedStatement@ > 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. > findUserAccountByApiKey:129- > > GeneratedMethodAccessor234.invoke:-1-DelegatingMethodAccessorImpl. > > invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection > :317- > > ReflectiveMethodInvocation.invokeJoinpoint:183- > ReflectiveMethodInvocation. > > 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.JDBC4PreparedStatement@ > 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- > GenericDaoBase. > > 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.JDBC4PreparedStatement@ > 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.invokeJoinpointUsingReflection > :317- > > ReflectiveMethodInvocation.invokeJoinpoint:183- > ReflectiveMethodInvocation. > > 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.JDBC4PreparedStatement@ > 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/ > log4j-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=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXX > XXXXXXXXXXXXXXXX&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=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXX > XXXXXXXXXXXXXXXX&command= > >> > listDomains&response=json&signature=YYYYYYYYYYYYYYYYYYY > >> > ==== > >> > > >> > Any advice on what caused the delay in the API reply and > how we > >> can > >> > expedite? > >> > > >> > Thank you. > >> > > >> > > >> > > >> > >> > >> > > > > >
