Hello,
The console access now fails on KVM hosts after upgrading from ACS 4.17.2 to
ACS 4.18.1
The console has been working flawlessly on 4.17.2 with SSL and
www-xxx-yyy-zzz.domain.com configuration.
I see some authentication and loading resource issues in the following Proxy
logs. Everything else works well, including the console access on Xen hosts.
The firewall on the host is disabled, times are synced, the management server
is using the local time zone, and the KVM hosts are using UTC.
What am I missing?
Regards,
Antoine
Note: The KVM host IP has been changed to 10.xx.xx.xx
MANAGEMENT SERVER LOGS
2024-01-14 23:57:20,027 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) (logid:) SeqA 104-3099: Processing Seq 104-3099:
{ Cmd , MgmtId: -1, via: 104, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"493","_loadInfo":"{
"connections": [],
"removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-01-14 23:57:20,032 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) (logid:) SeqA 104-3099: Sending Seq 104-3099: {
Ans: , MgmtId: 130593671224, via: 104, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:21,363 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-5:null) (logid:) SeqA 102-2964: Processing Seq 102-2964:
{ Cmd , MgmtId: -1, via: 102, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"488","_loadInfo":"{
"connections": [],
"removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-01-14 23:57:21,367 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-5:null) (logid:) SeqA 102-2964: Sending Seq 102-2964: {
Ans: , MgmtId: 130593671224, via: 102, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:23,558 DEBUG [c.c.a.ApiServlet]
(qtp279593458-695:ctx-2e31e696) (logid:a3f76229) ===START=== 104.28.133.19 --
GET
virtualmachineid=bca11a2a-f642-4ded-a8d8-809a046de56b&command=createConsoleEndpoint&response=json
2024-01-14 23:57:23,559 DEBUG [c.c.a.ApiServlet]
(qtp279593458-695:ctx-2e31e696) (logid:a3f76229) Two factor authentication is
already verified for the user 2, so skipping
2024-01-14 23:57:23,574 DEBUG [c.c.a.ApiServer] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) CIDRs from which account 'Account
[{"accountName":"admin","id":2,"uuid":"2cee75f9-8bc4-11ec-9c43-001e67fd4838"}]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2024-01-14 23:57:23,579 INFO [o.a.c.a.DynamicRoleBasedAPIAccessChecker]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Account [Account
[{"accountName":"admin","id":2,"uuid":"2cee75f9-8bc4-11ec-9c43-001e67fd4838"}]]
is Root Admin or Domain Admin, all APIs are allowed.
2024-01-14 23:57:23,581 WARN [o.a.c.a.ProjectRoleBasedApiAccessChecker]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Project is null,
ProjectRoleBasedApiAccessChecker only applies to projects, returning API
[createConsoleEndpoint] for user [User
{"username":"admin","uuid":"2cefb708-8bc4-11ec-9c43-001e67fd4838"}.] as allowed.
2024-01-14 23:57:23,591 WARN [c.c.a.d.ParamGenericValidationWorker]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Received unknown
parameters for command createConsoleEndpoint. Unknown parameters :
client-inet-address
2024-01-14 23:57:23,607 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Assign previous
allocated console proxy for user vm : 59
2024-01-14 23:57:23,614 DEBUG [c.c.a.t.Request] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) Seq 59-4686558362232422593: Sending { Cmd ,
MgmtId: 130593671224, via: 59(cs-kvm01), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.GetVncPortCommand":{"id":"59","name":"i-11-59-VM","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:23,679 DEBUG [c.c.a.t.Request] (AgentManager-Handler-7:null)
(logid:) Seq 59-4686558362232422593: Processing: { Ans: , MgmtId:
130593671224, via: 59, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.GetVncPortAnswer":{"address":"10.xxx.xxx.xxx","port":"5905","result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:23,680 DEBUG [c.c.a.t.Request] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) Seq 59-4686558362232422593: Received: { Ans: ,
MgmtId: 130593671224, via: 59(cs-kvm01), Ver: v1, Flags: 10, { GetVncPortAnswer
} }
2024-01-14 23:57:23,680 INFO [o.a.c.c.ConsoleAccessManagerImpl]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Parse host info
returned from executing GetVNCPortCommand. host info: 10.xxx.xxx.xxx
2024-01-14 23:57:23,769 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Assign previous
allocated console proxy for user vm : 59
2024-01-14 23:57:23,774 DEBUG [c.c.a.t.Request] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) Seq 102-5612892510587191300: Sending { Cmd ,
MgmtId: 130593671224, via: 102(v-488-VM), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.proxy.AllowConsoleAccessCommand":{"sessionUuid":"d7e6f73b-230a-43b7-95dc-dfc20c2f8992","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:23,817 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:null)
(logid:) Seq 102-5612892510587191300: Processing: { Ans: , MgmtId:
130593671224, via: 102, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:23,817 DEBUG [c.c.a.t.Request] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) Seq 102-5612892510587191300: Received: { Ans: ,
MgmtId: 130593671224, via: 102(v-488-VM), Ver: v1, Flags: 10, { Answer } }
2024-01-14 23:57:23,829 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(qtp279593458-695:ctx-2e31e696 ctx-ced9fb8e) (logid:a3f76229) Assign previous
allocated console proxy for user vm : 59
2024-01-14 23:57:23,833 DEBUG [c.c.a.ApiServlet] (qtp279593458-695:ctx-2e31e696
ctx-ced9fb8e) (logid:a3f76229) ===END=== 104.28.133.19 -- GET
virtualmachineid=bca11a2a-f642-4ded-a8d8-809a046de56b&command=createConsoleEndpoint&response=json
2024-01-14 23:57:24,738 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-15:null) (logid:) SeqA 102-2965: Processing Seq 102-2965:
{ Cmd , MgmtId: -1, via: 102, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleAccessAuthenticationCommand":{"_host":"10.xxx.xxx.xxx","_port":"5905","_vmId":"bca11a2a-f642-4ded-a8d8-809a046de56b","_sid":"UysC5FUxYMMtUvYBlzJLSQ","_ticket":"4ywKfs2GYjKVD+CkRYFseKlsBVJwGdfWWlDN/Vp3llos2plRn2Ek4lxkOgMzMkmuhcBTk998OE3j9n7/S7yUpw==","sessionUuid":"d7e6f73b-230a-43b7-95dc-dfc20c2f8992","_isReauthenticating":"false","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:24,740 DEBUG [c.c.c.AgentHookBase]
(AgentManager-Handler-15:null) (logid:) Console authentication. Ticket in url
for 10.xxx.xxx.xxx:5905-bca11a2a-f642-4ded-a8d8-809a046de56b is
4ywKfs2GYjKVD+CkRYFseKlsBVJwGdfWWlDN/Vp3llos2plRn2Ek4lxkOgMzMkmuhcBTk998OE3j9n7/S7yUpw==
2024-01-14 23:57:24,741 DEBUG [c.c.c.AgentHookBase]
(AgentManager-Handler-15:null) (logid:) Console authentication. Ticket in 1
minute boundary for 10.xxx.xxx.xxx:5905-bca11a2a-f642-4ded-a8d8-809a046de56b is
4ywKfs2GYjKVD+CkRYFseKlsBVJwGdfWWlDN/Vp3llos2plRn2Ek4lxkOgMzMkmuhcBTk998OE3j9n7/S7yUpw==
2024-01-14 23:57:24,744 DEBUG [c.c.c.AgentHookBase]
(AgentManager-Handler-15:null) (logid:) Acquiring session
[d7e6f73b-230a-43b7-95dc-dfc20c2f8992] as it was just used.
2024-01-14 23:57:24,761 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-15:null) (logid:) SeqA 102-2965: Sending Seq 102-2965: {
Ans: , MgmtId: 130593671224, via: 102, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.ConsoleAccessAuthenticationAnswer":{"_success":"true","_isReauthenticating":"false","_port":"0","result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:24,850 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-6:null) (logid:) SeqA 102-2966: Processing Seq 102-2966:
{ Cmd , MgmtId: -1, via: 102, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"488","_loadInfo":"{
"connections": [
{
"id": 13,
"clientInfo": "",
"host": "10.xxx.xxx.xxx",
"port": 5905,
"tag": "bca11a2a-f642-4ded-a8d8-809a046de56b",
"createTime": 1705294644803,
"lastUsedTime": 1705294644803,
"sessionUuid": "d7e6f73b-230a-43b7-95dc-dfc20c2f8992"
}
]
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-01-14 23:57:24,855 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-6:null) (logid:) SeqA 102-2966: Sending Seq 102-2966: {
Ans: , MgmtId: 130593671224, via: 102, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:30,026 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 104-3100: Processing Seq 104-3100:
{ Cmd , MgmtId: -1, via: 104, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"493","_loadInfo":"{
"connections": [],
"removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-01-14 23:57:30,030 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-14:null) (logid:) SeqA 104-3100: Sending Seq 104-3100: {
Ans: , MgmtId: 130593671224, via: 104, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-01-14 23:57:31,364 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) (logid:) SeqA 102-2967: Processing Seq 102-2967:
{ Cmd , MgmtId: -1, via: 102, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"488","_loadInfo":"{
"connections": [
{
"id": 13,
"clientInfo": "",
"host": "10.xxx.xxx.xxx",
"port": 5905,
"tag": "bca11a2a-f642-4ded-a8d8-809a046de56b",
"createTime": 1705294644803,
"lastUsedTime": 1705294644803,
"sessionUuid": "d7e6f73b-230a-43b7-95dc-dfc20c2f8992"
}
],
"removedSessions": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2024-01-14 23:57:31,368 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) (logid:) SeqA 102-2967: Sending Seq 102-2967: {
Ans: , MgmtId: 130593671224, via: 102, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
CONSOLE PROXY LOGS
2024-01-15 04:57:24,497 INFO [cloud.consoleproxy.ConsoleProxyResourceHandler]
(Thread-175:null) Get resource request for /resource/noVNC/vnc.html
2024-01-15 04:57:24,506 INFO [cloud.consoleproxy.ConsoleProxyResourceHandler]
(Thread-175:null) Sent file /resource/noVNC/vnc.html with content type text/html
2024-01-15 04:57:24,630 INFO [cloud.consoleproxy.ConsoleProxyResourceHandler]
(Thread-176:null) Get resource request for /resource/noVNC/app/sounds/bell.mp3
2024-01-15 04:57:24,635 INFO [cloud.consoleproxy.ConsoleProxyResourceHandler]
(Thread-176:null) Sent file /resource/noVNC/app/sounds/bell.mp3 with content
type application/octet-stream
2024-01-15 04:57:24,735 INFO [cloud.consoleproxy.ConsoleProxyNoVNCHandler]
(qtp1640959236-39:null) Get websocket connection request from remote IP :
104.28.133.19
2024-01-15 04:57:24,810 INFO [cloud.consoleproxy.ConsoleProxyNoVncClient]
(Thread-177:null) Connect to VNC server directly. host: 10.xxx.xxx.xxx, port:
5905
2024-01-15 04:57:24,815 INFO [consoleproxy.vnc.NoVncClient] (Thread-177:null)
Connecting to VNC server 10.xxx.xxx.xxx:5905 ...
2024-01-15 04:57:25,028 INFO [vnc.security.VncAuthSecurity] (Thread-177:null)
VNC server requires password authentication
2024-01-15 04:57:25,041 INFO [vnc.security.VncAuthSecurity] (Thread-177:null)
Finished VNCAuth security
Antoine Boucher
