The latest ocserv cannot work well with IOS Anyconnect using profile.xml

yick xie yick.xie at gmail.com
Wed Dec 16 02:28:49 PST 2015 

Hello,

As the title, running ocserv with the profile.xml config will
encounter a server error when an IOS Anyconnect client tries to
connect the server. Yet there is no problem when just using Windows 7
Anyconnect, or just roughly with profile.xml disabled.

The ocserv was complied at commit
a52ffc4d06578d0209397753eb6ad3b778ed581e(When max-clients is set
adjust the file descriptor limits accordingly). The error shows
"segfault at a0 ip 000000000041c95d sp 00007fff95a51c20 error 4 in
ocserv[400000+59000]"

Dec 16 17:58:15 hk ocserv[1414]: worker:  accepted connection
Dec 16 17:58:15 hk ocserv[1414]: worker:  client certificate
verification succeeded
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: received request from pid
1414 and uid 65534
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: cmd [size=261] sm: decrypt
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: received request from pid
1414 and uid 65534
Dec 16 17:58:15 hk ocserv[1414]: worker:  sending message 'resume data
store request' to secmod
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: cmd [size=1220] resume data
store request
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: TLS session DB storing
ad2e2b28d685eb5fd2f884a5e236dfc15442d9b4a329b8a8cd8510b09d3bc76c
Dec 16 17:58:15 hk ocserv[1414]: worker:  TLS handshake completed
Dec 16 17:58:15 hk ocserv[1414]: worker:  sending message 'session info' to main
Dec 16 17:58:15 hk ocserv[1406]: main: 11*.*0.*5.237:52249 main
received message 'session info' of 6 bytes
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: User-Agent: AnyConnect AppleSSLVPN_Darwin_ARM (iPhone)
4.0.03016
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 User-agent:
'AnyConnect AppleSSLVPN_Darwin_ARM (iPhone) 4.0.'
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Host: 11*.8*.1*2.2**:443
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Accept: */*
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Accept-Encoding: identity
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-Transcend-Version: 1
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-Transcend-Version: 1
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-ClientVersion: 4.0.03016
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Platform: apple-ios
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-PlatformVersion: 7.1.2
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-DeviceType: iPhone4,1
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-UniqueID:
55307d20b7d8b69b04f3d9a99f5d06d72e3b384b
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-MacAddress: unknown
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-Imei: UNKNOWN:unknown
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: X-Aggregate-Auth: 1
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Connection: close
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Content-Length: 476
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP
processing: Content-Type: application/x-www-form-urlencoded
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 HTTP POST /
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 POST body:
'<?xml version="1.0" encoding="UTF-8"?>#012<config-auth client="vpn"
type="init">#012<device-id platform-version="7.1.2"
device-type="iPhone4,1"
unique-id="55307d20b7d8b69b04f3d9a99f5d06d72e3b384b">apple-ios</device-id>#012<phone-id>UNKNOWN:unknown</phone-id>#012<mac-address-list>#012<mac-address>unknown</mac-address></mac-address-list>#012<version
who="vpn">4.0.03016</version>#012<group-select>admin-global</group-select>#012<group-access>https://11*.8*.1*2.2**:443/</group-access>#012</config-auth>#012'
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: received request from pid
1414 and uid 65534
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 sending message
'sm: auth init' to secmod
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: cmd [size=60] sm: auth init
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: using 'certificate'
authentication to authenticate user (session: zZSYS)
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: auth init (with cert) for
user 'admin' (session: zZSYS) of group: '' from '11*.*0.*5.237'
Dec 16 17:58:15 hk ocserv[1414]: worker: 11*.*0.*5.237 received auth
reply message (value: 1)
Dec 16 17:58:15 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 user
'admin' obtained cookie
Dec 16 17:58:15 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
sending: 200 OK
Dec 16 17:58:15 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 sent
sid: zZSYS++Z4+SRRyciJPMlbQ==
Dec 16 17:58:15 hk ocserv[1415]: worker:  accepted connection
Dec 16 17:58:15 hk ocserv[1415]: worker:  tlslib.c:379: no certificate was found
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: received request from pid
1415 and uid 65534
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: cmd [size=261] sm: decrypt
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: received request from pid
1415 and uid 65534
Dec 16 17:58:15 hk ocserv[1415]: worker:  sending message 'resume data
store request' to secmod
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: cmd [size=355] resume data
store request
Dec 16 17:58:15 hk ocserv[1407]: sec-mod: TLS session DB storing
a3233d5670a82782d691a064e78038be1490cf89085388c9c6dfd2a9e91bdc4a
Dec 16 17:58:15 hk ocserv[1415]: worker:  TLS handshake completed
Dec 16 17:58:15 hk ocserv[1415]: worker:  sending message 'session info' to main
Dec 16 17:58:15 hk ocserv[1406]: main: 11*.*0.*5.237:52250 main
received message 'session info' of 6 bytes
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 HTTP
processing: User-Agent: AnyConnect ERROR_NOT_USED 4.0.03016
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 User-agent:
'AnyConnect ERROR_NOT_USED 4.0.03016'
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 HTTP
processing: Host: 11*.8*.1*2.2**:443
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 HTTP
processing: Accept: */*
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 HTTP
processing: Cookie:
webvpn=B4HK6PlpHYicYsLXPbLzdnZsGy5X954oDl54R9/mi6R3ZY6jgX9R7OYQUobcS60ToFr6qSU47qF11EZ2kjq3aw6kUfdI9c3Zj1yai2pvGmnGVw==
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 HTTP GET
/profiles//etc/ocserv/profile.xml
Dec 16 17:58:15 hk ocserv[1415]: worker: 11*.*0.*5.237 requested
config: /profiles//etc/ocserv/profile.xml
Dec 16 17:58:15 hk ocserv[1406]: main: 11*.*0.*5.237:52250 command socket closed
Dec 16 17:58:15 hk ocserv[1406]: main: 11*.*0.*5.237:52250 user
disconnected (reason: unspecified, rx: 0, tx: 0)
Dec 16 17:58:15 hk kernel: [2578229.154688] ocserv-worker[1415]:
segfault at a0 ip 000000000041c95d sp 00007fff95a51c20 error 4 in
ocserv[400000+59000]
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: User-Agent: AnyConnect AppleSSLVPN_Darwin_ARM (iPhone)
4.0.03016
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237
User-agent: 'AnyConnect AppleSSLVPN_Darwin_ARM (iPhone) 4.0.'
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: Host: 11*.8*.1*2.2**:443
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: Accept: */*
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: Accept-Encoding: identity
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: Cookie:
webvpn=B4HK6PlpHYicYsLXPbLzdnZsGy5X954oDl54R9/mi6R3ZY6jgX9R7OYQUobcS60ToFr6qSU47qF11EZ2kjq3aw6kUfdI9c3Zj1yai2pvGmnGVw==;
webvpnc=bu:/&p:t&iu:1/&sh:7E9BB890976A71EB71695B6054CF0ED41FCA4E9D&lu:/+CSCOT+/translation-table?textdomain%3DAnyConnect%26type%3Dmanifest&fu:profiles%2F/etc/ocserv/profile.xml&fh:291FF7BC238526C0C9DA9AE91EB408CB229F07D4;
webvpncontext=zZSYS++Z4+SRRyciJPMlbQ==
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 received
sid: zZSYS++Z4+SRRyciJPMlbQ==
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-Transcend-Version: 1
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-Transcend-Version: 1
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-ClientVersion: 4.0.03016
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Platform: apple-ios
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-PlatformVersion: 7.1.2
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-DeviceType: iPhone4,1
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-UniqueID:
55307d20b7d8b69b04f3d9a99f5d06d72e3b384b
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-MacAddress: unknown
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-AnyConnect-Identifier-Device-Imei: UNKNOWN:unknown
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: X-Aggregate-Auth: 1
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
processing: Cookie:
webvpnc=bu:/&p:t&iu:1/&sh:7E9BB890976A71EB71695B6054CF0ED41FCA4E9D&lu:/+CSCOT+/translation-table?textdomain%3DAnyConnect%26type%3Dmanifest&fu:profiles%2F/etc/ocserv/profile.xml&fh:291FF7BC238526C0C9DA9AE91EB408CB229F07D4
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP GET //logout
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 HTTP
sending: 200 OK
Dec 16 17:58:16 hk ocserv[1414]: worker[admin]: 11*.*0.*5.237 sent
sid: zZSYS++Z4+SRRyciJPMlbQ==
Dec 16 17:58:16 hk ocserv[1406]: main: 11*.*0.*5.237:52249 command socket closed
Dec 16 17:58:16 hk ocserv[1406]: main: 11*.*0.*5.237:52249 user
disconnected (reason: unspecified, rx: 0, tx: 0)

More information about the openconnect-devel mailing list