Stunnel: Tunneling client failing with local socket: Function not implemented

[fcoquelet]

Is this a new Bug?

• I checked that the bug hasn't been reported before

Package Name

stunnel

Package Version

v5.60-2 / 5.57-1

Device Model

DS211j

Device Architecture

ARMv5

Firmware Version

6.2.4

What happened?

After setting up a tunneling service (SSH), stunnel starts successfully as a client on the synology.
However when trying to establish a connection through it (ssh user@SynologyIP -p StunnelAcceptPort), the ssh command hangs and the stunnel logs begin to flood with the following error message:

LOG3[ui]: local socket: Function not implemented (38)

I tried to toy with multiple options (different users including root, different ports, local ip binding, changing local socket options, ..) but no avail.
Same configuration running on a laptop connects successfully.

Reproduction steps

1. Set up a SSH tunneling service with stunnel as a client on the diskstation

[mySSH]
client = yes
accept = 18022
connect = targetServer:443
verifyPeer = yes
CAfile = /var/packages/stunnel/target/etc/stunnel/stunnel.pem

2. using SSH, connect to the stunnel client Accept port
   ssh user@SynologyIP -p 18022
3. ???
4. Profit
   ...

Install Log

2023/04/30 09:03:38	install stunnel 5.60-2 Begin preinst
2023/04/30 09:03:40	===> Step preinst. USER=stunnel GROUP= SHARE_PATH=
2023/04/30 09:03:40	install stunnel 5.60-2 End preinst ret=[0]
2023/04/30 09:03:40	install stunnel 5.60-2 Begin /bin/rm -rf /volume1/@appstore/stunnel
2023/04/30 09:03:40	install stunnel 5.60-2 End /bin/rm -rf /volume1/@appstore/stunnel ret=[0]
2023/04/30 09:03:40	install stunnel 5.60-2 Begin /bin/mv -f /volume1/@tmp/pkginstall/package /volume1/@appstore/stunnel
2023/04/30 09:03:41	install stunnel 5.60-2 End /bin/mv -f /volume1/@tmp/pkginstall/package /volume1/@appstore/stunnel ret=[0]
2023/04/30 09:03:41	install stunnel 5.60-2 Begin /bin/rm -rf /var/packages/stunnel
2023/04/30 09:03:41	install stunnel 5.60-2 End /bin/rm -rf /var/packages/stunnel ret=[0]
2023/04/30 09:03:41	install stunnel 5.60-2 Begin /bin/mkdir -p /var/packages/stunnel
2023/04/30 09:03:41	install stunnel 5.60-2 End /bin/mkdir -p /var/packages/stunnel ret=[0]
2023/04/30 09:03:41	install stunnel 5.60-2 Begin /bin/mv -f /volume1/@tmp/pkginstall/INFO /var/packages/stunnel/INFO
2023/04/30 09:03:41	install stunnel 5.60-2 End /bin/mv -f /volume1/@tmp/pkginstall/INFO /var/packages/stunnel/INFO ret=[0]
2023/04/30 09:03:41	install stunnel 5.60-2 Begin /bin/rm -rf /var/packages/stunnel/scripts
2023/04/30 09:03:42	install stunnel 5.60-2 End /bin/rm -rf /var/packages/stunnel/scripts ret=[0]
2023/04/30 09:03:42	install stunnel 5.60-2 Begin /bin/mv -f /volume1/@tmp/pkginstall/scripts /var/packages/stunnel/scripts
2023/04/30 09:03:42	install stunnel 5.60-2 End /bin/mv -f /volume1/@tmp/pkginstall/scripts /var/packages/stunnel/scripts ret=[0]
2023/04/30 09:03:42	install stunnel 5.60-2 Begin /bin/rm -rf /var/packages/stunnel/conf
2023/04/30 09:03:42	install stunnel 5.60-2 End /bin/rm -rf /var/packages/stunnel/conf ret=[0]
2023/04/30 09:03:42	install stunnel 5.60-2 Begin /bin/mv -f /volume1/@tmp/pkginstall/conf /var/packages/stunnel/conf
2023/04/30 09:03:43	install stunnel 5.60-2 End /bin/mv -f /volume1/@tmp/pkginstall/conf /var/packages/stunnel/conf ret=[0]
2023/04/30 09:03:53	install stunnel 5.60-2 Begin postinst
2023/04/30 09:03:53	===> Step postinst. USER=stunnel GROUP= SHARE_PATH=
2023/04/30 09:03:54	Granting 'sc-stunnel' unix ownership on /volume1/@appstore/stunnel/var
2023/04/30 09:03:54	install stunnel 5.60-2 End postinst ret=[0]
2023/04/30 09:03:54	install stunnel 5.60-2 Begin /bin/rm -rf /volume1/@tmp/pkginstall
2023/04/30 09:03:54	install stunnel 5.60-2 End /bin/rm -rf /volume1/@tmp/pkginstall ret=[0]
2023/04/30 09:04:16	install stunnel 5.60-2 Begin start-stop-status start
2023/04/30 09:04:16	install stunnel 5.60-2 End start-stop-status start ret=[0]

