Unable to connect from AnyConnect 3.0 and 3.1 Windows Clients to ocserv 0.2.4 and git head

[Thomas Glanzmann]

Hello Nikos,

> Ok, here it seems is the issue. read_user_pass() tries to parse the
> username as XML although it is not (according to the previous log). I
> wonder why memmem(body, body_length, "<?xml", 5) succeeds. Could you see
> what is the POST body when http-debug is specified?

(infra) [~/work/ocserv] /local/ocserv-bisect/sbin/ocserv -f -d -c /local/ocserv/etc/config --http-debug
listening (TCP) on 78.47.70.72:443...
listening (UDP) on 78.47.70.72:443...
ocserv[18836]: sec-mod initialized (socket: /var/run/ocserv-socket.18835)
ocserv[18835]: [main] initialized ocserv 0.3.0pre0
ocserv[18838]: 212.114.206.182:49308 accepted connection
ocserv[18836]: sec-mod received request from pid 18838 and uid 65534
ocserv[18838]: 212.114.206.182:49308 sending message 6 to main
ocserv[18838]: 212.114.206.182:49308 TLS handshake completed
ocserv[18835]: 212.114.206.182:49308 main received message 6 of 278 bytes
ocserv[18838]: 212.114.206.182:49308 HTTP: Cache-Control: no-cache
ocserv[18838]: 212.114.206.182:49308 HTTP: Connection: close
ocserv[18838]: 212.114.206.182:49308 HTTP: Pragma: no-cache
ocserv[18838]: 212.114.206.182:49308 HTTP: Host: lync.gmvl.de
ocserv[18838]: 212.114.206.182:49308 HTTP: User-Agent: AnyConnect Windows 3.1.05152
ocserv[18838]: 212.114.206.182:49308 HTTP: X-Transcend-Version: 1
ocserv[18838]: 212.114.206.182:49308 HTTP: X-Aggregate-Auth: 1
ocserv[18838]: 212.114.206.182:49308 HTTP: X-AnyConnect-Platform: win
ocserv[18838]: 212.114.206.182:49308 HTTP: Content-Length: 564
ocserv[18838]: 212.114.206.182:49308 HTTP POST /
ocserv[18838]: 212.114.206.182:49308 POST body: '<?xml version="1.0" encoding="UTF-8"?>
<config-auth client="vpn" type="init" aggregate-auth-version="2">
<version who="vpn">3.1.05152</version>
<device-id device-type="Intel Pentium Processors= 4 x86" platform-version="6.1.7601 Service Pack 1" unique-id="B2B563176DCDE1E541C743464446CCC939B98C0E8CD59E8752E8B2814411EEBA">win</device-id>
<mac-address-list>
<mac-address>00-24-d7-11-74-00</mac-address>
<mac-address>00-26-2d-fc-e4-1e</mac-address></mac-address-list>
<group-select>full</group-select>
ocserv[18838]: 212.114.206.182:49308 read_user_pass:467: cannot find username in client XML message
ocserv[18838]: 212.114.206.182:49308 post_auth_handler:588: failed reading username
ocserv[18835]: 212.114.206.182:49308 handle_commands:378: command socket closed
ocserv[18840]: 212.114.206.182:49309 accepted connection
ocserv[18840]: 212.114.206.182:49309 sending resumption request (fetch)
ocserv[18840]: 212.114.206.182:49309 sending message 8 to main
ocserv[18835]: 212.114.206.182:49309 main received message 8 of 34 bytes
ocserv[18835]: 212.114.206.182:49309 sending message 9 to worker
ocserv[18840]: 212.114.206.182:49309 TLS handshake completed
ocserv[18840]: 212.114.206.182:49309 HTTP: Cache-Control: no-cache
ocserv[18840]: 212.114.206.182:49309 HTTP: Connection: Close
ocserv[18840]: 212.114.206.182:49309 HTTP: Pragma: no-cache
ocserv[18840]: 212.114.206.182:49309 HTTP: Host: lync.gmvl.de
ocserv[18840]: 212.114.206.182:49309 HTTP: User-Agent: AnyConnect Windows 3.1.05152
ocserv[18840]: 212.114.206.182:49309 HTTP: X-Transcend-Version: 1
ocserv[18840]: 212.114.206.182:49309 HTTP: X-Aggregate-Auth: 1
ocserv[18840]: 212.114.206.182:49309 HTTP: X-AnyConnect-Platform: win
ocserv[18840]: 212.114.206.182:49309 HTTP: Content-Length: 17
ocserv[18840]: 212.114.206.182:49309 HTTP POST /auth
ocserv[18840]: 212.114.206.182:49309 sending message 1 to main
ocserv[18835]: 212.114.206.182:49309 main received message 1 of 16 bytes
ocserv[18835]: 212.114.206.182:49309 auth init for user 'sithglan' from '212.114.206.182:49309'
ocserv[18835]: 212.114.206.182:49309 sending message 2 to worker
ocserv[18840]: 212.114.206.182:49309 received auth reply message 2
ocserv[18840]: 212.114.206.182:49309 continuing authentication for ''
ocserv[18835]: 212.114.206.182:49309 handle_commands:378: command socket closed
ocserv[18835]: 212.114.206.182:49309 auth deinit for user 'sithglan'
ocserv[18842]: 212.114.206.182:49310 accepted connection
ocserv[18842]: 212.114.206.182:49310 sending resumption request (fetch)
ocserv[18842]: 212.114.206.182:49310 sending message 8 to main
ocserv[18835]: 212.114.206.182:49310 main received message 8 of 34 bytes
ocserv[18835]: 212.114.206.182:49310 sending message 9 to worker
ocserv[18842]: 212.114.206.182:49310 TLS handshake completed
ocserv[18842]: 212.114.206.182:49310 HTTP: Cache-Control: no-cache
ocserv[18842]: 212.114.206.182:49310 HTTP: Connection: Close
ocserv[18842]: 212.114.206.182:49310 HTTP: Pragma: no-cache
ocserv[18842]: 212.114.206.182:49310 HTTP: Host: lync.gmvl.de
ocserv[18842]: 212.114.206.182:49310 HTTP: User-Agent: AnyConnect Windows 3.1.05152
ocserv[18842]: 212.114.206.182:49310 HTTP: X-Transcend-Version: 1
ocserv[18842]: 212.114.206.182:49310 HTTP: X-Aggregate-Auth: 1
ocserv[18842]: 212.114.206.182:49310 HTTP: X-AnyConnect-Platform: win
ocserv[18842]: 212.114.206.182:49310 HTTP: Content-Length: 16
ocserv[18842]: 212.114.206.182:49310 HTTP POST /auth
ocserv[18842]: 212.114.206.182:49310 read_user_pass:515: cannot find username in client message
ocserv[18842]: 212.114.206.182:49310 post_auth_handler:588: failed reading username
ocserv[18835]: 212.114.206.182:49310 handle_commands:378: command socket closed

> Not reading the password initially is intentional in ocserv to follow
> PAM's requirements, and allow printing the PAM message when reading a
> password. This shouldn't affect you though.

I see.

Cheers,
        Thomas