problems with TLS offload - unexpected CSTP length

[Eugene Istomin]

Nikos,

#/usr/sbin/ocserv --version 
ocserv 0.10.9 

Compiled with PAM, PKCS#11, AnyConnect,  
GnuTLS version: 3.2.18


It happens at first connection after ~ 30-50 packets:
....
ocserv[16802]: main[VPN]: {IP}:60661 assigning tun device oc_vpn0
ocserv[16802]: main[VPN]: {IP}:60661 user of group 'VPN' authenticated (using cookie)
ocserv[16802]: main[VPN]: {IP}:60661 sending (socket) message 2 to worker
ocserv[16802]: main[VPN]: {IP}:60661 user logged in
ocserv[16828]: worker: {IP} received auth reply message (value: 1)
ocserv[16828]: worker[VPN]: {IP} suggesting DPD of 1800 secs
ocserv[16828]: worker[VPN]: {IP} peer's base MTU is 1440
ocserv[16828]: worker[VPN]: {IP} CSTP Base MTU is 1440 bytes
ocserv[16828]: worker[VPN]: {IP} sending IPv4 192.168.23.136
ocserv[16828]: worker[VPN]: {IP} adding custom header 'X-My-Header: user:VPN group:VPN'
ocserv[16828]: worker[VPN]: {IP} DTLS ciphersuite: AES128-SHA
ocserv[16828]: worker[VPN]: {IP} DTLS overhead is 114
ocserv[16828]: worker[VPN]: {IP} suggesting DTLS MTU 1326
ocserv[16828]: worker[VPN]: {IP} setsockopt(SO_PRIORITY) to 3, failed.
ocserv[16828]: worker[VPN]: {IP} sending message 'tun mtu change' to main
ocserv[16828]: worker[VPN]: {IP} setting MTU to 1326
ocserv[16802]: main[VPN]: {IP}:60661 main received message 'tun mtu change' of 3 bytes
ocserv[16802]: main[VPN]: {IP}:60661 setting oc_vpn0 MTU to 1326
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 52 byte(s)
ocserv[16828]: worker[VPN]: {IP} sending 226 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 991 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 983 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 1334 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 1326 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} received 991 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 983 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 467 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 459 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} sending 40 byte(s)
ocserv[16828]: worker[VPN]: {IP} sending 64 byte(s)
ocserv[16828]: worker[VPN]: {IP} received 68 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 60 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} received 68 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} writing 60 byte(s) to TUN
ocserv[16828]: worker[VPN]: {IP} received 272 byte(s) (TLS)
ocserv[16828]: worker[VPN]: {IP} unexpected CSTP length (have 60, should be 264)
ocserv[16828]: worker[VPN]: {IP} worker-vpn.c:1094: error parsing CSTP data
...


> tests/docker-ocserv/Dockerfile-fedora-proxyproto-unix.
Already tested, seems like the same behaviour.




---
Best regards,
Eugene Istomin

On Wednesday, December 09, 2015 02:10:57 PM  Mavrogiannopoulos wrote:
> On Wed, Dec 9, 2015 at 12:13 PM, Eugene Istomin <E.Istomin at edss.ee> wrote:
> > Hello,
> > we have a problems with TLS offload using HaProxy:
> >
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sending 440 byte(s)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sending 56 byte(s)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sending 440 byte(s)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sending 56 byte(s)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] received 60 byte(s) (TLS)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] writing 52 byte(s) to TUN
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] received 1070 byte(s) (TLS)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] unexpected CSTP length (have 52, should be 1062)
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] worker-vpn.c:1094: error parsing CSTP data
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sending message 'sm: cli stats' to secmod
> > ocserv[64521]: worker[vpn_name]: [SOME_IP] sent periodic stats (in: 52, out: 1984) to sec-mod
> 
> Which version of ocserv is that? Is that a random failure or happens
> consistently at a certain point. Please provide more info.
> 
> For configuration I'd refer you to check the files used by
> tests/docker-ocserv/Dockerfile-fedora-proxyproto-unix. It uses proxy
> protocol over unix sockets and includes a traffic check so I would
> expect that it fully covers your scenario.
> 
> regards,
> Nikos
> 
> _______________________________________________
> openconnect-devel mailing list
> openconnect-devel at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/openconnect-devel
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 473 bytes
Desc: This is a digitally signed message part.
URL: <http://lists.infradead.org/pipermail/openconnect-devel/attachments/20151209/971209cc/attachment.sig>