Service Log

No response

Other Logs

2023.04.30 17:49:11 LOG6[ui]: Initializing inetd mode configuration
2023.04.30 17:49:11 LOG7[ui]: Clients allowed=500
2023.04.30 17:49:11 LOG5[ui]: stunnel 5.60 on arm-marvell-linux-gnueabi platform
2023.04.30 17:49:11 LOG5[ui]: Compiled/running with OpenSSL 1.1.1l  24 Aug 2021
2023.04.30 17:49:11 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,OCSP,PSK,SNI Auth:LIBWRAP
2023.04.30 17:49:11 LOG7[ui]: errno: (*__errno_location ())
2023.04.30 17:49:11 LOG6[ui]: Initializing inetd mode configuration
2023.04.30 17:49:11 LOG5[ui]: Reading configuration from file /volume1/@appstore/stunnel/etc/stunnel/stunnel.conf
2023.04.30 17:49:11 LOG5[ui]: UTF-8 byte order mark detected
2023.04.30 17:49:11 LOG5[ui]: FIPS mode disabled
2023.04.30 17:49:11 LOG6[ui]: Compression enabled: 0 methods
2023.04.30 17:49:11 LOG7[ui]: No PRNG seeding was required
2023.04.30 17:49:11 LOG6[ui]: Initializing service [harbinger]
2023.04.30 17:49:12 LOG6[ui]: stunnel default security level set: 2
2023.04.30 17:49:12 LOG7[ui]: Ciphers: HIGH:!aNULL:!SSLv2:!DH:!kDHEPSK
2023.04.30 17:49:12 LOG7[ui]: TLSv1.3 ciphersuites: TLS_AES_256_GCM_SHA384:TLS_AES_128_GCM_SHA256:TLS_CHACHA20_POLY1305_SHA256
2023.04.30 17:49:12 LOG7[ui]: TLS options: 0x02100004 (+0x00000000, -0x00000000)
2023.04.30 17:49:12 LOG6[ui]: Session resumption enabled
2023.04.30 17:49:12 LOG7[ui]: No certificate or private key specified
2023.04.30 17:49:12 LOG6[ui]: DH initialization skipped: client section
2023.04.30 17:49:12 LOG7[ui]: ECDH initialization
2023.04.30 17:49:12 LOG7[ui]: ECDH initialized with curves X25519:P-256:X448:P-521:P-384
2023.04.30 17:49:12 LOG5[ui]: Configuration successful
2023.04.30 17:49:12 LOG7[ui]: Deallocating deployed section defaults
2023.04.30 17:49:12 LOG7[ui]: Binding service [mySSH]
2023.04.30 17:49:12 LOG7[ui]: Listening file descriptor created (FD=10)
2023.04.30 17:49:12 LOG7[ui]: Setting accept socket options (FD=10)
2023.04.30 17:49:12 LOG7[ui]: Option SO_REUSEADDR set on accept socket
2023.04.30 17:49:12 LOG6[ui]: Service [mySSH] (FD=10) bound to 0.0.0.0:18022
2023.04.30 17:49:12 LOG7[ui]: Listening file descriptor created (FD=11)
2023.04.30 17:49:12 LOG7[ui]: Setting accept socket options (FD=11)
2023.04.30 17:49:12 LOG7[ui]: Option SO_REUSEADDR set on accept socket
2023.04.30 17:49:12 LOG5[ui]: Binding service [mySSH] to :::18022: Address already in use (98)
2023.04.30 17:49:12 LOG7[ui]: No pid file being created
2023.04.30 17:49:12 LOG7[cron]: Cron thread initialized
2023.04.30 17:49:12 LOG6[cron]: Executing cron jobs
2023.04.30 17:49:12 LOG6[cron]: Cron jobs completed in 0 seconds
2023.04.30 17:49:12 LOG7[cron]: Waiting 86400 seconds
2023.04.30 17:52:47 LOG3[ui]: local socket: Function not implemented (38)
2023.04.30 17:52:47 LOG7[ui]: Found 1 ready file descriptor(s)
2023.04.30 17:52:47 LOG7[ui]: FD=4 events=0x2001 revents=0x0
2023.04.30 17:52:47 LOG7[ui]: FD=10 events=0x2001 revents=0x1
2023.04.30 17:52:47 LOG3[ui]: local socket: Function not implemented (38)
2023.04.30 17:52:47 LOG7[ui]: Found 1 ready file descriptor(s)
2023.04.30 17:52:47 LOG7[ui]: FD=4 events=0x2001 revents=0x0
2023.04.30 17:52:47 LOG7[ui]: FD=10 events=0x2001 revents=0x1
2023.04.30 17:52:47 LOG3[ui]: local socket: Function not implemented (38)
2023.04.30 17:52:47 LOG7[ui]: Found 1 ready file descriptor(s)
2023.04.30 17:52:47 LOG7[ui]: FD=4 events=0x2001 revents=0x0
2023.04.30 17:52:47 LOG7[ui]: FD=10 events=0x2001 revents=0x1
2023.04.30 17:52:47 LOG3[ui]: local socket: Function not implemented (38)
2023.04.30 17:52:47 LOG7[ui]: Found 1 ready file descriptor(s)
2023.04.30 17:52:47 LOG7[ui]: FD=4 events=0x2001 revents=0x0
2023.04.30 17:52:47 LOG7[ui]: FD=10 events=0x2001 revents=0x1
2023.04.30 17:52:47 LOG3[ui]: local socket: Function not implemented (38)
<...>

