tlshd fails to capture keys in the SSLKEYLOGFILE

[olgakorn1]

Ran into a strange behavior (possibly due to a flaky DNS setup). The problem was hit but not consistently reproducible. Using this report to keep track.

Test did:
sudo tcpdump -i ens160 -s 0 -w /tmp/0.trc &
sudo mount -o vers=4.1,xprtsec=tls 192.168.68.16:/export /mnt/t
ll /mnt/t/
cat /mnt/t/data/file
sudo umount /mnt/t

sudo mount -o vers=4.1,xprtsec=tls 192.168.68.16:/export /mnt/t
sudo umount /mnt/t

sudo mount -o vers=4.1,xprtsec=tls 192.168.68.16:/export /mnt/t
ll /mnt/t/linux
cat /mnt/t/linux/README
sudo umount /mnt/t

No failures were seen executing the setup.

This is the output of tlshd -s (nfs-tls-5.log):

tlshd[5200]: gnutls(4): EXT[0x1c36e00]: Preparing extension (Post Handshake Auth/49) for 'client hello'
tlshd[5200]: Handshake with netapp16.linux.fake (192.168.68.16) was successful
tlshd[5290]: Handshake with 'unknown' () failed
tlshd[5316]: gnutls(4): EXT[0x1c36e00]: Preparing extension (Post Handshake Auth/49) for 'client hello'
tlshd[5316]: Handshake with netapp16.linux.fake (192.168.68.16) was successful

This is the output of journalctl (nfs-tls-5.msg), all three mounts were successful:

Jul 11 11:42:10 netapp30.linux.fake tlshd[5200]: gnutls(4): EXT[0x1c36e00]: Preparing extension (Post Handshake Auth/49) for 'client hello'
Jul 11 11:42:10 netapp30.linux.fake tlshd[5200]: Handshake with netapp16.linux.fake (192.168.68.16) was successful
Jul 11 11:43:00 netapp30.linux.fake tlshd[5285]: gnutls(4): EXT[0x16a8e00]: Preparing extension (Post Handshake Auth/49) for 'client hello'
Jul 11 11:43:00 netapp30.linux.fake tlshd[5285]: Handshake with netapp16.linux.fake (192.168.68.16) was successful
Jul 11 11:43:08 netapp30.linux.fake tlshd[5316]: gnutls(4): EXT[0x1c36e00]: Preparing extension (Post Handshake Auth/49) for 'client hello'
Jul 11 11:43:08 netapp30.linux.fake tlshd[5316]: Handshake with netapp16.linux.fake (192.168.68.16) was successful

In this case, Wireshark is able to successfully decrypt/dissect all packets for the first and third mounts since the master key file only had two secrets.

[chucklever]

If you ever have an opportunity to attempt to reproduce this again, enable the NFS client's tracepoints that show mount options to see what DNS results are being handed down by mount.nfs. Other tracepoints in the sunrpc client (and in the handshake code) might also be helpful at tracking down the issue.