BanOnEvent BadProtocol triggers segfault

[ElDavoo]

What I Did

I configured mod_ban in order to ban users and I tried banning myself.

What I Expected/Wanted

I expected proftpd to ban me.

Note that I can get myself banned using ftpdctl .

ProFTPD Version and Configuration

Compile-time Settings:
  Version: 1.3.6 (stable)
  Platform: LINUX [Linux 5.10.103-v7+ armv7l]
  Built: Sat Sep 18 2021 21:05:52 UTC
  Built With:
    configure  '--build=arm-linux-gnueabihf' '--includedir=${prefix}/include' '--mandir=${prefix}/share/man' '--infodir=${prefix}/share/info' '--sysconfdir=/etc' '--localstatedir=/var' '--disable-silent-rules' '--libdir=${prefix}/lib/arm-linux-gnueabihf' '--libexecdir=${prefix}/lib/arm-linux-gnueabihf' '--disable-maintainer-mode' '--disable-dependency-tracking' '--prefix=/usr' '--with-includes=/usr/include/postgresql:/usr/include/mariadb:/usr/include/mariadb/mysql' '--mandir=/usr/share/man' '--sysconfdir=/etc/proftpd' '--localstatedir=/run' '--libexecdir=/usr/lib/proftpd' '--enable-sendfile' '--enable-facl' '--enable-dso' '--enable-autoshadow' '--enable-ctrls' '--enable-ipv6' '--enable-nls' '--enable-memcache' '--with-lastlog=/var/log/lastlog' '--enable-pcre' '--disable-strip' '--enable-redis' '--build' 'arm-linux-gnueabihf' '--with-shared=mod_unique_id:mod_site_misc:mod_load:mod_ban:mod_quotatab:mod_sql:mod_sql_mysql:mod_sql_postgres:mod_sql_sqlite:mod_sql_odbc:mod_dynmasq:mod_quotatab_sql:mod_ldap:mod_quotatab_ldap:mod_ratio:mod_tls:mod_rewrite:mod_radius:mod_wrap:mod_wrap2:mod_wrap2_file:mod_wrap2_sql:mod_quotatab_file:mod_quotatab_radius:mod_facl:mod_ctrls_admin:mod_copy:mod_deflate:mod_ifversion:mod_geoip:mod_exec:mod_sftp:mod_sftp_pam:mod_sftp_sql:mod_shaper:mod_sql_passwd:mod_ifsession:mod_auth_otp:mod_tls_redis:mod_wrap2_redis:mod_redis:mod_memcache:mod_tls_memcache:mod_readme:mod_snmp' 'build_alias=arm-linux-gnueabihf' 'CFLAGS=-g -O2 -fdebug-prefix-map=/build/proftpd-dfsg-756elr/proftpd-dfsg-1.3.6=. -fstack-protector-strong -Wformat -Werror=format-security' 'LDFLAGS=-Wl,-z,relro' 'CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2' 'CXXFLAGS=-g -O2 -fdebug-prefix-map=/build/proftpd-dfsg-756elr/proftpd-dfsg-1.3.6=. -fstack-protector-strong -Wformat -Werror=format-security'

  CFLAGS: -g2 -g -O2 -fdebug-prefix-map=/build/proftpd-dfsg-756elr/proftpd-dfsg-1.3.6=. -fstack-protector-strong -Wformat -Werror=format-security -Wall -fno-omit-frame-pointer -Werror=implicit-function-declaration
  LDFLAGS: -L$(top_srcdir)/lib -Wl,-z,relro -rdynamic  -L/usr/lib/arm-linux-gnueabihf/ -L/usr/lib/arm-linux-gnueabihf
  LIBS: -lacl  -lpcreposix -lpcre -lssl -lcrypto -lcap  -lpam -lsupp -lattr -lnsl -lresolv -lresolv -lcrypt -ldl -lhiredis -lmemcachedutil -lmemcached

  Files:
    Configuration File:
      /etc/proftpd/proftpd.conf
    Pid File:
      /run/proftpd.pid
    Scoreboard File:
      /run/proftpd.scoreboard
    Header Directory:
      /usr/include/proftpd
    Shared Module Directory:
      /usr/lib/proftpd

  Info:
    + Max supported UID: 4294967295
    + Max supported GID: 4294967295

  Features:
    + Autoshadow support
    + Controls support
    + curses support
    - Developer support
    + DSO support
    + IPv6 support
    + Largefile support
    + Lastlog support
    + Memcache support
    + ncursesw support
    + NLS support
    + Redis support
    - Sodium support
    + OpenSSL support
    + PCRE support
    + POSIX ACL support
    + Shadow file support
    + Sendfile support
    + Trace support
    + xattr support

  Tunable Options:
    PR_TUNABLE_BUFFER_SIZE = 1024
    PR_TUNABLE_DEFAULT_RCVBUFSZ = 8192
    PR_TUNABLE_DEFAULT_SNDBUFSZ = 8192
    PR_TUNABLE_ENV_MAX = 2048
    PR_TUNABLE_GLOBBING_MAX_MATCHES = 100000
    PR_TUNABLE_GLOBBING_MAX_RECURSION = 8
    PR_TUNABLE_HASH_TABLE_SIZE = 40
    PR_TUNABLE_LOGIN_MAX = 256
    PR_TUNABLE_NEW_POOL_SIZE = 512
    PR_TUNABLE_PATH_MAX = 4096
    PR_TUNABLE_SCOREBOARD_BUFFER_SIZE = 80
    PR_TUNABLE_SCOREBOARD_SCRUB_TIMER = 30
    PR_TUNABLE_SELECT_TIMEOUT = 30
    PR_TUNABLE_TIMEOUTIDENT = 10
    PR_TUNABLE_TIMEOUTIDLE = 600
    PR_TUNABLE_TIMEOUTLINGER = 10
    PR_TUNABLE_TIMEOUTLOGIN = 300
    PR_TUNABLE_TIMEOUTNOXFER = 300
    PR_TUNABLE_TIMEOUTSTALLED = 3600
    PR_TUNABLE_XFER_SCOREBOARD_UPDATES = 10