[hgy59]

@fcoquelet I guess this error is caused by the old kernel version or by the ARMv5 arch.

The error 38 shown in the log file is a system error defined in "errno.h" (of the build toolchain) as

#define	ENOSYS		38	/* Function not implemented */

In the stunnel source code there are the following functions writing "FD=..." logs in the loop reported by you:

void s_poll_dump(s_poll_set *fds, int level) {
    unsigned i;

    for(i=0; i<fds->nfds; i++)
        s_log(level, "FD=%ld events=0x%X revents=0x%X",
            (long)fds->ufds[i].fd, fds->ufds[i].events, fds->ufds[i].revents);
}

The error log is not so easy to locate in the source code.

There are generic logger funcions defined in log.c

void ioerror(const char *txt) { /* input/output error */
    log_error(LOG_ERR, (int)get_last_error(), txt);
}

void sockerror(const char *txt) { /* socket error */
    log_error(LOG_ERR, get_last_socket_error(), txt);
}

void log_error(int level, int error, const char *txt) { /* generic error */
    s_log(level, "%s: %s (%d)", txt, s_strerror(error), error);
}

The error local socket: Function not implemented (38) must occur when calling s=s_accept(fd, &addr.sa, &addrlen, 1, "local socket"); in stunnel.c.
This is the only code with the text "local socket".

s_accept is called in accept_connection function within the daemon_loop in stunnel.c

s_accept is implemented in fd.c (file descriptor functions) and is calling setup_fd.

if setup_fd is called with an invalid socket file descriptor, the error reported is logged with socketerror and the message local socket is comming from the call of s_accept.

    if(fd==INVALID_SOCKET) {
        sockerror(msg);
        return INVALID_SOCKET;
    }

TL;DR stunnel fails to open (connect to) the socket(s) to listen on your system.