This is a log analysis of a successful login with cisco Anyconnect. If the configuration is ready it is always useful to make a successful test with the system and raise the logging to the highest level in the meantime and save it before the first problem comes. It will come…
From this log analysis we can see what happens if the ASA authenticates the Anyconnect user with certificate, authorize the user with ldap and assign an ip from local pool.
This is the topology of my test setup.
Client has the following Informations in his certificate and under his LDAP Account:
E-mail: admin@mycompany.com Certificate Data: serial number: 111111, subject name: cn=Admin MyPKI,dc=com issuer_name: cn=myinternalca,dc=MyPKI,dc=com LDAP User Attributes: cn = Jackson, Joe sn = Jackson l = Brussel description = admin@mycompany.com telephoneNumber = +11-123-45-6789 givenName = Joe mail = admin@mycompany.com roomNumber = Brussel/113 uid = Jackson Joe 1234 pgpID = 123456789123 corp = My Company department = IT mail2 = admin@mycompany.com subDepartment = IT Security givenNameReal = Joe surnameReal = Jackson |
In the Cisco ASA we have the following setup:
VPN tunnel group name: MyTunnelGroup Group policy name: MyGroupPolicy VPN IP Pool: 40.0.0.0-40.0.0.254 CA or Trustpoint name: myinternalca |
The configuration of the ASA can be found HERE.
The Profile for Anyconnect is HERE.
Lets see the log to understand what happens in the background.
1. VPN Session initialisation
The Client builds 3 connections. 2 over udp 500 and over 4500 for IKEv2 /This is the VPN initialisation/ and one for the profile and version update over tcp 443 (it checks if there is a new verion or profile).
You can change the tcp 443 port for updates with the ‘ssl certificate-authentication interface inside port‘ command.
The Encryption method for updates and for SSL VPN can be changed with the ‘ssl encryption aes128-sha1 aes256-sha1‘ command.
Jul 15 2011 12:08:53: %ASA-6-302015: Built inbound UDP connection 1556718 for inside:20.0.0.21/22782 (20.0.0.21/22782) to identity:30.0.0.1/500 (30.0.0.1/500) Jul 15 2011 12:08:53: %ASA-5-750002: Local:30.0.0.1:500 Remote:20.0.0.21:22782 Username:Unknown Received a IKE_INIT_SA request Jul 15 2011 12:08:54: %ASA-6-302015: Built inbound UDP connection 1556719 for inside:20.0.0.21/22783 (20.0.0.21/22783) to identity:30.0.0.1/4500 (30.0.0.1/4500) Jul 15 2011 12:08:59: %ASA-7-717029: Identified client certificate within certificate chain. serial number: 111111, subject name: cn=Admin MyPKI,dc=com. Jul 15 2011 12:09:01: %ASA-6-302013: Built inbound TCP connection 1556724 for inside:20.0.0.21/22790 (20.0.0.21/22790) to identity:30.0.0.1/443 (30.0.0.1/443) Jul 15 2011 12:09:01: %ASA-6-725001: Starting SSL handshake with client inside:20.0.0.21/22790 for TLSv1 session. Jul 15 2011 12:09:01: %ASA-7-725008: SSL client inside:20.0.0.21/22790 proposes the following 18 cipher(s). Jul 15 2011 12:09:01: %ASA-7-725012: Device chooses cipher : AES128-SHA for the SSL session with client inside:20.0.0.21/22790 Jul 15 2011 12:09:02: %ASA-6-725002: Device completed SSL handshake with client inside:20.0.0.21/22790 Jul 15 2011 12:09:02: %ASA-6-302014: Teardown TCP connection 1556724 for inside:20.0.0.21/22790 to identity:30.0.0.1/443 duration 0:00:00 bytes 3921 TCP FINs Jul 15 2011 12:09:02: %ASA-6-725007: SSL session with client inside:20.0.0.21/22790 terminated. |
2. Certificate check (CRL) – There is no IP in logs! :-(
1. The ASA looks for a certificate in its chains (under the trustpoints) that exists in the client’s certificate chain. If the firewall finds one of the CAs in the chain of the client certificate it accepts the certificate.
2. the ASA check the user certificate in the CRL from the user certificate and if the serial is not int revocation list, the certificate is accepted.
Jul 15 2011 12:09:02: %ASA-7-717030: Found a suitable trustpoint myinternalca to validate certificate. Jul 15 2011 12:09:02: %ASA-6-717022: Certificate was successfully validated. serial number: 111111, subject name: cn=Admin MyPKI,dc=com. Jul 15 2011 12:09:02: %ASA-6-717028: Certificate chain was successfully validated with revocation status check. |
3. Certificate Mapping
1. To bind the user to the tunnel-group the ASA checks the certificate maps. With the certificate maps we can define which user belongs to which tunnel-group.
This was configured with a certificate map, that expect a cn with the name myinternalca and in webvpn configuration mode the tunnel mapping to certificate map:
crypto ca certificate map MyCM2 1 issuer-name attr cn co myinternalca
!
webvpn certificate-group-map MyCM2 1 MyTunnelGroup
|
2. For LDAP Authentication the ASA tries to extract the pre-defined attribute that will be forwarded to the LDAP Server for authorization.
Jul 15 2011 12:09:02: %ASA-7-717036: Looking for a tunnel group match based on certificate maps for peer certificate with serial number: 111111, subject name: cn=Admin MyPKI,dc=com, issuer_name: cn=myinternalca,dc=MyPKI,dc=com. Jul 15 2011 12:09:02: %ASA-7-717038: Tunnel group match found. Tunnel Group: MyTunnelGroup, Peer certificate: serial number: 111111, subject name: cn=Admin MyPKI,dc=com, issuer_name: cn=myinternalca,dc=MyPKI,dc=com. Jul 15 2011 12:09:02: %ASA-7-113028: Extraction of username from VPN client certificate has been requested. [Request 20575] Jul 15 2011 12:09:02: %ASA-7-113028: Extraction of username from VPN client certificate has started. [Request 20575] Jul 15 2011 12:09:02: %ASA-7-113028: Extraction of username from VPN client certificate has finished successfully. [Request 20575] Jul 15 2011 12:09:02: %ASA-7-717036: Looking for a tunnel group match based on certificate maps for peer certificate with serial number: 111111, subject name: cn=Admin MyPKI,dc=com, issuer_name: cn=myinternalca,dc=MyPKI,dc=com. Jul 15 2011 12:09:02: %ASA-7-717038: Tunnel group match found. Tunnel Group: MyTunnelGroup, Peer certificate: serial number: 111111, subject name: cn=Admin MyPKI,dc=com, issuer_name: cn=myinternalca,dc=MyPKI,dc=com. Jul 15 2011 12:09:02: %ASA-7-113028: Extraction of username from VPN client certificate has completed. [Request 20575] |
Wrongly selected Attribute:
The wrong attribute is choosen with the command ‘username-from-certificate‘ in tunnel-group configuration mode
or
the attribute does not exist in the certificate:
Jul 15 2011 14:22:16: %ASA-7-113028: Extraction of username from VPN client certificate has been requested. [Request 20631]
Jul 15 2011 14:22:16: %ASA-7-113028: Extraction of username from VPN client certificate has started. [Request 20631]
Jul 15 2011 14:22:16: %ASA-4-113026: Errorwhile executing Lua script for group
Jul 15 2011 14:22:16: %ASA-7-113028: Extraction of username from VPN client certificate has finished with error. [Request 20631]
|
4. AAA Authentication
The user will be authorized if the asa finds the required attribute in the certificate and the ldap server finds it in its database.
Jul 15 2011 12:09:02: %ASA-6-113004: AAA user authorization Successful : server = 20.0.0.200 : user = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-6-113009: AAA retrieved default group policy (MyGroupPolicy) for user = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-6-113008: AAA transaction status ACCEPT : user = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.1 = aagGenericPerson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.2 = externalAAGPerson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.3 = GenericPerson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.4 = SourceEntry Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.5 = PGPperson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.6 = PKIperson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.7 = Partner Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.8 = dxmNTuser Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.9 = top Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.10 = person Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.11 = organizationalPerson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.objectClass.12 = inetOrgPerson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.cn = Jackson, Joe Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.sn = Jackson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.l = Brussel Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.description = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.telephoneNumber = +11-123-45-6789 Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.givenName = Joe Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.userCertificate;binary.1 = 0..K0..2..........0...*.H....... Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.userCertificate;binary.2 = 0...0.............0...*.H....... Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.userCertificate;binary.3 = 0...0.............0...*.H....... Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.mail = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.roomNumber = Brussel/113 Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.uid = Jackson Joe 1234 Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.pgpID = 123456789123 Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.corp = My Company Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.department = IT Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.mail2 = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.subDepartment = IT Security Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.givenNameReal = Joe Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.ldap.surnameReal = Jackson Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.cisco.grouppolicy = MyGroupPolicy Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.cisco.username = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.cisco.username1 = admin@mycompany.com Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.cisco.username2 = |
5. IP Lease
If we are at this step, we are pretty good to login. The client get an ip that will be used internally in the vpn.
Jul 15 2011 12:09:02: %ASA-7-737001: IPAA: Received message 'UTL_IP_[IKE_]ADDR_REQ'
Jul 15 2011 12:09:02: %ASA-5-737003: IPAA: DHCP configured, no viable servers found for tunnel-group 'MyTunnelGroup'
Jul 15 2011 12:09:02: %ASA-6-737026: IPAA: Client assigned 40.0.0.200 from local pool
Jul 15 2011 12:09:02: %ASA-7-720041: (VPN-Primary) Sending Update SVC Addr Data message Session Index 85549056 to standby unit
Jul 15 2011 12:09:02: %ASA-6-737006: IPAA: Local pool request succeeded for tunnel-group 'MyTunnelGroup'
|
6. Anyconnect session is ready to use
Jul 15 2011 12:09:02: %ASA-7-734003: DAP: User admin@mycompany.com, Addr 20.0.0.21: Session Attribute aaa.cisco.tunnelgroup = MyTunnelGroup Jul 15 2011 12:09:02: %ASA-6-734001: DAP: User admin@mycompany.com, Addr 20.0.0.21, Connection AnyConnect: The following DAP records were selected for this connection: DfltAccessPolicy Jul 15 2011 12:09:02: %ASA-6-113039: GroupUserIPAnyConnect parent session started. Jul 15 2011 12:09:02: %ASA-7-720041: (VPN-Primary) Sending Create WebVPN Session message user admin@mycompany.com, IP 20.0.0.21 to standby unit Jul 15 2011 12:09:03: %ASA-5-750006: Local:30.0.0.1:4500 Remote:20.0.0.21:22783 Username:admin@mycompany.com SA UP. Reason: New Connection Established Jul 15 2011 12:09:03: %ASA-6-602303: IPSEC: An outbound remote access SA (SPI= 0x4DB0D7DC) between 30.0.0.1 and 20.0.0.21 (user= admin@mycompany.com) has been created. Jul 15 2011 12:09:03: %ASA-6-602303: IPSEC: An inbound remote access SA (SPI= 0x6B365A91) between 30.0.0.1 and 20.0.0.21 (user= admin@mycompany.com) has been created. |
7. Session delete
If the client disconnects the asa writes in its log “User Requested.” and deletes the Security Associations (SAs). We can see in the logs the time the user was online and the sent/transmitted traffic in bytes the user generated.
Jul 15 2011 12:09:23: %ASA-7-710007: NAT-T keepalive received from 20.0.0.21/22783 to inside:30.0.0.1/4500 Jul 15 2011 12:09:34: %ASA-5-750007: Local:30.0.0.1:4500 Remote:20.0.0.21:22783 Username:admin@mycompany.com SA DOWN. Reason: peer request Jul 15 2011 12:09:34: %ASA-7-720041: (VPN-Primary) Sending Delete WebVPN Session message user admin@mycompany.com, IP 20.0.0.21 to standby unit Jul 15 2011 12:09:34: %ASA-6-716002: GroupUserIPWebVPN session terminated: User Requested. Jul 15 2011 12:09:34: %ASA-4-113019: Group = MyTunnelGroup, Username = admin@mycompany.com, IP = 20.0.0.21, Session disconnected. Session Type: IKEv2, Duration: 0h:00m:32s, Bytes xmt: 122713, Bytes rcv: 1046181, Reason: User Requested Jul 15 2011 12:09:34: %ASA-6-602304: IPSEC: An outbound remote access SA (SPI= 0x4DB0D7DC) between 30.0.0.1 and 20.0.0.21 (user= admin@mycompany.com) has been deleted. Jul 15 2011 12:09:34: %ASA-6-602304: IPSEC: An inbound remote access SA (SPI= 0x6B365A91) between 20.0.0.21 and 30.0.0.1 (user= admin@mycompany.com) has been deleted. |
ashwathmendan
September 8, 2017
Is there a way to perform certificate authentication and ldap authorization on Fortigate for SSL VPN?
ashwathmendan
September 8, 2017
And also Here I’m getting error of invalid certificate on anyconnect client. What might be the possible reason?