proftpd.conf
modules.conf
conf.d/ctrl.conf
conf.d/ban.conf

mod_ban logs only show:

2022-05-05 18:46:08,512 mod_ban/0.7[4117]: removed shmid 6914049 for BanTable '/etc/proftpd/ban.tab'
2022-05-05 18:46:08,792 mod_ban/0.7[4153]: obtained shmid 6914094 for BanTable '/etc/proftpd/ban.tab'
2022-05-05 18:47:54,608 mod_ban/0.7[4154]: detached shmid 6914094 for BanTable '/etc/proftpd/ban.tab'

general-log.txt

general logs

[Castaglia]

In the provided log, I do see these log messages, indicating that mod_ban does indeed appear to be working:

2022-05-05 19:02:54,407 redacted proftpd[4372] 127.0.1.1 (redactedip[redactedip]): mod_ban/0.7: Login denied: host 'redactedip' banned
2022-05-05 19:02:54,407 redacted proftpd[4372] 127.0.1.1 (redactedip[redactedip]): mod_ban.c: error initializing session: Permesso negato
2022-05-05 19:02:59,455 redacted proftpd[4373] 127.0.1.1 (redactedip[redactedip]): mod_ban/0.7: Login denied: host 'redactedip' banned
2022-05-05 19:02:59,461 redacted proftpd[4373] 127.0.1.1 (redactedip[redactedip]): mod_ban.c: error initializing session: Permesso negato

What is the current mod_ban behavior that is not occurring as you expect, specifically?

[ElDavoo]

In the provided log, I do see these log messages, indicating that mod_ban does indeed appear to be working:

2022-05-05 19:02:54,407 redacted proftpd[4372] 127.0.1.1 (redactedip[redactedip]): mod_ban/0.7: Login denied: host 'redactedip' banned
2022-05-05 19:02:54,407 redacted proftpd[4372] 127.0.1.1 (redactedip[redactedip]): mod_ban.c: error initializing session: Permesso negato
2022-05-05 19:02:59,455 redacted proftpd[4373] 127.0.1.1 (redactedip[redactedip]): mod_ban/0.7: Login denied: host 'redactedip' banned
2022-05-05 19:02:59,461 redacted proftpd[4373] 127.0.1.1 (redactedip[redactedip]): mod_ban.c: error initializing session: Permesso negato

What is the current mod_ban behavior that is not occurring as you expect, specifically?

Hi,
These lines might come from when I tested banning myself manually with ftpdctl.

I'm just excepting it to work. You know, showing the ip up in ftpdctl ban info -v, getting the BanMessage, and so on.

Maybe the allowlist is causing the problem? edit: no, i tried removing it

[Castaglia]

