rsyslog server running with error : unexpected GnuTLS error -54 in nsd_gtls.c

[lichen2013]

Expected behavior

1. rsyslog running with no error

Actual behavior

1. rsyslog running with errors

Steps to reproduce the behavior

This is our environment:

log sender (500+ servers with rsyslog configured) ---> log forwarder (2 servers) --> target server

The issue is happening on the log forwarder servers.

After running 2 days, there are a lot of open connections on these 2 servers.
It has more than 1 connection from 1 IP.
I have checked the specific log sender, only 1 active connection there.
So, issue 1 => why there are so many open dead connections on the server side ?

I tried to solve the dead connection issue by adding the keepalive configure:

$InputTCPServerKeepAlive on

The connection reduced very fast, but different error shows up in the log:

Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad4bc9820 from 169.61.224.213 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad4b89910 from 52.116.56.204 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad4b885d0 from 169.61.246.243 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad4ba1330 from 149.81.89.147 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:12:33 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:14:28 qrada-log-forwarder-lbaas-2 rsyslogd:  message repeated 2 times: [unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]]
Sep 20 02:14:28 qrada-log-forwarder-lbaas-2 rsyslogd: rsyslogd[internal_messages]: 139 messages lost due to rate-limiting
Sep 20 02:14:28 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad41ca310 from 141.125.112.94 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:26:29 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:26:29 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad5741740 from 168.1.224.168 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:32:23 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:32:23 qrada-log-forwarder-lbaas-2 rsyslogd: netstream session 0x7f7ad411ded0 from 130.198.104.90 will be closed due to error [v8.32.0 try http://www.rsyslog.com/e/2078 ]
Sep 20 02:39:35 qrada-log-forwarder-lbaas-2 rsyslogd: unexpected GnuTLS error -54 in nsd_gtls.c:546: Error in the pull function.  [v8.32.0 try http://www.rsyslog.com/e/2078 ]

Environment

• servers are VMs on cloud

• rsyslog version:

rsyslogd 8.32.0, compiled with:
    PLATFORM:               x86_64-pc-linux-gnu
    PLATFORM (lsb_release -d):      
    FEATURE_REGEXP:             Yes
    GSSAPI Kerberos 5 support:      Yes
    FEATURE_DEBUG (debug build, slow code): No
    32bit Atomic operations supported:  Yes
    64bit Atomic operations supported:  Yes
    memory allocator:           system default
    Runtime Instrumentation (slow code):    No
    uuid support:               Yes
    systemd support:            Yes
    Number of Bits in RainerScript integers: 64

See http://www.rsyslog.com for more information.

• platform:

Ubuntu 18.04-64

• for configuration questions/issues, include rsyslog.conf and included config files

#  /etc/rsyslog.conf    Configuration file for rsyslog.
#
#           For more information see
#           /usr/share/doc/rsyslog-doc/html/rsyslog_conf.html
#
#  Default logging rules can be found in /etc/rsyslog.d/50-default.conf


# use gtls netstream driver
$DefaultNetstreamDriver gtls

# certificate files
$DefaultNetstreamDriverCAFile /etc/rsyslog.d/keys/cacert.pem
$DefaultNetstreamDriverCertFile /etc/rsyslog.d/keys/servercert.pem
$DefaultNetstreamDriverKeyFile /etc/rsyslog.d/keys/serverkey.pem

global(debug.gnutls="10" debug.logFile="/var/log/rsyslogdebug")

#################
#### MODULES ####
#################

module(load="imuxsock") # provides support for local system logging
#module(load="immark")  # provides --MARK-- message capability

# provides UDP syslog reception
module(load="imudp")
input(type="imudp" port="514")

# provides TCP syslog reception
#module(load="imtcp")
#input(type="imtcp" port="10514")
$ModLoad imtcp
$InputTCPServerRun 10514
$InputTCPServerKeepAlive on

# provides kernel logging support and enable non-kernel klog messages
module(load="imklog" permitnonkernelfacility="on")

$InputTCPServerStreamDriverMode 1 # run driver in TLS-only mode
$InputTCPServerStreamDriverAuthMode anon # client is NOT authenticated

$InputTCPMaxSessions 10000

###########################
#### GLOBAL DIRECTIVES ####
###########################

#
# Use traditional timestamp format.
# To enable high precision timestamps, comment out the following line.
#
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

# Filter duplicated messages
$RepeatedMsgReduction on

#
# Set the default permissions for all log files.
#
$FileOwner syslog
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$PrivDropToUser syslog
$PrivDropToGroup syslog

#
# Where to place spool and state files
#
$WorkDirectory /var/spool/rsyslog

#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf


authpriv.*   @@10.94.170.164:514

[lichen2013]

Tried google, no luck, opened the debug by adding the following line to rsyslog.conf

global(debug.gnutls="10" debug.logFile="/var/log/rsyslogdebug")

And started rsyslog with debug mode: /usr/sbin/rsyslogd -dn
Here is the log file.

rsyslogdebug.txt.zip

[lichen2013]

upgraded rsyslog version, still error:

Sep 21 02:14:37 qrada-log-forwarder-lbaas-2 rsyslogd[4895]: unexpected GnuTLS error -54 in nsd_gtls.c:594: Error in the pull function.  [v8.1910.0.9814b01e74e0 try https://www.rsyslog.com/e/2078 ]
Sep 21 02:14:37 qrada-log-forwarder-lbaas-2 rsyslogd[4895]: netstream session 0x7fe2cc071890 from 135.90.112.13 will be closed due to error [v8.1910.0.9814b01e74e0 try https://www.rsyslog.com/e/2078 ]

rsyslogd  8.1910.0.9814b01e74e0 (aka 2019.10) compiled with:
    PLATFORM:               x86_64-pc-linux-gnu
    PLATFORM (lsb_release -d):      
    FEATURE_REGEXP:             Yes
    GSSAPI Kerberos 5 support:      No
    FEATURE_DEBUG (debug build, slow code): No
    32bit Atomic operations supported:  Yes
    64bit Atomic operations supported:  Yes
    memory allocator:           system default
    Runtime Instrumentation (slow code):    No
    uuid support:               Yes
    systemd support:            Yes
    Config file:                /etc/rsyslog.conf
    PID file:               /var/run/rsyslogd.pid
    Number of Bits in RainerScript integers: 64

See https://www.rsyslog.com for more information.

[alorbach]

Since Version Version 8.32.0 (2018-01-09), there has have a lot of changes in gnutls / openssl code.
I suggest that you try latest rsyslog from our repository, to verify if the problem isnt already fixed:
https://www.rsyslog.com/ubuntu-repository/

If the problem persists, we can take a deeper look into your problem.

[rgerhards]

I would assume that this are just connection drops. Gnutls just reports them with a generic error message.

[lichen2013]

@alorbach I have tried the version 8.1910.0.9814b01e74e0, same issue.

[lichen2013]

@rgerhards

After several days long run, we have observed same error log at the client side.

Sep 23 21:28:06 lb-bd1247c1-65065 rsyslogd[1495]: unexpected GnuTLS error -53 - this could be caused by a broken connection. GnuTLS reports: Error in the push function.   [v8.32.0 try http://www.rsyslog.com/e
Sep 23 21:28:06 lb-bd1247c1-65065 rsyslogd[1495]: omfwd: TCPSendBuf error -2078, destruct TCP Connection to logforwarder.lb.appdomain.cloud:10514 [v8.32.0 try http://www.rsyslog.com/e/2078 ]

When connection drop happens, will rsyslog re-connect and re-send the log that failed to send ?
I think we have observed log been miss, and this is a real issue.

[davidelang]

read
https://rainer.gerhards.net/2008/04/on-unreliability-of-plain-tcp-syslog.html

to be reliable you need to use relp

David Lang

[alorbach]

It looks like broken connections.

@lichen2013 you may try openssl ("ossl") driver which provides way better error reporting and handling:

# use ossl netstream driver
$DefaultNetstreamDriver ossl

For more information:
https://www.rsyslog.com/doc/v8-stable/concepts/ns_ossl.html

[lichen2013]

Thanks for the kindly help, @alorbach @rgerhards.
Will check relp and openssl.
Since these error messages are not real problem, close this issue.

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.