Hi Wei, Thanks for your reply. Is it possible for us to remove the resource limitation feature -- any global settings that we can set to turn this off? If not, would you be able to let us know where on the source code this is being set, so that we can try changing it and recompile ACS to turn off the feature?
If it's possible, how would be the impact to CloudStack operations in general? May I know what was the original purpose the limitation is being put in the first place? Thanks for the workaround recommendation -- will forward to our application vendor to see if the app can be fine-tuned following your recommendation. Looking forward to your reply, thank you. Cheers. On Mon, Nov 7, 2016 at 12:42 AM, Wei ZHOU <ustcweiz...@gmail.com> wrote: > 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-ExposeInvocationInter >>> ceptor. >>> > 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-ReflectiveMethodInvo >>> cation. >>> > 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=XXXXXXXXXXXXXXXXXXXXXX >>> XXXXXXXXXXXXXXXXXXXXXXXX&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=XXXXXXXXXXXXXXXXXXXXXX >>> XXXXXXXXXXXXXXXXXXXXXXXX&command= >>> >> > listDomains&response=json&signature=YYYYYYYYYYYYYYYYYYY >>> >> > ==== >>> >> > >>> >> > Any advice on what caused the delay in the API reply >>> and how we >>> >> can >>> >> > expedite? >>> >> > >>> >> > Thank you. >>> >> > >>> >> > >>> >> > >>> >> >>> >> >>> >> >>> > >>> >>> >>> >> >
