Using logs to troubleshoot login problems

To troubleshoot login problems on Windows:

1. On the SafeLinx Client system: Start > Programs > SafeLinx Client > Connections > Tools > Configure Trace > Level > High > OK. The trace file is in C:\Users\Public\Documents.
2. Using the SafeLinx Administrator, configure logging for the SafeLinx Server. Right click on the SafeLinx Server resource in the Left Pane and select Properties. In the SafeLinx Server properties in the Right Pane, select the Logging tab. By default, this log file is wg.log. This file is in /var/adm/ on Linux. On Windows, this file is in the installation directory under the logs directory. The default level of logging is ERROR and WARNING. For troubleshooting purposes set the Log Levels to Debug, Error, Log, Secondary Authentication and Warning log levels, and then click Apply.
3. Attempt to log in from the SafeLinx Client.
4. Review the SafeLinx Client trace and SafeLinx Server log or Open a Case with HCL Support.

In general, you see four packets exchanged between the SafeLinx Client and SafeLinx Server to establish the secured and encrypted tunnel. Additional packets might be required if either the SafeLinx Client or SafeLinx Server disagrees (negative acknowledgment or NACK) on a setting proposed by the other. These packets are:

• Link control protocol (LCP) configuration request (SafeLinx Client to SafeLinx Server)
• LCP configuration acknowledge (ACK) (SafeLinx Server to SafeLinx Client)
• LCP configuration request (SafeLinx Server to SafeLinx Client)
• LCP configuration ACK (SafeLinx Client to SafeLinx Server)

Find the SafeLinx Server IP address and connection port that the SafeLinx Client is trying to use. This address should be routable from the SafeLinx Client and the port should be open on any firewalls between the SafeLinx Client and SafeLinx Server. Look for the first LCP-Configure Request id=0x01, Outbound packet. Right after the hexadecimal representation of the packet, you see the packet be transmitted to the network:

ipdriver.cpp,328: Message to core: eMsg_PacketTransmitted, rc=eOK, Default Local IP Interface
      (2516.2544)UdpPort.cpp,283: ---> write packet - length = 394 to 27.47.200.168:8894
    (2516.2544)

Determine which IP address and port the client is bound to and listening on. This address should be routable from the SafeLinx Server and the port should be open on any firewalls between the client and the SafeLinx Server.

Port.cpp,97: CPort::connect setting bind address to 192.168.0.13 (2516.11960)
Port.cpp,118: Bound to 192.168.0.13:56323 (2516.11960)

The SafeLinx Client sets a host route to the SafeLinx Server. The routing table can be verified by running netstat -ar on Linux and Windows operating systems. The SafeLinx Client prints out the current route table any time that it updates it.

Port.cpp,261: CPort::createRoute() dest=27.47.200.168, interface=192.168.0.13,
      gateway=192.168.0.1 (2516.11960)

Destination   Netmask           Gateway   Interface      Metric
27.47.200.168 255.255.255.255 192.168.0.1 192.168.0.13 10 

The outbound LCP configuration request (SafeLinx Client to SafeLinx Server) follows:

ALP LCP-Configure Request id=0x01, Outbound
<mru 1472> <magic 0xd341202d> <pcomp> <acomp>
<encrypt AES(256)/CBC> <compress LZW> <VJ-red> <ip-addr>
<subnet mask> <version 800 HCL Technologies/MS Windows 64-bit (03200206) 
Windows 7 Professional Edition version 6.1 Service Pack 1 (Build 7601)> 
<routes : none> <WLP_TCP> <restricted : none> <userid> 
<dns addresses : Primary DNS: Secondary DNS: Domain Name: >
<Diffie-Hellman : Client Public Key= > <WLP Session ID 0x2e3e>
<Network InformationSpeed=1000000000 Network Name=Intel(R) Ethernet Connection I217-LM> 
<Build DataBuild Data=1.0.0 20160713_0936_GA> (2516.2544)

Hex dumps of LCP packets always begin with "C0 21".

WRAPR	HEX dump of 1472 bytes starting at address 009F7578: (EB0.994)
    0000: C0 21 ...

