[gnutls-devel] GnuTLS | assert: lib/accelerated/x86/aes-gcm-x86-pclmul-avx.c[aesni_gcm_aead_decrypt]:351 (#707)
Development of GNU's TLS library
gnutls-devel at lists.gnutls.org
Mon Feb 18 21:41:30 CET 2019
New Issue was created.
Issue 707: https://gitlab.com/gnutls/gnutls/issues/707
Author: Fred
Assignee:
## Description of problem:
When using Knot Resolver (3.2.0-1 as included in Debian Buster) with TLS_FORWARD to 1.1.1.1 or 9.9.9.9, sometimes, seemingly random, an assert is hit and decryption fails. This is on an AMD Ryzen 5 1600 CPU.
```
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Allocating epoch #0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) added 4 protocols, 29 ciphersuites, 18 sig algos and 9 groups into priority list
Feb 18 21:05:18 piranha kresd[6366]: [08443.17][wrkr] => connecting to: '9.9.9.9#00853'
Feb 18 21:05:18 piranha kresd[6366]: [wrkr]=> connected to '9.9.9.9#00853'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Allocating epoch #1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: Adv. version: 3.3
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 13.02 (GNUTLS_AES_256_GCM_SHA384)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 13.03 (GNUTLS_CHACHA20_POLY1305_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 13.01 (GNUTLS_AES_128_GCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 13.04 (GNUTLS_AES_128_CCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.2c (GNUTLS_ECDHE_ECDSA_AES_256_GCM_SHA384)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite cc.a9 (GNUTLS_ECDHE_ECDSA_CHACHA20_POLY1305)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.ad (GNUTLS_ECDHE_ECDSA_AES_256_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.0a (GNUTLS_ECDHE_ECDSA_AES_256_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.2b (GNUTLS_ECDHE_ECDSA_AES_128_GCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.ac (GNUTLS_ECDHE_ECDSA_AES_128_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.09 (GNUTLS_ECDHE_ECDSA_AES_128_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.30 (GNUTLS_ECDHE_RSA_AES_256_GCM_SHA384)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite cc.a8 (GNUTLS_ECDHE_RSA_CHACHA20_POLY1305)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.14 (GNUTLS_ECDHE_RSA_AES_256_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.2f (GNUTLS_ECDHE_RSA_AES_128_GCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.13 (GNUTLS_ECDHE_RSA_AES_128_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.9d (GNUTLS_RSA_AES_256_GCM_SHA384)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.9d (GNUTLS_RSA_AES_256_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.35 (GNUTLS_RSA_AES_256_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.9c (GNUTLS_RSA_AES_128_GCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.9c (GNUTLS_RSA_AES_128_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.2f (GNUTLS_RSA_AES_128_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.9f (GNUTLS_DHE_RSA_AES_256_GCM_SHA384)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite cc.aa (GNUTLS_DHE_RSA_CHACHA20_POLY1305)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.9f (GNUTLS_DHE_RSA_AES_256_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.39 (GNUTLS_DHE_RSA_AES_256_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.9e (GNUTLS_DHE_RSA_AES_128_GCM_SHA256)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite c0.9e (GNUTLS_DHE_RSA_AES_128_CCM)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Keeping ciphersuite 00.33 (GNUTLS_DHE_RSA_AES_128_CBC_SHA1)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Maximum Record Size/1) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (OCSP Status Request/5) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension OCSP Status Request/5 (5 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Client Certificate Type/19) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Server Certificate Type/20) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Supported Groups/10) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group SECP256R1 (0x17)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group SECP384R1 (0x18)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group SECP521R1 (0x19)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group X25519 (0x1d)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group FFDHE2048 (0x100)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group FFDHE3072 (0x101)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group FFDHE4096 (0x102)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group FFDHE6144 (0x103)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sent group FFDHE8192 (0x104)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Supported Groups/10 (20 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Supported EC Point Formats/11) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Supported EC Point Formats/11 (2 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (SRP/12) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Signature Algorithms/13) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (4.1) RSA-SHA256
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.9) RSA-PSS-SHA256
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.4) RSA-PSS-RSAE-SHA256
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (4.3) ECDSA-SHA256
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.7) EdDSA-Ed25519
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (5.1) RSA-SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.10) RSA-PSS-SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.5) RSA-PSS-RSAE-SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (5.3) ECDSA-SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (6.1) RSA-SHA512
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.11) RSA-PSS-SHA512
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (8.6) RSA-PSS-RSAE-SHA512
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (6.3) ECDSA-SHA512
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (2.1) RSA-SHA1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sent signature algo (2.3) ECDSA-SHA1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Signature Algorithms/13 (32 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (SRTP/14) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Heartbeat/15) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (ALPN/16) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Encrypt-then-MAC/22) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Encrypt-then-MAC/22 (0 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Extended Master Secret/23) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Extended Master Secret/23 (0 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Session Ticket/35) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Session Ticket/35 (0 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Key Share/51) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sending key share for SECP256R1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: sending key share for X25519
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Key Share/51 (107 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Supported Versions/43) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Advertizing version 3.4
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) Advertizing version 3.3
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Supported Versions/43 (5 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Post Handshake Auth/49) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Safe Renegotiation/65281) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Safe Renegotiation/65281 (1 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Server Name Indication/0) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Cookie/44) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Early Data/42) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (PSK Key Exchange Modes/45) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension PSK Key Exchange Modes/45 (3 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Record Size Limit/28) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Sending extension Record Size Limit/28 (2 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (ClientHello Padding/21) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Preparing extension (Pre Shared Key/41) for 'client hello'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: CLIENT HELLO was queued [328 bytes]
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Preparing Packet Handshake(22) with length: 328 and min pad: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Sent Packet[1] Handshake(22) in epoch 0 and length: 333
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:589
Feb 18 21:05:18 piranha kresd[6366]: [00000.00][plan] plan 'ogs.google.com.' type 'A' uid [08330.00]
Feb 18 21:05:18 piranha kresd[6366]: [08330.00][iter] 'ogs.google.com.' type 'A' new uid was assigned .01, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.01][cach] => satisfied by exact CNAME: rank 030, new TTL 1005
Feb 18 21:05:18 piranha kresd[6366]: [08330.01][iter] <= rcode: NOERROR
Feb 18 21:05:18 piranha kresd[6366]: [08330.01][iter] <= cname chain, following
Feb 18 21:05:18 piranha kresd[6366]: [00000.00][plan] plan 'www3.l.google.com.' type 'A' uid [08330.02]
Feb 18 21:05:18 piranha kresd[6366]: [08330.02][iter] 'www3.l.google.com.' type 'A' new uid was assigned .03, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][cach] => skipping exact RR: rank 030 (min. 030), new TTL -390
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][cach] => no NSEC* cached for zone: google.com.
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][cach] => skipping zone: google.com., NSEC, hash 0;new TTL -123456789, ret -2
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][cach] => skipping zone: google.com., NSEC, hash 0;new TTL -123456789, ret -2
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][plan] plan '.' type 'DNSKEY' uid [08330.04]
Feb 18 21:05:18 piranha kresd[6366]: [08330.04][iter] '.' type 'DNSKEY' new uid was assigned .05, parent uid .03
Feb 18 21:05:18 piranha kresd[6366]: [08330.05][cach] => satisfied by exact RRset: rank 060, new TTL 112006
Feb 18 21:05:18 piranha kresd[6366]: [08330.05][iter] <= rcode: NOERROR
Feb 18 21:05:18 piranha kresd[6366]: [08330.05][vldr] <= parent: updating DNSKEY
Feb 18 21:05:18 piranha kresd[6366]: [08330.05][vldr] <= answer valid, OK
Feb 18 21:05:18 piranha kresd[6366]: [08330.03][iter] 'www3.l.google.com.' type 'A' new uid was assigned .06, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.06][plan] plan 'com.' type 'DS' uid [08330.07]
Feb 18 21:05:18 piranha kresd[6366]: [08330.07][iter] 'com.' type 'DS' new uid was assigned .08, parent uid .06
Feb 18 21:05:18 piranha kresd[6366]: [08330.08][cach] => satisfied by exact RRset: rank 060, new TTL 30836
Feb 18 21:05:18 piranha kresd[6366]: [08330.08][iter] <= rcode: NOERROR
Feb 18 21:05:18 piranha kresd[6366]: [08330.08][vldr] <= DS: OK
Feb 18 21:05:18 piranha kresd[6366]: [08330.08][vldr] <= parent: updating DS
Feb 18 21:05:18 piranha kresd[6366]: [08330.08][vldr] <= answer valid, OK
Feb 18 21:05:18 piranha kresd[6366]: [08330.06][iter] 'www3.l.google.com.' type 'A' new uid was assigned .09, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.09][plan] plan 'com.' type 'DNSKEY' uid [08330.10]
Feb 18 21:05:18 piranha kresd[6366]: [08330.10][iter] 'com.' type 'DNSKEY' new uid was assigned .11, parent uid .09
Feb 18 21:05:18 piranha kresd[6366]: [08330.11][cach] => satisfied by exact RRset: rank 060, new TTL 35081
Feb 18 21:05:18 piranha kresd[6366]: [08330.11][iter] <= rcode: NOERROR
Feb 18 21:05:18 piranha kresd[6366]: [08330.11][vldr] <= parent: updating DNSKEY
Feb 18 21:05:18 piranha kresd[6366]: [08330.11][vldr] <= answer valid, OK
Feb 18 21:05:18 piranha kresd[6366]: [08330.09][iter] 'www3.l.google.com.' type 'A' new uid was assigned .12, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.12][plan] plan 'google.com.' type 'DS' uid [08330.13]
Feb 18 21:05:18 piranha kresd[6366]: [08330.13][iter] 'google.com.' type 'DS' new uid was assigned .14, parent uid .12
Feb 18 21:05:18 piranha kresd[6366]: [08330.14][cach] => satisfied by exact packet: rank 060, new TTL 587
Feb 18 21:05:18 piranha kresd[6366]: [08330.14][iter] <= rcode: NOERROR
Feb 18 21:05:18 piranha kresd[6366]: [08330.14][vldr] <= DS doesn't exist, going insecure
Feb 18 21:05:18 piranha kresd[6366]: [08330.14][vldr] <= parent: updating DS
Feb 18 21:05:18 piranha kresd[6366]: [08330.14][vldr] <= answer valid, OK
Feb 18 21:05:18 piranha kresd[6366]: [08330.12][iter] 'www3.l.google.com.' type 'A' new uid was assigned .15, parent uid .00
Feb 18 21:05:18 piranha kresd[6366]: [08330.15][plan] plan 'google.com.' type 'NS' uid [08330.16]
Feb 18 21:05:18 piranha kresd[6366]: [08330.16][iter] 'google.com.' type 'NS' new uid was assigned .17, parent uid .15
Feb 18 21:05:18 piranha kresd[6366]: [08330.17][cach] => skipping exact RR: rank 020 (min. 030), new TTL 4782
Feb 18 21:05:18 piranha kresd[6366]: [08330.17][cach] => no NSEC* cached for zone: google.com.
Feb 18 21:05:18 piranha kresd[6366]: [08330.17][cach] => skipping zone: google.com., NSEC, hash 0;new TTL -123456789, ret -2
Feb 18 21:05:18 piranha kresd[6366]: [08330.17][cach] => skipping zone: google.com., NSEC, hash 0;new TTL -123456789, ret -2
Feb 18 21:05:18 piranha kresd[6366]: [ ][nsre] score 21 for 9.9.9.9#00853;#011 cached RTT: 25
Feb 18 21:05:18 piranha kresd[6366]: [08330.17][resl] => id: '21366' querying: '9.9.9.9#00853' score: 21 zone cut: 'com.' qname: 'gOogLe.Com.' qtype: 'NS' proto: 'tcp'
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Handshake packet received. Epoch 0, length: 123
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Handshake(22) with length: 123
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[0] Handshake(22) with length: 123
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: SERVER HELLO (2) was received. Length 119[119], frag offset 0, frag length: 119, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1162
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_handshake_io_recv_int]:1413
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: Server's version: 3.3
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Parsing extension 'Supported Versions/43' (2 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Negotiated version: 3.4
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: Selected cipher suite: GNUTLS_AES_256_GCM_SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Parsing extension 'Key Share/51' (69 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: Selected group SECP256R1 (2)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (2) EXT[0x5589285527f0]: client generated SECP256R1 shared key
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Preparing Packet ChangeCipherSpec(20) with length: 1 and min pad: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Sent Packet[2] ChangeCipherSpec(20) in epoch 0 and length: 6
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) REC[0x5589285527f0]: Sent ChangeCipherSpec
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Initializing epoch #1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Epoch #1 ready
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 ChangeCipherSpec packet received. Epoch 1, length: 1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet ChangeCipherSpec(20) with length: 1
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 39
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 39
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[0] Handshake(22) with length: 22
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: ENCRYPTED EXTENSIONS (8) was received. Length 18[18], frag offset 0, frag length: 18, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: parsing encrypted extensions
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) EXT[0x5589285527f0]: Parsing extension 'Supported Groups/10' (12 bytes)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 2664
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 2664
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:617
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1316
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/tls13/certificate_request.c[_gnutls13_recv_certificate_request]:204
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 2664
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 2664
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[1] Handshake(22) with length: 2647
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: CERTIFICATE (11) was received. Length 2643[2643], frag offset 0, frag length: 2643, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1162
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_handshake_io_recv_int]:1413
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: parsing certificate message
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 97
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 97
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:617
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1316
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/tls13/certificate_verify.c[_gnutls13_recv_certificate_verify]:75
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 97
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 97
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[2] Handshake(22) with length: 80
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: CERTIFICATE VERIFY (15) was received. Length 76[76], frag offset 0, frag length: 76, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: Parsing certificate verify
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: verifying TLS 1.3 handshake data using ECDSA-SECP256R1-SHA256
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/ocsp-api.c[gnutls_ocsp_status_request_get2]:99
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/ocsp-api.c[gnutls_ocsp_status_request_get2]:99
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../../lib/x509/name_constraints.c[gnutls_x509_crt_get_name_constraints]:470
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../../lib/x509/name_constraints.c[gnutls_x509_crt_get_name_constraints]:470
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 1, length: 69
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Handshake(22)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 69
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[3] Handshake(22) with length: 52
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: FINISHED (20) was received. Length 48[48], frag offset 0, frag length: 48, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: parsing finished
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: sending finished
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: FINISHED was queued [52 bytes]
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Preparing Packet Handshake(22) with length: 52 and min pad: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Sent Packet[1] Handshake(22) in epoch 1 and length: 74
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/constate.c[_gnutls_epoch_get]:906
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Allocating epoch #2
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Initializing epoch #2
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Epoch #2 ready
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: TLS 1.3 re-key with cipher suite: GNUTLS_AES_256_GCM_SHA384
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Start of epoch cleanup
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Epoch #0 freed
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Epoch #1 freed
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: End of epoch cleanup
Feb 18 21:05:18 piranha kresd[6366]: [tls_client] TLS handshake with 9.9.9.9#00853 has completed
Feb 18 21:05:18 piranha kresd[6366]: [tls_client] TLS session has not resumed
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:589
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Preparing Packet Application Data(23) with length: 41 and min pad: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Sent Packet[1] Application Data(23) in epoch 2 and length: 63
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Preparing Packet Application Data(23) with length: 41 and min pad: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Sent Packet[2] Application Data(23) in epoch 2 and length: 63
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_io_read_buffered]:589
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1766
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 2, length: 74
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Application Data(23)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 74
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[0] Handshake(22) with length: 57
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: NEW SESSION TICKET (4) was received. Length 53[53], frag offset 0, frag length: 53, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_handshake_io_recv_int]:1431
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: parsing session ticket message
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1567
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1766
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 2, length: 74
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Application Data(23)
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 74
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Decrypted Packet[1] Handshake(22) with length: 57
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[get_last_packet]:1171
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: NEW SESSION TICKET (4) was received. Length 53[53], frag offset 0, frag length: 53, sequence: 0
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/buffers.c[_gnutls_handshake_io_recv_int]:1431
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (4) HSK[0x5589285527f0]: parsing session ticket message
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1567
Feb 18 21:05:18 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1766
Feb 18 21:05:20 piranha kresd[6366]: [tls] session ticket: epoch 378545, scheduling rotation check in 4095999 ms
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: SSL 3.3 Application Data packet received. Epoch 2, length: 19
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Expected Packet Application Data(23)
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (5) REC[0x5589285527f0]: Received Packet Application Data(23) with length: 19
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../../../lib/accelerated/x86/aes-gcm-x86-pclmul-avx.c[aesni_gcm_aead_decrypt]:351
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/crypto-api.c[gnutls_aead_cipher_decrypt]:714
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/cipher.c[decrypt_packet_tls13]:873
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/cipher.c[_gnutls_decrypt]:160
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_in_buffers]:1468
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (1) Discarded message[2] due to invalid decryption
Feb 18 21:05:20 piranha kresd[6366]: [gnutls] (3) ASSERT: ../../lib/record.c[_gnutls_recv_int]:1766
Feb 18 21:05:20 piranha kresd[6366]: [tls_client] gnutls_record_recv failed: GNUTLS_E_DECRYPTION_FAILED (-24)
Feb 18 21:05:20 piranha kresd[6366]: [io] => connection to '9.9.9.9#00853' closed by peer (end of file)
```
## Version of gnutls used:
gnutls 3.6.6-2
## Distributor of gnutls (e.g., Ubuntu, Fedora, RHEL)
Debian Buster
## How reproducible:
Steps to Reproduce:
/etc/knot-resolver/kresd.conf
```
user('knot-resolver','knot-resolver')
verbose(true)
cache.size = 512*MB
modules = {
'policy',
'view',
'hints',
'serve_stale < cache',
'workarounds < iterate',
'stats',
'predict'
}
view:addr('127.0.0.1/8', function (req, qry) return policy.PASS end)
view:addr('[::1]/128', function (req, qry) return policy.PASS end)
view:addr('0.0.0.0/0', function (req, qry) return policy.DROP end)
policy.add(policy.all(policy.TLS_FORWARD({
{ '9.9.9.9', hostname='dns.quad9.net', ca_file='/etc/ssl/certs/ca-certificates.crt' },
})))
predict.config(20, 72)
```
```
$ namebench 127.0.0.1 -x -O
```
## Actual results:
Many errors GNUTLS_E_DECRYPTION_FAILED in syslog
## Expected results:
No errors
--
Reply to this email directly or view it on GitLab: https://gitlab.com/gnutls/gnutls/issues/707
You're receiving this email because of your account on gitlab.com.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.gnupg.org/pipermail/gnutls-devel/attachments/20190218/6aacad74/attachment-0001.html>
More information about the Gnutls-devel
mailing list