dtls-repro-20170915.log

dtls-repro-20170915.log (text/plain), 12.17 KB, created by Rolf Eike Beer on 2018-05-05 20:28:02 UTC

gnutls[2]: Enabled GnuTLS 3.5.18 logging...
gnutls[2]: getrandom random generator was detected
gnutls[2]: cached system priority /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/tests/system.prio mtime 1459588815
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/attributes.c[_x509_parse_attribute]:103
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/attributes.c[_x509_parse_attribute]:174
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:110
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509.c[get_alt_name]:1701
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/dn.c[_gnutls_x509_parse_dn_oid]:348
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/dn.c[_gnutls_x509_parse_dn_oid]:458
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509.c[gnutls_x509_crt_get_dn_by_oid]:871
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/mpi.c[_gnutls_x509_read_uint]:246
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/dh.c[gnutls_dh_params_import_pkcs3]:381
(null)|<5>| REC[0x84bd8]: Allocating epoch #0
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/attributes.c[_x509_parse_attribute]:103
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/attributes.c[_x509_parse_attribute]:174
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509_ext.c[gnutls_subject_alt_names_get]:110
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509.c[get_alt_name]:1701
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/dn.c[_gnutls_x509_parse_dn_oid]:348
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/dn.c[_gnutls_x509_parse_dn_oid]:458
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/x509.c[gnutls_x509_crt_get_dn_by_oid]:871
(null)|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/x509/extensions.c[_gnutls_get_extension]:65
(null)|<5>| REC[0x8d950]: Allocating epoch #0
negotiating DTLS 1.2 with cli-cert
client|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/constate.c[_gnutls_epoch_get]:600
client|<5>| REC[0x8d950]: Allocating epoch #1
client|<4>| HSK[0x8d950]: Adv. version: 254.255
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_ECDSA_AES_256_CBC_SHA1 (C0.0A)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_ECDSA_AES_128_CBC_SHA1 (C0.09)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_ECDSA_3DES_EDE_CBC_SHA1 (C0.08)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
client|<4>| HSK[0x8d950]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
client|<4>| EXT[0x8d950]: Sending extension Extended Master Secret (0 bytes)
client|<4>| EXT[0x8d950]: Sending extension OCSP Status Request (5 bytes)
client|<4>| EXT[0x8d950]: Sending extension Safe Renegotiation (1 bytes)
client|<4>| EXT[0x8d950]: Sending extension Session Ticket (0 bytes)
client|<4>| EXT[0x8d950]: Sending extension Supported curves (12 bytes)
client|<4>| EXT[0x8d950]: Sending extension Supported ECC Point Formats (2 bytes)
client|<4>| HSK[0x8d950]: CLIENT HELLO was queued [130 bytes]
client|<6>| DTLS[0x8d950]: Start of flight transmission.
client|<6>| DTLS[0x8d950]: Sending Packet[0] fragment CLIENT HELLO(1) with length: 118, offset: 0, fragment length: 118, mtu: 1427
client|<5>| REC[0x8d950]: Preparing Packet Handshake(22) with length: 130 and min pad: 0
client|<5>| REC[0x8d950]: Sent Packet[1] Handshake(22) in epoch 0 and length: 143
client|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/dtls.c[_dtls_transmit]:420
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/constate.c[_gnutls_epoch_get]:600
server|<5>| REC[0x84bd8]: Allocating epoch #1
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/buffers.c[get_last_packet]:1164
server|<5>| REC[0x84bd8]: SSL 254.255 Handshake packet received. Epoch 0, length: 130
server|<5>| REC[0x84bd8]: Expected Packet Handshake(22)
server|<5>| REC[0x84bd8]: Received Packet Handshake(22) with length: 130
server|<5>| REC[0x84bd8]: Decrypted Packet[0.0] Handshake(22) with length: 130
server|<4>| HSK[0x84bd8]: CLIENT HELLO (1) was received. Length 118[118], frag offset 0, frag length: 118, sequence: 0
server|<4>| HSK[0x84bd8]: Client's version: 254.255
server|<4>| HSK[0x84bd8]: Selected version DTLS1.0
server|<4>| EXT[0x84bd8]: Parsing extension 'Extended Master Secret/23' (0 bytes)
server|<4>| EXT[0x84bd8]: Found extension 'OCSP Status Request/5'
server|<4>| EXT[0x84bd8]: Parsing extension 'Safe Renegotiation/65281' (1 bytes)
server|<4>| EXT[0x84bd8]: Found extension 'Session Ticket/35'
server|<4>| EXT[0x84bd8]: Found extension 'Supported curves/10'
server|<4>| EXT[0x84bd8]: Found extension 'Supported ECC Point Formats/11'
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/db.c[_gnutls_server_restore_session]:276
server|<4>| EXT[0x84bd8]: Found extension 'Extended Master Secret/23'
server|<4>| EXT[0x84bd8]: Found extension 'OCSP Status Request/5'
server|<4>| EXT[0x84bd8]: Found extension 'Safe Renegotiation/65281'
server|<4>| EXT[0x84bd8]: Found extension 'Session Ticket/35'
server|<4>| EXT[0x84bd8]: Found extension 'Supported curves/10'
server|<4>| EXT[0x84bd8]: Found extension 'Supported ECC Point Formats/11'
server|<4>| EXT[0x84bd8]: Found extension 'Extended Master Secret/23'
server|<4>| EXT[0x84bd8]: Found extension 'OCSP Status Request/5'
server|<4>| EXT[0x84bd8]: Found extension 'Safe Renegotiation/65281'
server|<4>| EXT[0x84bd8]: Parsing extension 'Session Ticket/35' (0 bytes)
server|<4>| EXT[0x84bd8]: Parsing extension 'Supported curves/10' (12 bytes)
server|<4>| HSK[0x84bd8]: Selected ECC curve SECP256R1 (2)
server|<4>| EXT[0x84bd8]: Parsing extension 'Supported ECC Point Formats/11' (2 bytes)
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/ext/server_name.c[gnutls_server_name_get]:310
server|<4>| HSK[0x84bd8]: Requested server name: ''
server|<4>| HSK[0x84bd8]: Requested PK algorithm: EC/ECDSA (4) -- ctype: X.509 (1)
server|<4>| HSK[0x84bd8]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
server|<4>| HSK[0x84bd8]: Requested PK algorithm: RSA (1) -- ctype: X.509 (1)
server|<4>| HSK[0x84bd8]: certificate[0] PK algorithm: RSA (1) - ctype: X.509 (1)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1 (C0.14)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1 (C0.13)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDHE_RSA_3DES_EDE_CBC_SHA1 (C0.12)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_RSA_AES_256_CBC_SHA1 (00.35)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_256_CBC_SHA1 (00.84)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_RSA_AES_128_CBC_SHA1 (00.2F)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_RSA_CAMELLIA_128_CBC_SHA1 (00.41)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_RSA_3DES_EDE_CBC_SHA1 (00.0A)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_256_CBC_SHA1 (00.39)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_256_CBC_SHA1 (00.88)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DHE_RSA_AES_128_CBC_SHA1 (00.33)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DHE_RSA_CAMELLIA_128_CBC_SHA1 (00.45)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DHE_RSA_3DES_EDE_CBC_SHA1 (00.16)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDH_ANON_AES_256_CBC_SHA1 (C0.19)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDH_ANON_AES_128_CBC_SHA1 (C0.18)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_ECDH_ANON_3DES_EDE_CBC_SHA1 (C0.17)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DH_ANON_AES_256_CBC_SHA1 (00.3A)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DH_ANON_CAMELLIA_256_CBC_SHA1 (00.89)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DH_ANON_AES_128_CBC_SHA1 (00.34)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DH_ANON_CAMELLIA_128_CBC_SHA1 (00.46)
server|<4>| HSK[0x84bd8]: Keeping ciphersuite: GNUTLS_DH_ANON_3DES_EDE_CBC_SHA1 (00.1B)
server|<4>| HSK[0x84bd8]: Requested cipher suites[size: 32]: 
server|<4>| 	0xc0, 0x0a ECDHE_ECDSA_AES_256_CBC_SHA1
server|<4>| 	0xc0, 0x09 ECDHE_ECDSA_AES_128_CBC_SHA1
server|<4>| 	0xc0, 0x08 ECDHE_ECDSA_3DES_EDE_CBC_SHA1
server|<4>| 	0xc0, 0x14 ECDHE_RSA_AES_256_CBC_SHA1
server|<4>| HSK[0x84bd8]: Selected cipher suite: ECDHE_RSA_AES_256_CBC_SHA1
server|<4>| HSK[0x84bd8]: Selected Compression Method: NULL
server|<4>| EXT[0x84bd8]: Found extension 'Extended Master Secret/23'
server|<4>| EXT[0x84bd8]: Parsing extension 'OCSP Status Request/5' (5 bytes)
server|<4>| EXT[0x84bd8]: Found extension 'Safe Renegotiation/65281'
server|<4>| EXT[0x84bd8]: Found extension 'Session Ticket/35'
server|<4>| EXT[0x84bd8]: Found extension 'Supported curves/10'
server|<4>| EXT[0x84bd8]: Found extension 'Supported ECC Point Formats/11'
server|<4>| HSK[0x84bd8]: Safe renegotiation succeeded
server|<4>| EXT[0x84bd8]: Sending extension Extended Master Secret (0 bytes)
server|<4>| EXT[0x84bd8]: Sending extension Safe Renegotiation (1 bytes)
server|<4>| EXT[0x84bd8]: Sending extension Supported ECC Point Formats (2 bytes)
server|<4>| HSK[0x84bd8]: SessionID: 41e9ac7188d88d9b93bb9381d3c984190f756d48e690ecd640ce7502a351bb97
server|<4>| HSK[0x84bd8]: SERVER HELLO was queued [99 bytes]
server|<4>| HSK[0x84bd8]: CERTIFICATE was queued [2867 bytes]
server|<4>| HSK[0x84bd8]: signing handshake data: using RSA-SHA1
server|<4>| HSK[0x84bd8]: SERVER KEY EXCHANGE was queued [1331 bytes]
server|<4>| HSK[0x84bd8]: CERTIFICATE REQUEST was queued [18 bytes]
server|<4>| HSK[0x84bd8]: SERVER HELLO DONE was queued [12 bytes]
server|<6>| Session timeout: 168026 ms
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/dtls.c[_dtls_transmit]:299
server|<6>| DTLS[0x84bd8]: End of flight transmission.
server|<3>| ASSERT: /var/tmp/portage/net-libs/gnutls-3.5.18/work/gnutls-3.5.18/lib/handshake.c[handshake_server]:3301
client: Resource temporarily unavailable, try again.
server: The operation timed out
dtls_try_with_key_mtu:160: dtls_try_with_key_mtu:160: Handshake failed
FAIL dtls-repro-20170915 (exit status: 1)