Inbound LCP configuration ACK (SafeLinx Server to SafeLinx Client):

ALP LCP-Configure Ack id=0x01, Inbound
<mru 1472> <magic 0xd341202d> <pcomp> <acomp>
<encrypt AES(256)/CBC> <compress LZW> <VJ-red> <ip-addr> <subnet mask> 
<version 800 HCL Technologies/MS Windows 64-bit (03200206) Windows 7 
Professional Edition version 6.1 Service Pack 1 (Build 7601)> 
<routes : none> <WLP_TCP> <restricted : none> <userid> 
<dns addresses : Primary DNS: Secondary DNS: Domain Name: > 
<Diffie-Hellman : Client Public Key=> <WLP Session ID 0x2e3e> 
<Network InformationSpeed=1000000000 Network Name=Intel(R) Ethernet 
Connection I217-LM> 
<Build DataBuild Data=1.0.0 20160713_0936_GA> (2516.10548)

ALP LCP-Configure Request id=0x01, Inbound
<magic 0x3d6c4324> <pcomp> <encrypt AES(256)/CBC> <compress LZW>
<auth EAP 0x00> <VJ-red> <ip-addr> <subnet mask>
<routes : not listed> <version 800 HCL Technologies/AIX (03200205)> <WLP Session
ID 0x2e3e>
<Transport Profile Compression=FALSE, Balance Fragments=TRUE, Header
Reduction=FALSE, Packet Joining=FALSE, IP Forwarding=TRUE, TCP Opt=FALSE, 
Network MTU=1472, IP Stack MTU=1448, TCP Initial RTT=3, TCP ACK Delay=0, WLP
Transmit Delay=0, LCP Echo Interval=0, 
TCP Opt TTL=0, TCP Window=0, TCP Burst Rate=0, TCP Max Retransmits=0> 
<restricted : > <session key> <Diffie-Hellman : Gateway Public Key=> (2516.10548)

Outbound LCP configuration ACK (SafeLinx Client to SafeLinx Server):

ALP LCP-Configure Ack id=0x01, Outbound
<magic 0x3d6c4324> <pcomp> <encrypt AES(256)/CBC> <compress LZW>
<auth EAP 0x00> <VJ-red> <ip-addr> <subnet mask>
<routes : not listed> <version 800 HCL Technologies/AIX (03200205)> <WLP
Session ID 0x2e3e>
<Transport Profile Compression=FALSE, Balance Fragments=TRUE, Header
Reduction=FALSE, Packet Joining=FALSE, IP Forwarding=TRUE, TCP Opt=FALSE, 
Network MTU=1472, IP Stack MTU=1448, TCP Initial RTT=3, TCP ACK Delay=0, WLP
Transmit Delay=0, LCP Echo Interval=0, 
TCP Opt TTL=0, TCP Window=0, TCP Burst Rate=0, TCP Max Retransmits=0>
<restricted : > <session key> <Diffie-Hellman : Gateway Public Key> (2516.10548)

LCP handshaking is complete, but since this login is configured to use a Secondary Authentication, the SafeLinx Client uses an Extensible Authentication Protocol (EAP) to negotiate this authentication with the SafeLinx Server:

ALP PPP-EAP: Request id=0x00, Inbound
<major EXPANDED_EAP> <minor LDAP Bind> <vendor HCL> <PPP_PAP>
<rc=0x00000000>
<version=0x00> <flags R I> <length 15>
<REALM BluepagesAuth> (2516.10548)
01/10/2017 15:05:30:0996 EAP	
eap_recv_request: Rcvd id 0. (2516.10548)

The SafeLinx Client responds to the SafeLinx Server EAP request with its response:

DATAMGR	Sending secondary authentication to gateway u=17 p=8 (2516.10548)
EAP	eap_set_config: enter (2516.10548)
EAP	eap_set_config: ALP_EAP_LDAPBIND_LOGIN, (3) ????????mpe@??????h6??t?)5535:??????????????(2516.10548)
EAP	eap_send_response: sending Expanded EAP! (2516.10548)
ALP	PPP-EAP: Response id=0x00, Outbound
<major EXPANDED_EAP> <minor LDAP Bind> <vendor HCL> <PPP_PAP>
<version=0x00> <flags R I> <length 63>
<IDENTITY ????????m>
<REALM BluepagesAuth.com>
<SECRET=**SECRET**> (2516.10548)

