Incompatible with SPA525G
With the VPN credentials set on a Cisco SPA525g desk phone the following is seen in the debug log. The phone makes repeated connections and sends a GET / request each time never making an attempt to authenticate.
Setting 'plain' as primary authentication method
listening (TCP) on 0.0.0.0:443...
listening (UDP) on 0.0.0.0:443...
ocserv[21258]: main: initializing control unix socket: /var/run/occtl.socket
ocserv[21258]: main: initialized ocserv 0.10.11
ocserv[21259]: sec-mod: reading supplemental config from files
ocserv[21259]: sec-mod: sec-mod initialized (socket: /var/run/ocserv-socket.21258)
ocserv[21258]: TLS[<3>]: ASSERT: mpi.c:246
ocserv[21258]: TLS[<3>]: ASSERT: gnutls_dh.c:332
ocserv[21258]: TLS[<3>]: ASSERT: common.c:1110
ocserv[21259]: sec-mod: received request from pid 21258 and uid 0
ocserv[21259]: sec-mod: cmd [size=55] sm: sign
ocserv[21260]: worker: accepted connection
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Allocating epoch #0
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_constate.c:596
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Allocating epoch #1
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 135
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 135
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[0] Handshake(22) with length: 135
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: CLIENT HELLO (1) was received. Length 131[131], frag offset 0, frag length: 131, sequence: 0
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Client's version: 3.1
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected version TLS1.0
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_db.c:263
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC/10'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SESSION TICKET/35'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC/10'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SESSION TICKET/35' (0 bytes)
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SUPPORTED ECC POINT FORMATS/11' (4 bytes)
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SUPPORTED ECC/10' (10 bytes)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected ECC curve SECP521R1 (4)
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SESSION TICKET/35'
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Received safe renegotiation CS
ocserv[21260]: TLS[<3>]: ASSERT: server_name.c:307
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Requested PK algorithm: RSA (1) -- ctype: X.509 (1)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Requested cipher suites[size: 58]:
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected cipher suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected Compression Method: NULL
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Safe renegotiation succeeded
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Sending extension SAFE RENEGOTIATION (1 bytes)
ocserv[21260]: TLS[<4>]: EXT[0x55d59c6f6000]: Sending extension SUPPORTED ECC POINT FORMATS (2 bytes)
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: SessionID: 8f38f8c16ddf7aa15b94f392cae4b6919d126b8aa4b334cea726281b1d4da052
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER HELLO was queued [87 bytes]
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: CERTIFICATE was queued [2489 bytes]
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: signing handshake data: using RSA-SHA1
ocserv[21259]: sec-mod: received request from pid 21260 and uid 65534
ocserv[21259]: sec-mod: cmd [size=40] sm: sign
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER KEY EXCHANGE was queued [399 bytes]
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER HELLO DONE was queued [4 bytes]
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 87 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 92
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 2489 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[2] Handshake(22) in epoch 0 and length: 2494
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 399 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[3] Handshake(22) in epoch 0 and length: 404
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 4 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[4] Handshake(22) in epoch 0 and length: 9
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 138
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 138
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[1] Handshake(22) with length: 138
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: CLIENT KEY EXCHANGE (16) was received. Length 134[134], frag offset 0, frag length: 134, sequence: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 ChangeCipherSpec packet received. Epoch 0, length: 1
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet ChangeCipherSpec(20)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet ChangeCipherSpec(20) with length: 1
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[2] ChangeCipherSpec(20) with length: 1
ocserv[21260]: TLS[<9>]: INT: PREMASTER SECRET[66]: 018627056fcee32a48fc2cd3de009d04239d940be8b22f85c1e611caad10765887e9db7c4cfac07d47c28072deb29103fd05dfcab85915a211cb2ff4bf70ff930cfa
ocserv[21260]: TLS[<9>]: INT: CLIENT RANDOM[32]: 344065b6ade1ff3b53858671b220c2f4cd716edc7ba7d33e159059c7be6f2ff1
ocserv[21260]: TLS[<9>]: INT: SERVER RANDOM[32]: 574ec2ec14960a17da7d2e7f9aa15b823542f236e37af94ee12c144598dc44fc
ocserv[21260]: TLS[<9>]: INT: MASTER SECRET: f170560da034b01b25dd60b91702170a93b285b5c8d7976a9df0f9deabc7f8241d151db905497e221b2ca76c08d8a765
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Initializing epoch #1
ocserv[21260]: TLS[<9>]: INT: KEY BLOCK[104]: 12fa68258d61612a013830d0c2b9abc5b7616c255c7cf6a284debb6a85715328
ocserv[21260]: TLS[<9>]: INT: CLIENT WRITE KEY [16]: cdec2ad49fe93cc8db41f4b2242f6d2c
ocserv[21260]: TLS[<9>]: INT: SERVER WRITE KEY [16]: 1a7a4ced4a4b543d2d6ad247b8748028
ocserv[21260]: TLS[<9>]: INT: CLIENT WRITE IV [16]: 6c4e5f7ff1e379a2417250116dbe53dd
ocserv[21260]: TLS[<9>]: INT: SERVER WRITE IV [16]: 836f6ec5f1587fecfee59579fdf2dac6
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Epoch #1 ready
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Cipher Suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 48
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 48
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[0] Handshake(22) with length: 16
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: FINISHED (20) was received. Length 12[12], frag offset 0, frag length: 12, sequence: 0
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: recording tls-unique CB (recv)
ocserv[21260]: TLS[<4>]: REC[0x55d59c6f6000]: Sent ChangeCipherSpec
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Cipher Suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: Initializing internal [write] cipher sessions
ocserv[21260]: TLS[<4>]: HSK[0x55d59c6f6000]: FINISHED was queued [16 bytes]
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[5] ChangeCipherSpec(20) in epoch 0 and length: 6
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 16 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: AES-128-CBC, MAC: SHA1, Epoch: 1
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 53
ocserv[21260]: worker: sending message 'resume data store request' to main
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Start of epoch cleanup
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Epoch #0 freed
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: End of epoch cleanup
ocserv[21260]: worker: TLS handshake completed
ocserv[21260]: worker: sending message 'session info' to main
ocserv[21258]: main: 77.111.214.227:3788 main received message 'resume data store request' of 273 bytes
ocserv[21258]: main: 77.111.214.227:3788 TLS session DB storing 8f38f8c16ddf7aa15b94f392cae4b6919d126b8aa4b334cea726281b1d4da052
ocserv[21258]: main: 77.111.214.227:3788 main received message 'session info' of 6 bytes
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Application Data packet received. Epoch 0, length: 32
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Application Data(23)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Application Data(23) with length: 32
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[1] Application Data(23) with length: 0
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Application Data packet received. Epoch 0, length: 192
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Application Data(23)
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Application Data(23) with length: 192
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[2] Application Data(23) with length: 166
ocserv[21260]: worker: 77.111.214.227 HTTP processing: Host: pbx-master.atomic.co.uk
ocserv[21260]: worker: 77.111.214.227 HTTP processing: User-Agent: Open AnyConnect VPN Agent v2.25-unknown
ocserv[21260]: worker: 77.111.214.227 User-agent: 'Open AnyConnect VPN Agent v2.25-unknown'
ocserv[21260]: worker: 77.111.214.227 HTTP processing: Accept: */*
ocserv[21260]: worker: 77.111.214.227 HTTP processing: Accept-Encoding: identity
ocserv[21260]: worker: 77.111.214.227 HTTP processing: X-Transcend-Version: 1
ocserv[21260]: worker: 77.111.214.227 HTTP GET /
ocserv[21260]: worker: 77.111.214.227 HTTP sending: 200 OK
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Application Data(23) with length: 477 and min pad: 0
ocserv[21260]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: AES-128-CBC, MAC: SHA1, Epoch: 1
ocserv[21260]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[2] Application Data(23) in epoch 1 and length: 517
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_buffers.c:592
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_record.c:1038
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_record.c:1158
ocserv[21260]: TLS[<3>]: ASSERT: gnutls_record.c:1410
ocserv[21258]: main: 77.111.214.227:3788 command socket closed
ocserv[21258]: main: 77.111.214.227:3788 user disconnected (rx: 0, tx: 0)
ocserv[21261]: worker: accepted connection
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Allocating epoch #0
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_constate.c:596
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Allocating epoch #1
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 135
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 135
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[0] Handshake(22) with length: 135
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: CLIENT HELLO (1) was received. Length 131[131], frag offset 0, frag length: 131, sequence: 0
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Client's version: 3.1
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected version TLS1.0
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_db.c:263
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC/10'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SESSION TICKET/35'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SUPPORTED ECC/10'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SESSION TICKET/35' (0 bytes)
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SUPPORTED ECC POINT FORMATS/11' (4 bytes)
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Parsing extension 'SUPPORTED ECC/10' (10 bytes)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected ECC curve SECP521R1 (4)
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension 'SESSION TICKET/35'
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Found extension '(null)/15'
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Received safe renegotiation CS
ocserv[21261]: TLS[<3>]: ASSERT: server_name.c:307
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Requested PK algorithm: RSA (1) -- ctype: X.509 (1)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Requested cipher suites[size: 58]:
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected cipher suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Selected Compression Method: NULL
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Safe renegotiation succeeded
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Sending extension SAFE RENEGOTIATION (1 bytes)
ocserv[21261]: TLS[<4>]: EXT[0x55d59c6f6000]: Sending extension SUPPORTED ECC POINT FORMATS (2 bytes)
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: SessionID: 3c3bbb3e022363e3e9a11e4504c0df97463928d9257d4fae71dc27a68a403945
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER HELLO was queued [87 bytes]
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: CERTIFICATE was queued [2489 bytes]
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: signing handshake data: using RSA-SHA1
ocserv[21259]: sec-mod: received request from pid 21261 and uid 65534
ocserv[21259]: sec-mod: cmd [size=40] sm: sign
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER KEY EXCHANGE was queued [399 bytes]
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: SERVER HELLO DONE was queued [4 bytes]
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 87 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 92
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 2489 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[2] Handshake(22) in epoch 0 and length: 2494
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 399 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[3] Handshake(22) in epoch 0 and length: 404
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 4 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[4] Handshake(22) in epoch 0 and length: 9
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 138
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 138
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[1] Handshake(22) with length: 138
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: CLIENT KEY EXCHANGE (16) was received. Length 134[134], frag offset 0, frag length: 134, sequence: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 ChangeCipherSpec packet received. Epoch 0, length: 1
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet ChangeCipherSpec(20)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet ChangeCipherSpec(20) with length: 1
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[2] ChangeCipherSpec(20) with length: 1
ocserv[21261]: TLS[<9>]: INT: PREMASTER SECRET[66]: 012f3467549e74401260e4ca187ac22018f827201435c8ddd552f99ec2c1435b49394c953962ec0a4d471bef3cbd81292ac6073d87b375a38712d281d1ff8279f973
ocserv[21261]: TLS[<9>]: INT: CLIENT RANDOM[32]: 716514f752aa5b9facff5ee4835db7cba33e2a97dc93a27885ec18fe806d7024
ocserv[21261]: TLS[<9>]: INT: SERVER RANDOM[32]: 574ec283fa95492328d1d703552454adf9b4e9c103a6437952f4a43e8b51b783
ocserv[21261]: TLS[<9>]: INT: MASTER SECRET: 789ced487c40473f37862da244b60b0b247c7c0784bcfe26cffcc83dc90132c30ed46fba9230925b01e79a1fcd035107
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Initializing epoch #1
ocserv[21261]: TLS[<9>]: INT: KEY BLOCK[104]: 36ee1b9212cc7e67c1a3e462a9b8308b07957eae9671c086d996ffd919d390fe
ocserv[21261]: TLS[<9>]: INT: CLIENT WRITE KEY [16]: 8ca4e884b71170366274f38cbf5a36f1
ocserv[21261]: TLS[<9>]: INT: SERVER WRITE KEY [16]: b36c4792247e3a4f169844dd5a545069
ocserv[21261]: TLS[<9>]: INT: CLIENT WRITE IV [16]: 164b4bfb4fe8d365ea1d99eb9f99572f
ocserv[21261]: TLS[<9>]: INT: SERVER WRITE IV [16]: 6d660364b6cf88fa2f13e94f11bf4863
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Epoch #1 ready
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Cipher Suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Handshake packet received. Epoch 0, length: 48
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Handshake(22)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Handshake(22) with length: 48
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[0] Handshake(22) with length: 16
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: FINISHED (20) was received. Length 12[12], frag offset 0, frag length: 12, sequence: 0
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: recording tls-unique CB (recv)
ocserv[21261]: TLS[<4>]: REC[0x55d59c6f6000]: Sent ChangeCipherSpec
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Cipher Suite: ECDHE_RSA_AES_128_CBC_SHA1
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: Initializing internal [write] cipher sessions
ocserv[21261]: TLS[<4>]: HSK[0x55d59c6f6000]: FINISHED was queued [16 bytes]
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[5] ChangeCipherSpec(20) in epoch 0 and length: 6
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Handshake(22) with length: 16 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: AES-128-CBC, MAC: SHA1, Epoch: 1
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 53
ocserv[21261]: worker: sending message 'resume data store request' to main
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Start of epoch cleanup
ocserv[21258]: main: 77.111.214.227:3789 main received message 'resume data store request' of 273 bytes
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Epoch #0 freed
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: End of epoch cleanup
ocserv[21261]: worker: TLS handshake completed
ocserv[21261]: worker: sending message 'session info' to main
ocserv[21258]: main: 77.111.214.227:3789 TLS session DB storing 3c3bbb3e022363e3e9a11e4504c0df97463928d9257d4fae71dc27a68a403945
ocserv[21258]: main: 77.111.214.227:3789 main received message 'session info' of 6 bytes
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Application Data packet received. Epoch 0, length: 32
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Application Data(23)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Application Data(23) with length: 32
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[1] Application Data(23) with length: 0
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: SSL 3.1 Application Data packet received. Epoch 0, length: 192
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Expected Packet Application Data(23)
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Received Packet Application Data(23) with length: 192
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Decrypted Packet[2] Application Data(23) with length: 166
ocserv[21261]: worker: 77.111.214.227 HTTP processing: Host: pbx-master.atomic.co.uk
ocserv[21261]: worker: 77.111.214.227 HTTP processing: User-Agent: Open AnyConnect VPN Agent v2.25-unknown
ocserv[21261]: worker: 77.111.214.227 User-agent: 'Open AnyConnect VPN Agent v2.25-unknown'
ocserv[21261]: worker: 77.111.214.227 HTTP processing: Accept: */*
ocserv[21261]: worker: 77.111.214.227 HTTP processing: Accept-Encoding: identity
ocserv[21261]: worker: 77.111.214.227 HTTP processing: X-Transcend-Version: 1
ocserv[21261]: worker: 77.111.214.227 HTTP GET /
ocserv[21261]: worker: 77.111.214.227 HTTP sending: 200 OK
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Preparing Packet Application Data(23) with length: 477 and min pad: 0
ocserv[21261]: TLS[<9>]: ENC[0x55d59c6f6000]: cipher: AES-128-CBC, MAC: SHA1, Epoch: 1
ocserv[21261]: TLS[<5>]: REC[0x55d59c6f6000]: Sent Packet[2] Application Data(23) in epoch 1 and length: 517
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_buffers.c:592
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_record.c:1038
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_record.c:1158
ocserv[21261]: TLS[<3>]: ASSERT: gnutls_record.c:1410
ocserv[21258]: main: 77.111.214.227:3789 command socket closed
ocserv[21258]: main: 77.111.214.227:3789 user disconnected (rx: 0, tx: 0)
When using Ubuntu and NetworkManager the connection succeeds with normal looking debug
Setting 'plain' as primary authentication method
listening (TCP) on 0.0.0.0:443...
listening (UDP) on 0.0.0.0:443...
ocserv[21394]: main: initializing control unix socket: /var/run/occtl.socket
ocserv[21394]: main: initialized ocserv 0.10.11
ocserv[21395]: sec-mod: reading supplemental config from files
ocserv[21395]: sec-mod: sec-mod initialized (socket: /var/run/ocserv-socket.21394)
ocserv[21394]: TLS[<3>]: ASSERT: mpi.c:246
ocserv[21394]: TLS[<3>]: ASSERT: gnutls_dh.c:332
ocserv[21394]: TLS[<3>]: ASSERT: common.c:1110
ocserv[21395]: sec-mod: received request from pid 21394 and uid 0
ocserv[21395]: sec-mod: cmd [size=55] sm: sign
ocserv[21396]: worker: accepted connection
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Allocating epoch #0
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_constate.c:596
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Allocating epoch #1
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.1 Handshake packet received. Epoch 0, length: 518
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 518
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[0] Handshake(22) with length: 518
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: CLIENT HELLO (1) was received. Length 514[514], frag offset 0, frag length: 514, sequence: 0
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Client's version: 3.3
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Selected version TLS1.2
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_db.c:263
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'STATUS REQUEST/5'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SERVER NAME/0' (28 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SAFE RENEGOTIATION/65281'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SESSION TICKET/35'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC/10'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SIGNATURE ALGORITHMS/13'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'DUMBFW/21'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'STATUS REQUEST/5'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SERVER NAME/0'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SAFE RENEGOTIATION/65281' (1 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SESSION TICKET/35' (0 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC/10'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SIGNATURE ALGORITHMS/13'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'DUMBFW/21'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'STATUS REQUEST/5' (5 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SERVER NAME/0'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SAFE RENEGOTIATION/65281'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SESSION TICKET/35'
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SUPPORTED ECC/10' (12 bytes)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Selected ECC curve SECP256R1 (2)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SUPPORTED ECC POINT FORMATS/11' (2 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SIGNATURE ALGORITHMS/13' (28 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.1) RSA-SHA256
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.2) DSA-SHA256
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.3) ECDSA-SHA256
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (5.1) RSA-SHA384
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (5.3) ECDSA-SHA384
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (6.1) RSA-SHA512
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (6.3) ECDSA-SHA512
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.1) RSA-SHA224
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.2) DSA-SHA224
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.3) ECDSA-SHA224
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.1) RSA-SHA1
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.2) DSA-SHA1
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.3) ECDSA-SHA1
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'DUMBFW/21'
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Requested PK algorithm: EC (4) -- ctype: X.509 (1)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Requested PK algorithm: RSA (1) -- ctype: X.509 (1)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_GCM_SHA256 (C0.2F)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_GCM_SHA384 (C0.30)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_128_GCM_SHA256 (C0.8A)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_256_GCM_SHA384 (C0.8B)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA256 (C0.27)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA384 (C0.28)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_128_CBC_SHA256 (C0.76)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_256_CBC_SHA384 (C0.77)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_GCM_SHA256 (00.9C)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_GCM_SHA384 (00.9D)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_GCM_SHA256 (C0.7A)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_GCM_SHA384 (C0.7B)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA256 (00.3C)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA256 (00.3D)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA256 (00.BA)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA256 (00.C0)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CCM (C0.9C)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CCM (C0.9D)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_GCM_SHA256 (00.9E)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_GCM_SHA384 (00.9F)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_GCM_SHA256 (C0.7C)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_GCM_SHA384 (C0.7D)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA256 (00.67)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA256 (00.6B)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA256 (00.BE)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA256 (00.C4)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CCM (C0.9E)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CCM (C0.9F)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Requested cipher suites[size: 132]:
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Selected cipher suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Selected Compression Method: NULL
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Safe renegotiation succeeded
ocserv[21396]: TLS[<3>]: ASSERT: status_request.c:218
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Sending extension SAFE RENEGOTIATION (1 bytes)
ocserv[21396]: TLS[<4>]: EXT[0x55fc79c35000]: Sending extension SUPPORTED ECC POINT FORMATS (2 bytes)
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: SessionID: 3bc6b7521620696efa38d5537b9c34e715edc920afa65a7e8084c05c7ef166fd
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER HELLO was queued [87 bytes]
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: CERTIFICATE was queued [2489 bytes]
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: signing handshake data: using RSA-SHA256
ocserv[21395]: sec-mod: received request from pid 21396 and uid 65534
ocserv[21395]: sec-mod: cmd [size=55] sm: sign
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER KEY EXCHANGE was queued [333 bytes]
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER HELLO DONE was queued [4 bytes]
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 87 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 92
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 2489 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[2] Handshake(22) in epoch 0 and length: 2494
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 333 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[3] Handshake(22) in epoch 0 and length: 338
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 4 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[4] Handshake(22) in epoch 0 and length: 9
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Handshake packet received. Epoch 0, length: 70
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 70
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[1] Handshake(22) with length: 70
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: CLIENT KEY EXCHANGE (16) was received. Length 66[66], frag offset 0, frag length: 66, sequence: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 0, length: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet ChangeCipherSpec(20)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet ChangeCipherSpec(20) with length: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[2] ChangeCipherSpec(20) with length: 1
ocserv[21396]: TLS[<9>]: INT: PREMASTER SECRET[32]: ba9023effecee9cddc16a9a205effa9d216ee1d309c849f1f14f25e65a0ca1a4
ocserv[21396]: TLS[<9>]: INT: CLIENT RANDOM[32]: 574ec382583409c3961cd1d38574f0b0b7ccfadb0385c9da485c8246117a9b2c
ocserv[21396]: TLS[<9>]: INT: SERVER RANDOM[32]: 574ec309a6ed5eb7811cc54cc8e72965e8772cab9d7d160880688967fbf1f962
ocserv[21396]: TLS[<9>]: INT: MASTER SECRET: b3badfbc1525fdf8abd62854211588c6f26b271a3e8f17649ec92474876387d954db21221bfa0b8058508a435437cac6
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Initializing epoch #1
ocserv[21396]: TLS[<9>]: INT: KEY BLOCK[40]: 88aedf7c2200209a8deae326576abc8d809d7748b339f1265998c569892fea10
ocserv[21396]: TLS[<9>]: INT: CLIENT WRITE KEY [16]: 88aedf7c2200209a8deae326576abc8d
ocserv[21396]: TLS[<9>]: INT: SERVER WRITE KEY [16]: 809d7748b339f1265998c569892fea10
ocserv[21396]: TLS[<9>]: INT: CLIENT WRITE IV [4]: 2d06c2ca
ocserv[21396]: TLS[<9>]: INT: SERVER WRITE IV [4]: 2bd0ee48
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Epoch #1 ready
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Cipher Suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Handshake packet received. Epoch 0, length: 40
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 40
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[0] Handshake(22) with length: 16
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: FINISHED (20) was received. Length 12[12], frag offset 0, frag length: 12, sequence: 0
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: recording tls-unique CB (recv)
ocserv[21396]: TLS[<4>]: REC[0x55fc79c35000]: Sent ChangeCipherSpec
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Cipher Suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: Initializing internal [write] cipher sessions
ocserv[21396]: TLS[<4>]: HSK[0x55fc79c35000]: FINISHED was queued [16 bytes]
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[5] ChangeCipherSpec(20) in epoch 0 and length: 6
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 16 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 45
ocserv[21396]: worker: sending message 'resume data store request' to main
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Start of epoch cleanup
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Epoch #0 freed
ocserv[21394]: main: 77.111.214.227:46958 main received message 'resume data store request' of 392 bytes
ocserv[21394]: main: 77.111.214.227:46958 TLS session DB storing 3bc6b7521620696efa38d5537b9c34e715edc920afa65a7e8084c05c7ef166fd
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: End of epoch cleanup
ocserv[21396]: worker: TLS handshake completed
ocserv[21396]: worker: sending message 'session info' to main
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Application Data packet received. Epoch 0, length: 612
ocserv[21394]: main: 77.111.214.227:46958 main received message 'session info' of 6 bytes
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Application Data(23)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Application Data(23) with length: 612
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[1] Application Data(23) with length: 588
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Host: pbx-master.atomic.co.uk
ocserv[21396]: worker: 77.111.214.227 HTTP processing: User-Agent: OpenConnect VPN Agent (NetworkManager) v7.06
ocserv[21396]: worker: 77.111.214.227 User-agent: 'OpenConnect VPN Agent (NetworkManager) v7.06'
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Accept: */*
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Accept-Encoding: identity
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Transcend-Version: 1
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Aggregate-Auth: 1
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-AnyConnect-Platform: linux-64
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Support-HTTP-Auth: true
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Pad: 000000000000000000000000000000000000000
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Content-Type: application/x-www-form-urlencoded
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Content-Length: 217
ocserv[21396]: worker: 77.111.214.227 HTTP POST /
ocserv[21396]: worker: 77.111.214.227 POST body: '<?xml version="1.0" encoding="UTF-8"?>
<config-auth client="vpn" type="init"><version who="vpn">v7.06</version><device-id>linux-64</device-id><group-access>https://pbx-master.atomic.co.uk</group-access></config-auth>
'
ocserv[21396]: worker: 77.111.214.227 cannot find 'group-select' in client XML message
ocserv[21396]: worker: 77.111.214.227 cannot find 'group-select' in client XML message
ocserv[21396]: worker: 77.111.214.227 failed reading groupname
ocserv[21396]: worker: 77.111.214.227 cannot find 'username' in client XML message
ocserv[21396]: worker: 77.111.214.227 failed reading username
ocserv[21396]: worker: 77.111.214.227 HTTP sending: 200 OK
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Application Data(23) with length: 477 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[2] Application Data(23) in epoch 1 and length: 506
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Application Data packet received. Epoch 0, length: 616
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Application Data(23)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Application Data(23) with length: 616
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[2] Application Data(23) with length: 592
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Host: pbx-master.atomic.co.uk
ocserv[21396]: worker: 77.111.214.227 HTTP processing: User-Agent: OpenConnect VPN Agent (NetworkManager) v7.06
ocserv[21396]: worker: 77.111.214.227 User-agent: 'OpenConnect VPN Agent (NetworkManager) v7.06'
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Accept: */*
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Accept-Encoding: identity
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Transcend-Version: 1
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Aggregate-Auth: 1
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-AnyConnect-Platform: linux-64
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Support-HTTP-Auth: true
ocserv[21396]: worker: 77.111.214.227 HTTP processing: X-Pad: 0000000000000000000000000000000000000000000000000000
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Content-Type: application/x-www-form-urlencoded
ocserv[21396]: worker: 77.111.214.227 HTTP processing: Content-Length: 204
ocserv[21396]: worker: 77.111.214.227 HTTP POST /auth
ocserv[21396]: worker: 77.111.214.227 POST body: '<?xml version="1.0" encoding="UTF-8"?>
<config-auth client="vpn" type="auth-reply"><version who="vpn">v7.06</version><device-id>linux-64</device-id><auth><username>example</username></auth></config-auth>
'
ocserv[21396]: worker: 77.111.214.227 cannot find 'group-select' in client XML message
ocserv[21396]: worker: 77.111.214.227 cannot find 'group-select' in client XML message
ocserv[21396]: worker: 77.111.214.227 failed reading groupname
ocserv[21395]: sec-mod: received request from pid 21396 and uid 65534
ocserv[21396]: worker[example]: 77.111.214.227 sending message 'sm: auth init' to secmod
ocserv[21395]: sec-mod: cmd [size=47] sm: auth init
ocserv[21395]: sec-mod: using 'plain' authentication to authenticate user (session: SWm1V)
ocserv[21395]: sec-mod: auth init for user 'example' (session: SWm1V) of group: '*' from '77.111.214.227'
ocserv[21396]: worker[example]: 77.111.214.227 received auth reply message (value: 2)
ocserv[21396]: worker[example]: 77.111.214.227 continuing authentication for 'example'
ocserv[21396]: worker[example]: 77.111.214.227 HTTP sending: 200 OK
ocserv[21396]: worker[example]: 77.111.214.227 sent sid: SWm1Vif0APMNTMcJSSLxCw==
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Application Data(23) with length: 471 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[3] Application Data(23) in epoch 1 and length: 500
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Application Data packet received. Epoch 0, length: 664
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Application Data(23)
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Application Data(23) with length: 664
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[3] Application Data(23) with length: 640
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Host: pbx-master.atomic.co.uk
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: User-Agent: OpenConnect VPN Agent (NetworkManager) v7.06
ocserv[21396]: worker[example]: 77.111.214.227 User-agent: 'OpenConnect VPN Agent (NetworkManager) v7.06'
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Cookie: webvpncontext=SWm1Vif0APMNTMcJSSLxCw==
ocserv[21396]: worker[example]: 77.111.214.227 received sid: SWm1Vif0APMNTMcJSSLxCw==
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Accept: */*
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Accept-Encoding: identity
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: X-Transcend-Version: 1
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: X-Aggregate-Auth: 1
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: X-AnyConnect-Platform: linux-64
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: X-Support-HTTP-Auth: true
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: X-Pad: 0000000000000000000000000000000000000
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Content-Type: application/x-www-form-urlencoded
ocserv[21396]: worker[example]: 77.111.214.227 HTTP processing: Content-Length: 219
ocserv[21396]: worker[example]: 77.111.214.227 HTTP POST /auth
ocserv[21396]: worker[example]: 77.111.214.227 POST body: '<?xml version="1.0" encoding="UTF-8"?>
<config-auth client="vpn" type="auth-reply"><version who="vpn">v7.06</version><device-id>linux-64</device-id><auth><password>superstrongpassword123</password></auth></config-auth>
'
ocserv[21395]: sec-mod: received request from pid 21396 and uid 65534
ocserv[21396]: worker[example]: 77.111.214.227 sending message 'sm: auth cont' to secmod
ocserv[21395]: sec-mod: cmd [size=58] sm: auth cont
ocserv[21395]: sec-mod: auth cont for user 'example' (session: SWm1V)
ocserv[21396]: worker[example]: 77.111.214.227 received auth reply message (value: 1)
ocserv[21396]: worker[example]: 77.111.214.227 user 'example' obtained cookie
ocserv[21396]: worker[example]: 77.111.214.227 HTTP sending: 200 OK
ocserv[21396]: worker[example]: 77.111.214.227 sent sid: SWm1Vif0APMNTMcJSSLxCw==
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Application Data(23) with length: 679 and min pad: 0
ocserv[21396]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21396]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[4] Application Data(23) in epoch 1 and length: 708
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_buffers.c:592
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_record.c:1038
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_record.c:1158
ocserv[21396]: TLS[<3>]: ASSERT: gnutls_record.c:1410
ocserv[21394]: main: 77.111.214.227:46958 command socket closed
ocserv[21394]: main: 77.111.214.227:46958 user disconnected (rx: 0, tx: 0)
ocserv[21397]: worker: accepted connection
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Allocating epoch #0
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_constate.c:596
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Allocating epoch #1
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.1 Handshake packet received. Epoch 0, length: 249
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 249
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[0] Handshake(22) with length: 249
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: CLIENT HELLO (1) was received. Length 245[245], frag offset 0, frag length: 245, sequence: 0
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Client's version: 3.3
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Selected version TLS1.2
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_db.c:263
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'STATUS REQUEST/5'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SAFE RENEGOTIATION/65281'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SESSION TICKET/35'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC/10'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SIGNATURE ALGORITHMS/13'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'STATUS REQUEST/5'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SAFE RENEGOTIATION/65281' (1 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SESSION TICKET/35' (0 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC/10'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SUPPORTED ECC POINT FORMATS/11'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SIGNATURE ALGORITHMS/13'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'STATUS REQUEST/5' (5 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SAFE RENEGOTIATION/65281'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Found extension 'SESSION TICKET/35'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SUPPORTED ECC/10' (12 bytes)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Selected ECC curve SECP256R1 (2)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SUPPORTED ECC POINT FORMATS/11' (2 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Parsing extension 'SIGNATURE ALGORITHMS/13' (28 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.1) RSA-SHA256
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.2) DSA-SHA256
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (4.3) ECDSA-SHA256
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (5.1) RSA-SHA384
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (5.3) ECDSA-SHA384
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (6.1) RSA-SHA512
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (6.3) ECDSA-SHA512
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.1) RSA-SHA224
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.2) DSA-SHA224
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (3.3) ECDSA-SHA224
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.1) RSA-SHA1
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.2) DSA-SHA1
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: rcvd signature algo (2.3) ECDSA-SHA1
ocserv[21397]: TLS[<3>]: ASSERT: server_name.c:307
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Requested PK algorithm: EC (4) -- ctype: X.509 (1)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Requested PK algorithm: RSA (1) -- ctype: X.509 (1)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_GCM_SHA256 (C0.2F)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_GCM_SHA384 (C0.30)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_128_GCM_SHA256 (C0.8A)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_256_GCM_SHA384 (C0.8B)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA256 (C0.27)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA384 (C0.28)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_128_CBC_SHA256 (C0.76)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_CAMELLIA_256_CBC_SHA384 (C0.77)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_GCM_SHA256 (00.9C)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_GCM_SHA384 (00.9D)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_GCM_SHA256 (C0.7A)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_GCM_SHA384 (C0.7B)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA256 (00.3C)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA256 (00.3D)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA256 (00.BA)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA256 (00.C0)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CCM (C0.9C)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CCM (C0.9D)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_GCM_SHA256 (00.9E)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_GCM_SHA384 (00.9F)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_GCM_SHA256 (C0.7C)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_GCM_SHA384 (C0.7D)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA256 (00.67)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA256 (00.6B)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA256 (00.BE)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA256 (00.C4)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CCM (C0.9E)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CCM (C0.9F)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Requested cipher suites[size: 132]:
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Selected cipher suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Selected Compression Method: NULL
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Safe renegotiation succeeded
ocserv[21397]: TLS[<3>]: ASSERT: status_request.c:218
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Sending extension SAFE RENEGOTIATION (1 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c35000]: Sending extension SUPPORTED ECC POINT FORMATS (2 bytes)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: SessionID: 075dc163219e0934a5e12a500b0d42c3e23d278fbe7bdeb4ae77e00a984e6755
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER HELLO was queued [87 bytes]
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: CERTIFICATE was queued [2489 bytes]
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: signing handshake data: using RSA-SHA256
ocserv[21395]: sec-mod: received request from pid 21397 and uid 65534
ocserv[21395]: sec-mod: cmd [size=55] sm: sign
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER KEY EXCHANGE was queued [333 bytes]
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: SERVER HELLO DONE was queued [4 bytes]
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 87 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[1] Handshake(22) in epoch 0 and length: 92
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 2489 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[2] Handshake(22) in epoch 0 and length: 2494
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 333 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[3] Handshake(22) in epoch 0 and length: 338
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 4 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[4] Handshake(22) in epoch 0 and length: 9
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Handshake packet received. Epoch 0, length: 70
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 70
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[1] Handshake(22) with length: 70
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: CLIENT KEY EXCHANGE (16) was received. Length 66[66], frag offset 0, frag length: 66, sequence: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 ChangeCipherSpec packet received. Epoch 0, length: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet ChangeCipherSpec(20)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet ChangeCipherSpec(20) with length: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[2] ChangeCipherSpec(20) with length: 1
ocserv[21397]: TLS[<9>]: INT: PREMASTER SECRET[32]: f0f2da36fc3870660bd0ee295244330db263ac73e2df5b54f9afadccdc610c82
ocserv[21397]: TLS[<9>]: INT: CLIENT RANDOM[32]: 574ec396287455283439b74b05ad13694cec0f15a6e3599b535f577b51b9b270
ocserv[21397]: TLS[<9>]: INT: SERVER RANDOM[32]: 574ec3ee0d4e787e932805543df0e1e44b16557151da8ed28d90dad532fcadf6
ocserv[21397]: TLS[<9>]: INT: MASTER SECRET: ae4d69ea009e4a18fd8760bc8c4ee69fcf0c40fa25e1fdbd2ac7e6ac1cf1ccb7a9499751b2e49bc8570e33dd9938b6d3
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Initializing epoch #1
ocserv[21397]: TLS[<9>]: INT: KEY BLOCK[40]: 099f2262197c5eaee5f933a27228d4e6de81a45a40461c7c92751fd5c56aa081
ocserv[21397]: TLS[<9>]: INT: CLIENT WRITE KEY [16]: 099f2262197c5eaee5f933a27228d4e6
ocserv[21397]: TLS[<9>]: INT: SERVER WRITE KEY [16]: de81a45a40461c7c92751fd5c56aa081
ocserv[21397]: TLS[<9>]: INT: CLIENT WRITE IV [4]: 59f4aac8
ocserv[21397]: TLS[<9>]: INT: SERVER WRITE IV [4]: a04723cb
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Epoch #1 ready
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Cipher Suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:1154
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Handshake packet received. Epoch 0, length: 40
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Handshake(22)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Handshake(22) with length: 40
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[0] Handshake(22) with length: 16
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: FINISHED (20) was received. Length 12[12], frag offset 0, frag length: 12, sequence: 0
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: recording tls-unique CB (recv)
ocserv[21397]: TLS[<4>]: REC[0x55fc79c35000]: Sent ChangeCipherSpec
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Cipher Suite: ECDHE_RSA_AES_128_GCM_SHA256
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: Initializing internal [write] cipher sessions
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c35000]: FINISHED was queued [16 bytes]
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[5] ChangeCipherSpec(20) in epoch 0 and length: 6
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Handshake(22) with length: 16 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[1] Handshake(22) in epoch 1 and length: 45
ocserv[21397]: worker: sending message 'resume data store request' to main
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Start of epoch cleanup
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Epoch #0 freed
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: End of epoch cleanup
ocserv[21397]: worker: TLS handshake completed
ocserv[21397]: worker: sending message 'session info' to main
ocserv[21394]: main: 77.111.214.227:46962 main received message 'resume data store request' of 349 bytes
ocserv[21394]: main: 77.111.214.227:46962 TLS session DB storing 075dc163219e0934a5e12a500b0d42c3e23d278fbe7bdeb4ae77e00a984e6755
ocserv[21394]: main: 77.111.214.227:46962 main received message 'session info' of 6 bytes
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: SSL 3.3 Application Data packet received. Epoch 0, length: 706
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Expected Packet Application Data(23)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Received Packet Application Data(23) with length: 706
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Decrypted Packet[1] Application Data(23) with length: 682
ocserv[21397]: worker: 77.111.214.227 HTTP processing: Host: 77.111.214.250
ocserv[21397]: worker: 77.111.214.227 HTTP processing: User-Agent: Open AnyConnect VPN Agent v7.06
ocserv[21397]: worker: 77.111.214.227 User-agent: 'Open AnyConnect VPN Agent v7.06'
ocserv[21397]: worker: 77.111.214.227 HTTP processing: Cookie: webvpn=Li6INpJiNlYTddm/LqnX+Pbxs4WQexOPz4rG7hydWjJhvuG367WuU+rnHDeJw8zHxR5VEC4UZbNWbi4s4MPxPHf5cu3sbj7vYD9L7CEn1HVsxZ5KdCQ=
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-Version: 1
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-Hostname: jacek-work-desktop
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-Accept-Encoding: oc-lz4,lzs
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-MTU: 1406
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-Address-Type: IPv6,IPv4
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-CSTP-Full-IPv6-Capability: true
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-DTLS-Master-Secret: 14358A5FAEF781901F0E4217578BFD04A6E20112200E9B540F31958C03108E7812CD812E47A40CA8BEE21C0282B95ED9
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-DTLS-CipherSuite: OC-DTLS1_2-AES256-GCM:OC-DTLS1_2-AES128-GCM:AES256-SHA:AES128-SHA:DES-CBC3-SHA:DES-CBC-SHA
ocserv[21397]: worker: 77.111.214.227 HTTP processing: X-DTLS-Accept-Encoding: oc-lz4,lzs
ocserv[21397]: worker: 77.111.214.227 HTTP CONNECT /CSCOSSLC/tunnel
ocserv[21397]: worker: 77.111.214.227 sending message 'auth cookie request' to main
ocserv[21394]: main: 77.111.214.227:46962 main received message 'auth cookie request' of 88 bytes
ocserv[21394]: main[example]: 77.111.214.227:46962 sending msg sm: session open to sec-mod
ocserv[21395]: sec-mod: received request sm: session open
ocserv[21395]: sec-mod: cmd [size=112] sm: session open
ocserv[21395]: sec-mod: initiating session for user 'example' (session: SWm1V)
ocserv[21394]: main[example]: 77.111.214.227:46962 new user session
ocserv[21394]: main[example]: 77.111.214.227:46962 selected IP: 10.13.20.184
ocserv[21394]: main[example]: 77.111.214.227:46962 assigned IPv4: 10.13.20.184
ocserv[21394]: main[example]: 77.111.214.227:46962 assigning tun device vpns0
ocserv[21394]: main[example]: 77.111.214.227:46962 user of group '*' authenticated (using cookie)
ocserv[21394]: main[example]: 77.111.214.227:46962 sending (socket) message 2 to worker
ocserv[21394]: main[example]: 77.111.214.227:46962 user logged in
ocserv[21397]: worker: 77.111.214.227 received auth reply message (value: 1)
ocserv[21397]: worker[example]: 77.111.214.227 suggesting DPD of 90 secs
ocserv[21397]: worker[example]: 77.111.214.227 reducing MTU due to TCP MSS to 1435 (from 1500)
ocserv[21397]: worker[example]: 77.111.214.227 CSTP Base MTU is 1435 bytes
ocserv[21397]: worker[example]: 77.111.214.227 sending IPv4 10.13.20.184
ocserv[21397]: worker[example]: 77.111.214.227 adding DNS 77.111.214.254
ocserv[21397]: worker[example]: 77.111.214.227 Include route 10.13.0.0/255.255.0.0
ocserv[21397]: worker[example]: 77.111.214.227 DTLS ciphersuite: OC-DTLS1_2-AES128-GCM
ocserv[21397]: worker[example]: 77.111.214.227 DTLS overhead is 66
ocserv[21397]: worker[example]: 77.111.214.227 suggesting DTLS MTU 1369
ocserv[21397]: worker[example]: 77.111.214.227 setsockopt(UDP, SO_RCVTIMEO) failed.
ocserv[21397]: worker[example]: 77.111.214.227 sending message 'tun mtu change' to main
ocserv[21397]: worker[example]: 77.111.214.227 setting MTU to 1369
ocserv[21397]: worker[example]: 77.111.214.227 selected DTLS compression method oc-lz4
ocserv[21397]: worker[example]: 77.111.214.227 selected CSTP compression method oc-lz4
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Application Data(23) with length: 937 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21394]: main[example]: 77.111.214.227:46962 main received message 'tun mtu change' of 3 bytes
ocserv[21394]: main[example]: 77.111.214.227:46962 setting vpns0 MTU to 1369
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[2] Application Data(23) in epoch 1 and length: 966
ocserv[21394]: main: new DTLS session from 77.111.214.227:50435 (record v254.253, hello v1.0)
ocserv[21394]: main[example]: 77.111.214.227:46962 sending (socket) message 10 to worker
ocserv[21394]: main[example]: 77.111.214.227:46962 passed UDP socket from 77.111.214.227:50435
ocserv[21397]: worker[example]: 77.111.214.227 worker received message udp fd of 156 bytes
ocserv[21397]: worker[example]: 77.111.214.227 received new UDP fd and connected to peer
ocserv[21397]: worker[example]: 77.111.214.227 setting up DTLS connection
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Allocating epoch #0
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_constate.c:596
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Allocating epoch #1
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:1158
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: SSL 254.253 Handshake packet received. Epoch 0, length: 138
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Expected Packet Handshake(22)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Received Packet Handshake(22) with length: 138
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Decrypted Packet[0.0] Handshake(22) with length: 138
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: CLIENT HELLO (1) was received. Length 126[126], frag offset 0, frag length: 126, sequence: 0
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Client's version: 254.253
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Selected version DTLS1.2
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c460f0]: Found extension 'STATUS REQUEST/5'
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c460f0]: Parsing extension 'SAFE RENEGOTIATION/65281' (1 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c460f0]: Parsing extension 'SESSION TICKET/35' (0 bytes)
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c460f0]: Found extension 'SIGNATURE ALGORITHMS/13'
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Safe renegotiation succeeded
ocserv[21397]: TLS[<4>]: EXT[0x55fc79c460f0]: Sending extension SAFE RENEGOTIATION (1 bytes)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: SessionID: 60e9e10b82980ee578c7017bc92ead4adc059785f726ac9988bf6d5c2e4ffc71
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: SERVER HELLO was queued [89 bytes]
ocserv[21397]: TLS[<4>]: REC[0x55fc79c460f0]: Sent ChangeCipherSpec
ocserv[21397]: TLS[<9>]: INT: PREMASTER SECRET[48]: 14358a5faef781901f0e4217578bfd04a6e20112200e9b540f31958c03108e7812cd812e47a40ca8bee21c0282b95ed9
ocserv[21397]: TLS[<9>]: INT: CLIENT RANDOM[32]: 574ec3cd50586541e464a966808917c3116748b0852d8136bf5ed49e9c460709
ocserv[21397]: TLS[<9>]: INT: SERVER RANDOM[32]: 574ec3b45e044d91fd7f6d57e59017d795908f31cc04db821194fa970dd65fdb
ocserv[21397]: TLS[<9>]: INT: MASTER SECRET: 82dfe80d4926129812efc946c9bbc8961b0f664e8b63771b2b50bd348b50359a725791e90169e4c14035bca9dadca20b
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Initializing epoch #1
ocserv[21397]: TLS[<9>]: INT: KEY BLOCK[40]: e4cf0353908f203d8dff1aed27a4272b22c97912630e3af1dbd45dc50d0ebd04
ocserv[21397]: TLS[<9>]: INT: CLIENT WRITE KEY [16]: e4cf0353908f203d8dff1aed27a4272b
ocserv[21397]: TLS[<9>]: INT: SERVER WRITE KEY [16]: 22c97912630e3af1dbd45dc50d0ebd04
ocserv[21397]: TLS[<9>]: INT: CLIENT WRITE IV [4]: de163a32
ocserv[21397]: TLS[<9>]: INT: SERVER WRITE IV [4]: 6f5f13b3
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Epoch #1 ready
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Cipher Suite: RSA_AES_128_GCM_SHA256
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Initializing internal [write] cipher sessions
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: recording tls-unique CB (send)
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: FINISHED was queued [24 bytes]
ocserv[21397]: TLS[<6>]: DTLS[0x55fc79c460f0]: Start of flight transmission.
ocserv[21397]: TLS[<6>]: DTLS[0x55fc79c460f0]: Sending Packet[0] fragment SERVER HELLO(2) with length: 77, offset: 0, fragment length: 77
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Preparing Packet Handshake(22) with length: 89 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c460f0]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Sent Packet[1] Handshake(22) in epoch 0 and length: 102
ocserv[21397]: TLS[<6>]: DTLS[0x55fc79c460f0]: Sending Packet[0] fragment CHANGE CIPHER SPEC(254)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c460f0]: cipher: NULL, MAC: MAC-NULL, Epoch: 0
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 14
ocserv[21397]: TLS[<6>]: DTLS[0x55fc79c460f0]: Sending Packet[1] fragment FINISHED(20) with length: 12, offset: 0, fragment length: 12
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Preparing Packet Handshake(22) with length: 24 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c460f0]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Sent Packet[1] Handshake(22) in epoch 1 and length: 61
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:695
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_dtls.c:258
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_dtls.c:415
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_dtls.c:435
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_handshake.c:3038
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: SSL 254.253 ChangeCipherSpec packet received. Epoch 0, length: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Expected Packet ChangeCipherSpec(20)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Received Packet ChangeCipherSpec(20) with length: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Decrypted Packet[0.1] ChangeCipherSpec(20) with length: 1
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: Cipher Suite: RSA_AES_128_GCM_SHA256
ocserv[21397]: TLS[<3>]: ASSERT: gnutls_buffers.c:1158
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: SSL 254.253 Handshake packet received. Epoch 1, length: 48
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Expected Packet Handshake(22)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Received Packet Handshake(22) with length: 48
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Decrypted Packet[1.0] Handshake(22) with length: 24
ocserv[21397]: TLS[<4>]: HSK[0x55fc79c460f0]: FINISHED (20) was received. Length 12[12], frag offset 0, frag length: 12, sequence: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Start of epoch cleanup
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Epoch #0 freed
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: End of epoch cleanup
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Start of epoch cleanup
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: End of epoch cleanup
ocserv[21397]: worker[example]: 77.111.214.227 sending message 'tun mtu change' to main
ocserv[21397]: worker[example]: 77.111.214.227 setting MTU to 1369
ocserv[21397]: worker[example]: 77.111.214.227 DTLS handshake completed (plaintext MTU: 1369)
ocserv[21397]: worker[example]: 77.111.214.227 sending message 'session info' to main
ocserv[21394]: main[example]: 77.111.214.227:46962 main received message 'tun mtu change' of 3 bytes
ocserv[21394]: main[example]: 77.111.214.227:46962 setting vpns0 MTU to 1369
ocserv[21394]: main[example]: 77.111.214.227:46962 main received message 'session info' of 126 bytes
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: SSL 254.253 Application Data packet received. Epoch 1, length: 97
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Expected Packet Application Data(23)
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Received Packet Application Data(23) with length: 97
ocserv[21397]: TLS[<5>]: REC[0x55fc79c460f0]: Decrypted Packet[1.1] Application Data(23) with length: 73
ocserv[21397]: worker[example]: 77.111.214.227 received 73 byte(s) (DTLS)
ocserv[21397]: worker[example]: 77.111.214.227 writing 72 byte(s) to TUN
^Cocserv[21394]: main: termination request received; waiting for children to die
ocserv[21394]: main[example]: 77.111.214.227:46962 user disconnected (rx: 0, tx: 0)
ocserv[21397]: worker[example]: 77.111.214.227 worker-misc.c:97: parent terminated
ocserv[21397]: worker[example]: 77.111.214.227 sending disconnect message in TLS channel
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Preparing Packet Application Data(23) with length: 8 and min pad: 0
ocserv[21397]: TLS[<9>]: ENC[0x55fc79c35000]: cipher: AES-128-GCM, MAC: AEAD, Epoch: 1
ocserv[21397]: TLS[<5>]: REC[0x55fc79c35000]: Sent Packet[3] Application Data(23) in epoch 1 and length: 37
ocserv[21397]: worker[example]: 77.111.214.227 worker-auth.c:748: error connecting to sec-mod socket '/var/run/ocserv-socket.21394': No such file or directory
This is using version 0.10.11-1build1 from the Ubuntu main repo