call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')])

[Creeper19472]

As stated in the title. I'm trying to enable FTP over TLS and have inherited the TLS_FTPHandler class when writing my own custom Handler.

However, this led to some hard-to-ignore but hard-to-identify causes of problems in the connection, leading to extremely high CPU usage and making the log file several gigabytes long (I turned on debug logging).

Recurrence:

Using client: FileZilla Pro

FileZilla Pro
-------------

Version:          3.61.1

Build information:
  Compiled for:   x86_64-w64-mingw32
  Compiled on:    x86_64-pc-linux-gnu
  Build date:     2022-09-30
  Compiled with:  x86_64-w64-mingw32-gcc (GCC) 10-win32 20210110
  Compiler flags:  -O2 -g -Wall -Wextra -Wno-deprecated-copy -ffunction-sections -fdata-sections -Wno-cast-function-type

Linked against:
  wxWidgets:      3.0.6
  SQLite:         3.35.5
  GnuTLS:         3.7.7

Operating system:
  Name:           Windows Server 2016 (build 20348), 64-bit edition
  Version:        10.0
  Platform:       64-bit system
  CPU features:   sse sse2 sse3 ssse3 sse4.1 sse4.2 avx avx2 aes pclmulqdq rdrnd bmi bmi2 adx lm
  Settings dir:   [REDACTED]

1. Initialize the server. I am in the process of integrating the FTP service into a system and the document that oversees the FTP service is here: https://github.com/Creeper19472/cfms_2/blob/3646c8fd6de376489d7bc7e93946bc302ec064ca/include/fileftp/pyftpd.py

To start from the file itself, you should probably pass main() the absolute path to its project folder (I'm assuming you've cloned the repository, since this file needs to be backed by the database initialized by cfms_server.py in the root directory). And don't forget to install requirements (pip install -i requirements.txt)

Run cfms_server.py (in the root directory), and it will initialize itself. Meanwhile it will start the ftp service on port 5104 (by default).

2. Create a database entry in content/fqueue.db. (It's a sqlite3 file) Like this:

INSERT INTO "main"."ft_queue" ("task_id", "token", "operation", "file_id", "fake_id", "fake_dir", "expire_time", "done") VALUES ('e6222cd64d3da6e99f9da8bd2c125101945ed15fa4218d3956ac254a97e1a7b9519fec189e41f6c6367fd61fb11bd217a37cfb0135b745cd21992812cfa19517', '["ca17b203c685b1300dd0317a1b0ad60b48eb5465dcc67efafcb6d3eee103f481", "53e12e72baccda5c0e37fed1b7180bbd"]', 'read', '0', 'acdc5311fac9aa2def188b2cd7c9f361523aa6c018ce6ed28034f16f607c71594d7f0cecf27ef069affbc69c2548d00d1a238761c3b805839b0c97d6f10f9d77', 'e6222cd64d3da6e99f9da8bd2c125101945ed15fa4218d3956ac254a97e1a7b9519fec189e41f6c6367fd61fb11bd217a37cfb0135b745cd21992812cfa19517', '1688993648.48515', '0');

3. Open FileZilla and connect to the server (deafult address is localhost:5104), username: e6222cd64d3da6e99f9da8bd2c125101945ed15fa4218d3956ac254a97e1a7b9519fec189e41f6c6367fd61fb11bd217a37cfb0135b745cd21992812cfa19517, password: c54cc034130651c23416cd20f522fae855cc8fa869783b1798c0ad1d0d00d484 (per above)

4. download a file. then close the connection from FileZilla.

5. And see the log file. Like this below:

...
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
2023-07-09 19:53:11,499 - pyftpdlib - DEBUG - [debug] call: _do_ssl_shutdown() -> shutdown(), err: Error([('SSL routines', '', 'shutdown while in init')]) (<FTPCustomizedHandler(id=2196548107344, addr='::1:61185', ssl=True)>)
...

I tried to find out what's going on, but I still have no idea after searching the Internet. The only thing I found is that this log seemed to be made by handlers.py (pyftpdlib), in line 3402:

            except SSL.SysCallError as err:
                debug("call: _do_ssl_shutdown() -> shutdown(), err: %r" % err,
                      inst=self)
                errnum, errstr = err.args
                if errnum in _ERRNOS_DISCONNECTED or \
                        errstr == 'Unexpected EOF':
                    super().close()
                else:
                    raise
            except SSL.Error as err:
                debug("call: _do_ssl_shutdown() -> shutdown(), err: %r" % err,
                      inst=self)
                # see:
                # https://github.com/giampaolo/pyftpdlib/issues/171
                # https://bugs.launchpad.net/pyopenssl/+bug/785985
                if err.args and not getattr(err, "errno", None):
                    pass
                else:
                    raise
            except socket.error as err:
                debug("call: _do_ssl_shutdown() -> shutdown(), err: %r" % err,
                      inst=self)
                if err.errno in _ERRNOS_DISCONNECTED:
                    super().close()
                else:
                    raise

But I actually don't know which statement caught the exception.

[Creeper19472]

Well I just modified the module's source code and now figured out that the Exception was handled by except SSL.Error.

[Creeper19472]

I modified the source code to this:

            except SSL.Error as err:
                debug("SSL.Error call: _do_ssl_shutdown() -> shutdown(), err: %r" % err,
                      inst=self)
                # see:
                # https://github.com/giampaolo/pyftpdlib/issues/171
                # https://bugs.launchpad.net/pyopenssl/+bug/785985
                print(err)
                print(err.args)
                print(err.errno)
                if err.args and not getattr(err, "errno", None):
                    pass
                else:
                    raise

And it raised an error without doubt, saying that the Error object does not have an attribute named "errno".

However, I don't know when will the SSL.Error object have a attribute named this. I found that this exception class inherits from the built-in class of Exception, but it does not overload a new errno property in it, and this property is not owned by the built-in Exception class.

In summary, since the errno property never seems to exist, getattr() will always return its set default value None, and make the latter condition in the if statement always true; Err.args will always exist and have value because it returns the error number and description string of the exception, so this statement will cause the exception to always be ignored, resulting in an infinite loop of exception handling logic that I have not yet figured out.

[Creeper19472]

Oh, I just looked up the code defining the other exceptions. It seems that the OSError class additionally defines the errno attribute.

However, SSL.Error seems to be less closely related to this exception class if its subclass has no other part that deals with OSError.