Hi all,
in a recente ACS 4.11.2.0 installation (Ubuntu 16.04 + KVM + Advanced
network) I have some problems in cloudstack usage.
During the usual operations, I find a slowdown in the responses of the
UI and occasionally errors.
This morning I created a new VM and I assigned an IP (xx.xx.xx.xx) of
a specific network (net-name).
The UI has stopped in the assignment phase even if in the logs (which
I report at the bottom of the email) I see that the job is executed in
a few seconds and updating the list of associated IPs in the network
list I see that the association is correct.
I noticed that a series of these messages appear in the mysql log:
2019-02-06T00:50:58.758699Z 6298 [Note] Aborted connection 6298 to db:
'dbname' user: 'username' host: 'localhost' (Got timeout reading
communication packets) 2019-02-06T00:51:59.352203Z 6269 [Note] Aborted
connection 6269 to db:
'dbname' user: 'username' host: 'localhost' (Got timeout reading
communication packets) 2019-02-06T00:51:59.421092Z 6289 [Note] Aborted
connection 6289 to db:
'dbname' user: 'username' host: 'localhost' (Got timeout reading
communication packets) 2019-02-06T08:00:35.717673Z 6101 [Note] Aborted
connection 6101 to db:
'dbname_usage' user: 'username' host: 'localhost' (Got timeout reading
communication packets
Note that the mysql server is used only by cloustack and is configured
according to the instructions in the cloudstack manual.
I've already had a number of similar problems before (the version of
ACS was 4.11.1) and the situation has been getting worse and worse
until the interface and the whole cloudstack system has stopped
working (see "URGENT: Unable to schedule async job for command
com.cloud.vm.VmWorkStart, unexpected exception" and "urgent: Unable to
apply firewall rules on router").
Has anyone had similar experiences or can help me understand where the
problem is?
Job log (extracted from management-server.log):
2019-02-06 10:21:07,282 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-6:ctx-5d20ed8a job-876) (logid:130cd0a6) Add job-876
into job monitoring 2019-02-06 10:21:07,294 DEBUG
[o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:ctx-5d20ed8a
job-876) (logid:ce8dc8fb) Executing AsyncJobVO {id:876, userId: 2,
accountId: 2, instanceType: IpAddress, instanceId: 31, cmd:
org.apache.cloudstack.api.command.admin.address.AssociateIPAddrCmdByAd
min,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","networkid":"bc0
cc3a2-e21f-4904-a826-04477b1805c0","ctxStartEventId":"2308","id":"31",
"ctxDetails":"{\"interface
com.cloud.network.IpAddress\":\"a710fbad-c2e5-409a-bd97-884e2d0ab7a5\"
,\"interface
com.cloud.network.Network\":\"bc0cc3a2-e21f-4904-a826-04477b1805c0\"}"
,"ctxAccountId":"2","uuid":"a710fbad-c2e5-409a-bd97-884e2d0ab7a5","cmd
EventType":"NET.IPASSIGN","_":"1549444854378"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null} 2019-02-06
10:21:07,295 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-521:ctx-31017793 ctx-63a1f58b) (logid:601bc8dd) submit
async job-876, details: AsyncJobVO {id:876, userId: 2, accountId: 2,
instanceType: IpAddress, instanceId: 31, cmd:
org.apache.cloudstack.api.command.admin.address.AssociateIPAddrCmdByAd
min,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","networkid":"bc0
cc3a2-e21f-4904-a826-04477b1805c0","ctxStartEventId":"2308","id":"31",
"ctxDetails":"{\"interface
com.cloud.network.IpAddress\":\"a710fbad-c2e5-409a-bd97-884e2d0ab7a5\"
,\"interface
com.cloud.network.Network\":\"bc0cc3a2-e21f-4904-a826-04477b1805c0\"}"
,"ctxAccountId":"2","uuid":"a710fbad-c2e5-409a-bd97-884e2d0ab7a5","cmd
EventType":"NET.IPASSIGN","_":"1549444854378"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null} 2019-02-06
10:21:07,354 DEBUG [c.c.n.IpAddressManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Associating ip Ip[xx.xx.xx.xx-1] to network
Ntwk[206|Guest|8] 2019-02-06 10:21:07,419 DEBUG
[c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-6:ctx-5d20ed8a
job-876 ctx-462aefc2) (logid:ce8dc8fb) Updating resource Type =
public_ip count for Account = 2 Operation = increasing Amount = 1
2019-02-06 10:21:07,426 DEBUG [c.c.n.IpAddressManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Successfully associated ip address xx.xx.xx.xx to
network Ntwk[206|Guest|8] 2019-02-06 10:21:07,439 DEBUG
[o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:ctx-5d20ed8a
job-876 ctx-462aefc2) (logid:ce8dc8fb) Complete async job-876,
jobStatus: SUCCEEDED, resultCode: 0, result:
org.apache.cloudstack.api.response.IPAddressResponse/ipaddress/{"id":"
a710fbad-c2e5-409a-bd97-884e2d0ab7a5","ipaddress":"xx.xx.xx.xx","alloc
ated":"2019-02-06T10:21:07+0100","zoneid":"f8d175fa-e4cc-4259-8c44-f88
d7d429107","zonename":"somezone","issourcenat":false,"account":"admin"
,"domainid":"165f090c-ffa3-11e8-bcb0-c8cbb8cb15cd","domain":"ROOT","fo
rvirtualnetwork":true,"vlanid":"db86f7ae-6285-4beb-8e11-30e2a516e7e4",
"vlanname":"vlan://untagged","isstaticnat":false,"issystem":false,"ass
ociatednetworkid":"bc0cc3a2-e21f-4904-a826-04477b1805c0","associatedne
tworkname":"net-name","networkid":"0b8de733-b587-472b-b2c9-6944f45410d
6","state":"Allocating","physicalnetworkid":"5cdff050-9cdc-4ffb-aa1f-7
8d2eeb7e28b","tags":[],"isportable":false,"fordisplay":true}
2019-02-06 10:21:07,441 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Publish async job-876 complete on message bus
2019-02-06 10:21:07,441 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Wake up jobs related to job-876 2019-02-06
10:21:07,441 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Update db status for job-876 2019-02-06 10:21:07,442
DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-5d20ed8a job-876 ctx-462aefc2)
(logid:ce8dc8fb) Wake up jobs joined with job-876 and disjoin all
subjobs created from job- 876 2019-02-06 10:21:07,446 DEBUG
[o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:ctx-5d20ed8a
job-876) (logid:ce8dc8fb) Done executing
org.apache.cloudstack.api.command.admin.address.AssociateIPAddrCmdByAd
min for job-876 2019-02-06 10:21:07,447 INFO
[o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-6:ctx-5d20ed8a
job-876) (logid:ce8dc8fb) Remove
job-876 from job monitoring
