cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Wei ZHOU <ustcweiz...@gmail.com>
Subject Re: Long delay in listDomains API response
Date Sun, 06 Nov 2016 16:42:07 GMT
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-list@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.Levitskiy@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-list@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-list@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.Levitskiy@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-list@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.Levitskiy@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-list@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.
>>     >>     >
>>     >>     >
>>     >>     >
>>     >>
>>     >>
>>     >>
>>     >
>>
>>
>>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message