Presuming all went well with the Authentication at the SafeLinx Server it would respond positively to the SafeLinx Client:

IncomingEAP	HEX dump of 4 bytes starting at address 03034148: (2516.10548)
0000: 03 00 00 04 <....>
CONNMGR	Message to API clients: eMsg_PacketReceived, rc=eOK (2516.11960)
ALP	PPP-EAP: Success id=0x00, Inbound (2516.10548)

The secured and encrypted tunnel between the client and server is initialized after you see this message:

DATAMGR	Gratuitous ARP Received (EB0.F4C)

Routes are then added to the routing table based on the MNI definition:

DATAMGR	Adding route: Destination = 9.9.9.9 Mask = 255.255.255.255 (EB0.F4C)
DATAMGR	Adding route: Destination = 10.3.3.0 Mask = 255.255.255.0 (EB0.F4C)

The formal completion of the VPN login connection is signaled with the following messages:

DATAMGR	Now logged onto gateway x.x.x.x with local ip=x.x.x.x, subnet=x.x.x.x
(2516.10548)
DATAMGR	DNS: Domain (sampledomain.com), Primary (x.x.x.x), Secondary (x.x.x.x),
WINS Primary (x.x.x.x), Secondary (x.x.x.x) (2516.10548)
DATAMGR	Network MTU (1472), IP Stack MTU (1448) (2516.10548)
DATAMGR	Network Name: Intel(R) Ethernet Connection I217-LM (2516.10548)
DATAMGR	Network ID: x.x.x.x (2516.10548)

From the wg.log file on the SafeLinx Server, as on the client, you can identify the LCP packets by the first 2 bytes of the hex dump:

UdpPort: received data from <client real IP address> port <client MNC port> (1472) 
on port <server MNC port>
	0000: c0 21 . . .

The LCP packet enters the queue for processing:

WLP: queueing LCP packet from device <client real IP address>:<client MNC port>
for processing

Creating the active session table entry for this SafeLinx Client:

First occurence of device <client real IP address>:<client MNC port> in the system - 
creating an account for it

. . . Database calls follow. . .

The DHCP subsystem assigns the client an IP address:

DHCP_System::assign: (entry)
DHCP_System::assign: (return), rc=0

Transport profile processing begins. See the technote on Determining the transport profile used in a session for details.

WLP_Session::setTransportProfile: (entry)

The initial configuration request processed by the SafeLinx Server with "id 1" corresponds to "id=0x01" in the SafeLinx Client trace:

[<user Id> (client real IP address>:<client MNC port>)] PPP-FSM: rconfreq - received 
CONFREQ with id1

The SafeLinx Server reviews each requested setting for the connection, either ACKs or NACKs, and sends the response to the SafeLinx Client:

[<user ID>(<client real IP address>:<client MNC port>)] PPP-LCP: lcp_reqci - 
received MRU
PPP-LCP: lcp_reqci - received MRU-value 1472
PPP-LCP: lcp_reqci - ACK
...
PPP-LCP: lcp_reqci - ACK
PPP-LCP: lcp_reqci - returning CONFACK.
...
WLP: delivering WLP data (256) to account 
<user ID>(client real IP address>:<client MNC port>)
ip-lan0::deliver: (entry)
ip-lan0: delivering packet (256)
	0000: c0 21 . . .

The SafeLinx Server sends its configuration request:

PPP-LCP: fsm_sconfreq - sending Configure-Request, id 1

The SafeLinx Server then receives the configuration acknowledgment (CONFACK) from the SafeLinx Client:

PPP-LCP: fsm_rconfack - received id 1

And indicates that the connection is complete (SafeLinx Client virtual IP/MNI address):

Trap: 'AG: connection established' (10.3.3.2/ip-lan)