SSLVPN intermittently disconnects

[marcis]

Hi! SSLVPN conections are quite unstable and tend to disconnect without reason (logs say that reason is " n/a" ). Several users are using SSLVPN and tendency is that this happens to other users whenever one of users connects or disconnects. Have anybody had similar problems? How to debug this? System information

fg1 # get system stat Version: Fortigate-80C v4.0,build0441,110318 (MR3) Virus-DB: 11.00782(2010-05-07 00:42) Extended DB: 1.00001(2010-05-21 13:37) IPS-DB: 2.00910(2010-12-02 17:49) FortiClient application signature package: 1.429(2011-10-12 09:43) Serial-Number: FGT80C3910621014 BIOS version: 04000006 Log hard disk: Not available Internal Switch mode: switch Hostname: fg1 Operation Mode: NAT Current virtual domain: root Max number of virtual domains: 10 Virtual domains status: 1 in NAT mode, 0 in TP mode Virtual domain configuration: disable FIPS-CC mode: disable Current HA mode: standalone Distribution: International Branch point: 441 Release Version Information: MR3 System time: Wed Oct 12 16:29:13 2011

Last disconnect happened to user " adminuser" when " user22" connected. I caputer debug log with following settings, when this happened

fg1 # di de in debug output: enable console timestamp: enable console no user log message: disable sslvpn debug level: -1 (0xffffffff) CLI debug level: 3

Debug log showing " user22" connecting and (probably somewhere) " adminuser" user losing connection