Can you tell me exactly how you're testing this feature, and what you see (and expect to see), so that I can reproduce locally the behavior you're seeing?

I'm just expecting it to work

Yes, but how, exactly? I don't know what your expectations are, so I don't know where to start to see where your configuration differs from the behavior you want to see..

[ElDavoo]

Can you tell me exactly how you're testing this feature, and what you see (and expect to see), so that I can reproduce locally the behavior you're seeing?

I'm just expecting it to work

Yes, but how, exactly? I don't know what your expectations are, so I don't know where to start to see where your configuration differs from the behavior you want to see..

ok.
I want to get banned from the server.
Be banned means any of the following behaviour:

1. Server won't answer to commands or would close the TCP connection and / or write a line in the log as you pointed out Login denied: host 'redactedip' banned
2. Upon attempting a correct login with a valid user/pass, instead of a succesful login I should get a failed login
3. I've written this line into the coniguration too:
   BanMessage "Host %a has been banned"
   So I'm expecting to see this line anywhere during a normal FTP session.
4. ftpdctl -s /var/run/proftpd/proftpd.sock ban info -v NOT saying this:
   ftpdctl: No bans

---

So it turns out many of the issue were me assuming the wrong thing.
E.g.:

• Did not know that RootLogin event gets generated for succesful root login events
• Did not know that AllowEmptyPasswords must be off in order for EmptyPassword event to work.
• Same story for MaxLoginAttempts, i did not put MaxLoginAttempts 1 into the config file. (this is what reading without taking attention makes you do...)
• Thought "AnonRejectPasswords" was generated for anonymous logins, but instead is generated when matching a regex from another configuration option. lol!

Yet, I managed to find what looks like an actual different, even though it's different.

Along the various events I tried triggering, there is BadProtocol. BadProtocol still does not trigger.
Recall on the relevant configuration line:
BanOnEvent BadProtocol 1/01:00:00 99:59:59
I'm expecting the server to ban me as soon as I try making an HTTP request to the proftpd server. This is how a BadProtocol event should be triggered, right?

What I try to do:

curl 10.10.11.14:21 -vv
*   Trying 10.10.11.14:21...
* TCP_NODELAY set
* Connected to 10.10.11.14 (10.10.11.14) port 21 (#0)
> GET / HTTP/1.1
> Host: 10.10.11.14:21
> User-Agent: curl/7.68.0
> Accept: */*
>
* Received HTTP/0.9 when not allowed

* Closing connection 0
curl: (1) Received HTTP/0.9 when not allowed`

This is written in the logs:

AuthOrder in effect, resetting auth module order
connected - local  : 10.10.11.14:21
connected - remote : 10.10.11.133:41980
FTP session opened.
setting CommandBufferSize to 256
client sent HTTP command 'GET', disconnecting
getnameinfo error: ai_family non supportata
-----BEGIN STACK TRACE-----
 -----END STACK TRACE-----
ProFTPD terminating (signal 11)

As I said before, after this request i'm expecting to see myself in the ftpdctl list, but instead I will always get the "no bans" message. After this request, I tried logging in with filezilla and I could open the connection without issues, while I'm expecting the authentication to not go through (as I said before, I'm expecting the login to fail or the server to close the tcp connection before checking for valid user/pass authentication)..

This however, seems to be because of the server crashing! :)

So, sorry for being unclear at the beginning, now I'm happy and looks like we found an actual issue
Let me know what you think

[Castaglia]

No worries about reporting the issues you see; it sometimes takes a little while for both sides to take a step back, and clarify what both sides are looking at. Once that happens, debugging (and fixing!) the behaviors we both see happens much faster.

This is definitely a problem:

-----BEGIN STACK TRACE-----
 -----END STACK TRACE-----
ProFTPD terminating (signal 11)

I see that you are running ProFTPD 1.3.6, which is a little older (and currently no longer supported) -- but that doesn't mean this bug doesn't exist anymore! I'll work on verifying this first. Might if I ask what distribution (and version) you are using? With that info, I should be able to spin up a Docker container of that distribution, install the same ProFTPD package, and then make it crash the same way you are. (Crashing would definitely prevent any BadProtocol events from being handled by mod_ban properly!)

[Castaglia]

I think I've managed to reproduce this "signal 11" behavior locally; tracking down the cause now.

[Castaglia]

This segfault should now be fixed in the master branch; the fix has been backported to the 1.3.7 branch as well.