특정 Group이 제거됨으로써, vCenter UI에 접근하지 못하는 증상을 Troubleshooting한 내용에 대해 다뤄봅니다.
## vCenter 6.7
vCenter UI에 접속할 때, 다음과 같이 "vCenter Single Sign-On 서버 https://vcenter_ip_address/sts/STSService/vsphere.local에 연결할 수 없습니다." 오류와 함께 접속이 실패한 사례가 있습니다.
분석에 필요한 SSO Logon Flow Architecture Diagram 입니다.
우선 vSphere UI 로그(/var/log/vmware/vsphere-ui/logs/vsphere_client_virgo.log)를 확인해야 합니다.
아래 로그를 보면, STS Server로부터 Security Token을 획득하는 과정이 실패하는 것을 알 수 있습니다.
| [ERROR] tokenAcqExec-990786 70955875 131281 ###### com.vmware.vise.vim.security.sso.AsyncTokenManager Token acquisition failed for SSO domain vsphere.local(b4a5f030-b2e9-11eb-9b8e-000c29280135@L) from STS server https://vcenter/sts/STSService/vsphere.local com.vmware.vise.vim.security.sso.exception.SsoServiceException: com.vmware.vim.sso.client.exception.InvalidTokenRequestException: Request is invalid: ns0:InvalidRequest: Access not authorized! |
STS 서비스 상태를 확인하기 위해 /var/log/vmware/sso/vmware-identity-sts.log를 확인했지만 유용한 내용을 확인할 수 없었습니다.
그 다음 SSO 로그(/var/log/vmware/sso/websso.log)를 확인했을 때, ldap(tcp/389)에 연결 실패 메시지를 확인할 수 있습니다.
| [tomcat-http--3 vsphere.local 8ffa18f5-6704-4907-9207-a1dcdebaf7bd WARN com.vmware.identity.interop.ldap.LdapErrorChecker] Error received by LDAP client: com.vmware.identity.interop.ldap.OpenLdapClientLibrary, error code: 49 [tomcat-http--3 vsphere.local 8ffa18f5-6704-4907-9207-a1dcdebaf7bd WARN com.vmware.identity.idm.server.ServerUtils] cannot bind connection: [ldap://vCenter:389, CN=abc,OU=ServiceAccounts,DC=xxx,DC=yyy] [tomcat-http--3 vsphere.local 8ffa18f5-6704-4907-9207-a1dcdebaf7bd ERROR com.vmware.identity.idm.server.ServerUtils] cannot establish connection with uri: ldap://vcenter:389 |
connection bind 실패 메시지를 확인했으므로, 그 다음에는 실제 tcp/389가 정상적으로 listening 중인지 확인해야 합니다.
tcp/389를 listening하고 있는 프로세스는 vmdird인 것을 확인할 수 있습니다.
| Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 127.0.0.1:8201 0.0.0.0:* LISTEN 4094/python tcp 0 0 0.0.0.0:1514 0.0.0.0:* LISTEN 3888/rsyslogd tcp 0 0 127.0.0.1:18091 0.0.0.0:* LISTEN 3006/vmware-sca.lau … tcp 0 0 0.0.0.0:9090 0.0.0.0:* LISTEN 3009/vsphere-client tcp 0 0 0.0.0.0:514 0.0.0.0:* LISTEN 3888/rsyslogd tcp 0 0 0.0.0.0:5090 0.0.0.0:* LISTEN 3008/vsphere-ui.lau tcp 0 0 0.0.0.0:9443 0.0.0.0:* LISTEN 3009/vsphere-client tcp 0 0 0.0.0.0:5443 0.0.0.0:* LISTEN 3008/vsphere-ui.lau tcp 0 0 0.0.0.0:2020 0.0.0.0:* LISTEN 1618/vmafdd tcp 0 0 127.0.0.1:549 0.0.0.0:* LISTEN 2823/rhttpproxy tcp 0 0 0.0.0.0:389 0.0.0.0:* LISTEN 1691/vmdird tcp 0 0 127.0.0.1:8006 0.0.0.0:* LISTEN 6866/python tcp 0 0 0.0.0.0:15080 0.0.0.0:* LISTEN 2583/vmware-analyti tcp 0 0 0.0.0.0:7080 0.0.0.0:* LISTEN 2020/vmware-stsd |
tcp/389가 정상적으로 listening하고 있으므로, vmdird 서비스에 문제가 없는지 분석이 필요합니다.
vmdird 서비스 로그(/var/log/vmware/vmdird/vmdird-syslog.log)를 확인해보면, 다음과 같이 vmdird 로그에도 bind 관련 오류가 기록되어 있습니다.
로그 내용을 보면, SASL(Simple Authentication and Security Layer) 과정에서 인증 오류가 기록되고 그 후에 ldap bind request가 실패하는 것을 볼 수 있습니다.
| err vmdird t@140132837488384: SASLSessionStep: sasl error (-13)(SASL(-13): authentication failure: client evidence does not match what we calculated. Probably a password error) err vmdird t@140132837488384: VmDirSendLdapResult: Request (Bind), Error (49), Message ((49)(SASL step failed.)), (0) socket (127.0.0.1) err vmdird t@140132837488384: Bind Request Failed (127.0.0.1) error 49: Protocol version: 3, Bind DN: "CN=abc,CN=Users,DC=vsphere,DC=local", Method: SASL |
Research 결과, https://kb.vmware.com/s/article/70756 KB가 해당 메시지를 다루고 있어 1차적으로 Machine Account Password를 Reset 해봅니다.
Reset 후에 SASL 과정의 인증 오류는 더 이상 기록되지 않으나, vCenter UI는 계속해서 접속이 되지 않는 상태입니다.
다시 vCenter UI 로그로 돌아와서 분석을 시작합니다.
사용자가 vCenter UI에 접속한 후 ID/PW까지는 입력한 후에 문제가 발생하기 때문에, 로그인 과정을 다시 살펴봅니다.
administrator@vshpere.local 계정으로 로그인 한 후에 websso 인증은 성공했다고 기록되어 있습니다.
이 후 token을 발급한 후 exchange 하는 과정 중 "Access not authorized" 메시지가 발생합니다.
| [INFO ] http-nio-5090-exec-1 70000126 100046 ###### com.vmware.identity.websso.client.SsoValidationState NameID: Administrator@VSPHERE.LOCAL [INFO ] http-nio-5090-exec-1 70000126 100046 ###### com.vmware.vsphere.client.security.websso.LogonProcessorImpl Websso authentication successful. [INFO ] http-nio-5090-exec-1 70000126 100046 ###### com.vmware.vsphere.client.security.sso.SsoAuthenticationHandler Exchanging the websso token for a Hok token. [INFO ] tokenAcqExec-73 70000126 100046 ###### com.vmware.vise.vim.security.sso.impl.SsoLsLocatorImpl Retrieved locations of services from LS at https://vcenter:443/lookupservice/sdk in 3 milliseconds: [INFO ] tokenAcqExec-73 70000126 100046 ###### com.vmware.vise.vim.security.sso.impl.SsoUtilInternal Exchanging token _6960d364-3515-4514-87f1-5006fd93f6dd for a new one using https://vcenter/sts/STSService/vsphere.local from domain vsphere.local(b4a5f030-b2e9-11eb-9b8e-000c29280135@L) [INFO ] tokenAcqExec-73 70000126 100046 ###### c.v.v.s.c.impl.SecurityTokenServiceImpl$RequestResponseProcessor Request is invalid: ns0:InvalidRequest: Access not authorized! |
내부적으로 Research 결과, 이러한 현상은 vCenter의 VMDIR에 생성된 Group 중 ActAsUser라는 이름의 Group이 사라진 경우 발생할 수 있는 것으로 파악됩니다.
이에 실제로 VMDIR에 ActAsUser Group이 없는지를 확인하기 위해 JXplorer(http://jxplorer.org/downloads/users.html)를 이용합니다.
JXplorer는 표준 LDAP Protocol을 이용하므로, VMDIR이 LDAP 기반으로 작성된 서비스이기 때문에 JXplorer를 이용하여 접속이 가능합니다.
문제가 있는 vCenter에 JXplorer로 접속하여 살펴보면 ActAsUser Group(정확히는 Container)가 보이지 않습니다.
검증을 위해, 테스트 vCenter에 동일하게 JXplorer를 통해 접속해보면 다음과 같이 ActAsUser Group이 최상위에 존재하는 것을 확인할 수 있습니다.
ActAsUser Container에는 member property로 vCenter에서 제공하는 서비스를 위한 Solution User 계정들도 등록되어 있습니다.
문제 증상 조치를 위해서 vCenter에 ActAsUser Group와 Solution Users를 수동으로 생성합니다.
| /usr/lib/vmware-vmafd/bin/dir-cli ssogroup create --name ActAsUsers /usr/lib/vmware-vmafd/bin/dir-cli group modify --name ActAsUsers --add vpxd-extension-<machine id> /usr/lib/vmware-vmafd/bin/dir-cli group modify --name ActAsUsers --add vsphere-webclient-<machine id> |
위 명령어에서 machine id 값은 아래 명령어로 구할 수 있습니다.
| /usr/lib/vmware-vmafd/bin/vmafd-cli get-machine-id --server-name localhost |
위 Action Plan을 진행한 후 정상적으로 vCenter UI에 접속이 가능합니다.
문제가 발생했던 원인을 파악하기 위해서 vmdird 로그와 tomcat access log를 확인합니다.
vmdird 로그에는 실제로 ActAsUser Group을 제거하는 행위가 기록되어 있습니다.
| info vmdird t@140132820702976: Delete Entry (CN=ActAsUsers,DC=vsphere,DC=local)(from 127.0.0.1)(by xxx@vsphere.local)(via Ext)(USN 7629,0) |
또한, tomcat access log(/var/log/vmware/vsphere-ui/logs/access/localhost_access_log.txt)에는 어떤 IP를 이용하여 접속한 client가 삭제 시도를 했는지도 확인할 수 있습니다.
| 127.0.0.1 x.y.z.w - - [22/Aug/2022:04:18:01 +0000] "DELETE /ui/psc-ui/ctrl/psc/tenant/group/ActAsUsers@vsphere.local HTTP/1.1" 200 - - http-nio-5090-exec-11 40 |
실제 "DELETE /ui/psc-ui/ctrl/psc/tenant/group/ActAsUsers@vsphere.local" API를 호출하는 것이 ActAsUser Group을 지우는 것이 맞는지를 검증하기 위해 테스트 vCenter에서 ActAsUser Group을 수동으로 제거할 때 어떤 API Endpoint를 호출하는지 검증합니다.
수동으로 제거하는 시점에 Web Browser의 개발자 도구를 이용하면, 어떤 API Endpoint가 호출되었는지 확인할 수 있고, 이를 통해 검증이 가능합니다.
'Compute' 카테고리의 다른 글
| Reverse lookup for SMTP service (0) | 2022.10.24 |
|---|---|
| VMTools version 확인 및 Download (0) | 2022.10.07 |
| vmss2core를 이용한 guest os memory dump 생성 (0) | 2022.08.30 |
| GPU 테스트(DirectPath I/O, Dynamic DirectPath I/O) (0) | 2022.08.19 |
| JXplorer를 이용한 vCenter의 VMDIR 접근 방법 (0) | 2022.08.14 |