2011-10-12 16:19:59 [7927:root]LCP terminated by peer 2011-10-12 16:19:59 [7927:root]ipcp: down ppp:0x41dc9008 tun: 0x41bf4008 ref 4 2011-10-12 16:19:59 [7927:root]sys-fortik.c:699 deassociate 10.37.70.1 to tun (22) 2011-10-12 16:19:59 [7927:root]tun: reference count: 0x41bf4008 ref 3 2011-10-12 16:20:01 [7927:root]tunnel_state.c,cliRead,774, read=0, tunnel finish. 2011-10-12 16:20:01 [7927:root]tunnel_state.c:tunnelStateCleanup:916 0x41220008::0x412ea008 2011-10-12 16:20:01 [7927:root]SSL state:warning close notify (1.1.1.1) 2011-10-12 16:20:01 [7927:root]Destroy sconn 0x41220008, connSize=3. 2011-10-12 16:20:03 [7927:root]SSL state:before/accept initialization (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client hello A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write server hello A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write certificate A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write certificate request A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 flush data (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client certificate A:system lib(1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client certificate A:system lib(1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL_accept returned 0. 2011-10-12 16:20:03 [7927:root]Destroy sconn 0x9972410, connSize=3. 2011-10-12 16:20:03 [7927:root]SSL state:before/accept initialization (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv2/v3 read client hello A:system lib(1.1.1.1) 2011-10-12 16:20:03 [7927:root]buff.c,ap_read,72, error=1, errno=11 ssl 0x412e9008 Resource temporarily unavailable. error:140F3042:SSL routines:SSL_UNDEFINED_CONST_FUNCTION:called a function you should not call 2011-10-12 16:20:03 [7927:root]tunnel_state.c,cliRead,782, error=-1, 0x412e8008 tunnel finish. error:00000000:lib(0):func(0):reason(0) 2011-10-12 16:20:03 [7927:root]tunnel_state.c:tunnelStateCleanup:916 0x412e8008::0x412e9008 2011-10-12 16:20:03 [7927:root]SSL state:warning close notify (2.2.2.2) 2011-10-12 16:20:03 [7927:root]Destroy sconn 0x412e8008, connSize=3. 2011-10-12 16:20:03 [7927:root]ipcp: down ppp:0x41f4e008 tun: 0x41bf4008 ref 3 2011-10-12 16:20:03 [7927:root]sys-fortik.c:699 deassociate 10.37.70.4 to tun (22) 2011-10-12 16:20:03 [7927:root]tun: reference count: 0x41bf4008 ref 2 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client hello A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write server hello A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write certificate A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write certificate request A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 flush data (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client certificate A:system lib(1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client certificate A:system lib(1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client certificate A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read client key exchange A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read certificate verify A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 read finished A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write change cipher spec A (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 write finished B (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSLv3 flush data (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL state:SSL negotiation finished successfully (1.1.1.1) 2011-10-12 16:20:03 [7927:root]SSL established: AES128-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(128) Mac=SHA1 2011-10-12 16:20:03 [7927:root]rmt_websession.c:296 decode session id ok, user=[user22],group=[sslvpn_users],host=[1.1.1.1],idx=0,auth=1,login=1318422505 2011-10-12 16:20:03 [7927:root]rmt_websession.c:296 decode session id ok, user=[user22],group=[sslvpn_users],host=[1.1.1.1],idx=0,auth=1,login=1318422505 2011-10-12 16:20:03 [7927:root]rmt_websession.c:296 decode session id ok, user=[user22],group=[sslvpn_users],host=[1.1.1.1],idx=0,auth=1,login=1318422505 2011-10-12 16:20:03 [7927:root]buff.c,ap_read,72, error=1, errno=11 ssl 0x9976968 Resource temporarily unavailable. error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag 2011-10-12 16:20:03 [7927:root]buff.c,ap_read,72, error=1, errno=11 ssl 0x9976968 Resource temporarily unavailable. error:0D07803A:asn1 encoding routines:ASN1_ITEM_EX_D2I:nested asn1 error 2011-10-12 16:20:03 [7927:root]http_state.c,ap_read_request,430, error=-1, sconn=0x9972410. 2011-10-12 16:20:03 [7927:root]SSL state:warning close notify (1.1.1.1) 2011-10-12 16:20:03 [7927:root]Destroy sconn 0x9972410, connSize=2.

Event logs regarding particular disconnect

1: 2011-10-12 16:28:13 log_id=0132039425 type=event subtype=sslvpn-user pri=information action=tunnel-down tunnel_type=ssl-web vd=" root" tunnel_id=1512264311 remote_ip=1.1.1.1 tunnel_ip=N/A user=" user22" group=" sslvpn_users" dst_host=" N/A" reason=" idle timeout" duration=21373 sent=0 rcvd=0 msg=" SSL tunnel shutdown" 2: 2011-10-12 16:20:03 log_id=0132039425 type=event subtype=sslvpn-user pri=information action=tunnel-down tunnel_type=ssl-web vd=" root" tunnel_id=1512264319 remote_ip=1.1.1.1 tunnel_ip=N/A user=" user22" group=" sslvpn_users" dst_host=" N/A" reason=" log out" duration=3098 sent=0 rcvd=0 msg=" SSL tunnel shutdown" 3: 2011-10-12 16:20:03 log_id=0134039942 type=event subtype=sslvpn-session pri=information action=ssl-cert tunnel_type=ssl vd=" root" tunnel_id=0 remote_ip=1.1.1.1 tunnel_ip=N/A user=" N/A" group=" N/A" dst_host=" N/A" reason=" N/A" msg=" SSL new SSL certificate verification success" 4: 2011-10-12 16:20:03 log_id=0134039942 type=event subtype=sslvpn-session pri=information action=ssl-cert tunnel_type=ssl vd=" root" tunnel_id=0 remote_ip=1.1.1.1 tunnel_ip=N/A user=" N/A" group=" N/A" dst_host=" N/A" reason=" N/A" msg=" SSL new SSL certificate verification success" 5: 2011-10-12 16:20:03 log_id=0134039948 type=event subtype=sslvpn-session pri=information action=tunnel-down tunnel_type=ssl-tunnel vd=" root" tunnel_id=1512264329 remote_ip=2.2.2.2 tunnel_ip=10.37.70.4 user=" adminuser" group=" sslvpn_admins" dst_host=" N/A" duration=1090 sent=24952106 rcvd=1515012 reason=" N/A" msg=" SSL tunnel shutdown" 6: 2011-10-12 16:20:01 log_id=0134039948 type=event subtype=sslvpn-session pri=information action=tunnel-down tunnel_type=ssl-tunnel vd=" root" tunnel_id=1512264320 remote_ip=1.1.1.1 tunnel_ip=10.37.70.1 user=" user22" group=" sslvpn_users" dst_host=" N/A" duration=3093 sent=261026 rcvd=86039 reason=" N/A" msg=" SSL tunnel shutdown" 7: 2011-10-12 16:01:53 log_id=0134039947 type=event subtype=sslvpn-session pri=information action=tunnel-up tunnel_type=ssl-tunnel vd=" root" tunnel_id=1512264329 remote_ip=2.2.2.2 tunnel_ip=10.37.70.4 user=" adminuser" group=" sslvpn_admins" dst_host=" N/A" reason=" N/A" msg=" SSL tunnel established"

[Brian_T]

I have had 2 incidents where all my VPN connections (SSL and IPSEC) terminated at the same time. When this occurred I was unable to connect to my firewall using port 444 to try to see what was going on. It freed up on its own after a few minutes and I could not spot anything specific in the logs indicating the cause. I am on v4 MR2 Patch 3. Is this similar to what is happening to you?

[marcis]

Hi Brian! No this is not the same. For me only SSLVPN disconnets. IPSec VPN connections contionue to work and I don' t lose any other conectivity to FG. It appears that this problem is fixed 4.3.1. I' ll upgrade and see how SSLVPN works then.

[marcis]

Hi! Upgraded to build0482 (4mr3 patch2) last Friday. SSLVPN works stable now. It managed to work from 9:30 AM till 23:00 yesterday and then disconnected due to " idle timeout" (probably caused by network problems). Haven' t checked " what' s new" about this, but some parts of WEB GUI seem to be removed (or not working) - " system->maintenance" and " firewall objects->load balance" .