String Index of out Range with JSON log

redwiz666 commented 3 years ago

Behaviour

When processing a JSON log for traefik. receive an string index out of range error.

Steps to reproduce this issue

Using this sample data set: {"ClientAddr":"10.244.244.244:54816","ClientHost":"10.244.244.244","ClientPort":"54816","ClientUsername":"-","DownstreamContentSize":2,"DownstreamStatus":200,"Duration":301232,"OriginContentSize":2,"OriginDuration":40659,"OriginStatus":401,"Overhead":260573,"RequestAddr":"10.244.1.244:8100","RequestContentSize":0,"RequestCount":17757,"RequestHost":"10.244.1.244","RequestMethod":"GET","RequestPath":"/ping","RequestPort":"8100","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"ping@internal","StartLocal":"2021-01-31T10:41:04.654393666Z","StartUTC":"2021-01-31T10:41:04.654393666Z","entryPointName":"traefik","level":"info","msg":"","time":"2021-01-31T10:41:04Z"} {"ClientAddr":"10.244.244.244:54816","ClientHost":"10.244.244.244","ClientPort":"54816","ClientUsername":"-","DownstreamContentSize":2,"DownstreamStatus":200,"Duration":301232,"OriginContentSize":2,"OriginDuration":40659,"OriginStatus":200,"Overhead":260573,"RequestAddr":"10.244.1.244:8100","RequestContentSize":0,"RequestCount":17757,"RequestHost":"10.244.1.244","RequestMethod":"GET","RequestPath":"/ping","RequestPort":"8100","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"ping@internal","StartLocal":"2021-01-31T10:41:04.654393666Z","StartUTC":"2021-01-31T10:41:04.654393666Z","entryPointName":"traefik","level":"info","msg":"","time":"2021-01-31T10:41:04Z"}

with this failregex filter ^{.+,.ClientHost...<HOST>.+OriginStatus..401.+$

then test regex with the following command fail2ban-regex /var/log/traefik/access.log /etc/fail2ban/filter.d/traefik-auth.conf

Expected behaviour

this should have been able to retrieve the IP address of the Client for blocking.

Actual behaviour

Traceback (most recent call last): File "/usr/bin/fail2ban-regex", line 34, in <module> exec_command_line() File "/usr/lib/python3.8/site-packages/fail2ban/client/fail2banregex.py", line 836, in exec_command_line if not fail2banRegex.start(args): File "/usr/lib/python3.8/site-packages/fail2ban/client/fail2banregex.py", line 776, in start self.process(test_lines) File "/usr/lib/python3.8/site-packages/fail2ban/client/fail2banregex.py", line 584, in process line_datetimestripped, ret, is_ignored = self.testRegex(line) File "/usr/lib/python3.8/site-packages/fail2ban/client/fail2banregex.py", line 456, in testRegex found = self._filter.processLine(line, date) File "/usr/lib/python3.8/site-packages/fail2ban/server/filter.py", line 613, in processLine timeMatch = self.dateDetector.matchTime(line) File "/usr/lib/python3.8/site-packages/fail2ban/server/datedetector.py", line 368, in matchTime (line[distance] == self.__lastPos[2] and not self.__lastPos[2].isalnum()) IndexError: string index out of range

Configuration

running crazymax/fail2ban:latest in kubernetes with docker backend

Docker version 19.03.14, build 5eb3275d40

Platform (Debian 9, Ubuntu 18.04, ...) : Distributor ID: Ubuntu Description: Ubuntu 20.04.1 LTS Release: 20.04 Codename: focal
System info (type uname -a) : Linux kube-slave3 5.4.0-56-generic #62-Ubuntu SMP Mon Nov 23 19:20:19 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
Include all necessary configuration files : docker-compose.yml, .env, ... traefik-auth.conf [Definition] failregex=^{.+,.ClientHost...<HOST>.+OriginStatus..401.+$ ignoreregex=

Logs


> Container logs (set LOG_LEVEL to debug if applicable)
`Setting timezone to America/Chicago...
Setting SSMTP configuration...
WARNING: SSMTP_HOST must be defined if you want fail2ban to send emails
Initializing files and folders...
Setting Fail2ban configuration...
Checking for custom actions in /data/action.d...
Checking for custom filters in /data/filter.d...
  WARNING: traefik-auth.conf already exists and will be overriden
  Add custom filter traefik-auth.conf...
  Add custom filter traefik-botsearch.conf...
2021-01-31 09:08:44,717 fail2ban.configreader   [1]: INFO    Loading configs for fail2ban under /etc/fail2ban
2021-01-31 09:08:44,719 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/fail2ban.conf']
2021-01-31 09:08:44,720 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/fail2ban.conf']
2021-01-31 09:08:44,721 fail2ban                [1]: INFO    Using socket file /var/run/fail2ban/fail2ban.sock
2021-01-31 09:08:44,721 fail2ban                [1]: INFO    Using pid file /var/run/fail2ban/fail2ban.pid, [INFO] logging to STDOUT
2021-01-31 09:08:44,726 fail2ban.configreader   [1]: INFO    Loading configs for jail under /etc/fail2ban
2021-01-31 09:08:44,730 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/jail.conf']
2021-01-31 09:08:44,752 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/paths-debian.conf']
2021-01-31 09:08:44,754 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/paths-common.conf']
2021-01-31 09:08:44,757 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/paths-overrides.local']
2021-01-31 09:08:44,757 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/jail.d/traefik.conf']
2021-01-31 09:08:44,760 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/paths-common.conf', '/etc/fail2ban/paths-debian.conf', '/etc/fail2ban/jail.conf', '/etc/fail2ban/jail.d/traefik.conf']
2021-01-31 09:08:44,783 fail2ban.configreader   [1]: INFO    Loading configs for filter.d/traefik-auth under /etc/fail2ban
2021-01-31 09:08:44,784 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/filter.d/traefik-auth.conf']
2021-01-31 09:08:44,788 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/filter.d/traefik-auth.conf']
2021-01-31 09:08:44,791 fail2ban.configreader   [1]: INFO    Loading configs for action.d/cloudflare under /etc/fail2ban
2021-01-31 09:08:44,792 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/action.d/cloudflare.conf']
2021-01-31 09:08:44,793 fail2ban.configparserinc[1]: INFO      Loading files: ['/etc/fail2ban/action.d/cloudflare.conf']
2021-01-31 09:08:44,844 fail2ban.server         [1]: INFO    --------------------------------------------------
2021-01-31 09:08:44,845 fail2ban.server         [1]: INFO    Starting Fail2ban v0.11.2
2021-01-31 09:08:44,846 fail2ban.observer       [1]: INFO    Observer start...
2021-01-31 09:08:44,860 fail2ban.database       [1]: INFO    Connected to fail2ban persistent database '/data/db/fail2ban.sqlite3'
2021-01-31 09:08:44,884 fail2ban.jail           [1]: INFO    Creating new jail 'traefik-auth'
2021-01-31 09:08:44,900 fail2ban.jail           [1]: INFO    Jail 'traefik-auth' uses pyinotify {}
2021-01-31 09:08:44,902 fail2ban.jail           [1]: INFO    Initiated 'pyinotify' backend
2021-01-31 09:08:44,924 fail2ban.filter         [1]: INFO      maxRetry: 5
2021-01-31 09:08:44,924 fail2ban.filter         [1]: INFO      findtime: 300
2021-01-31 09:08:44,925 fail2ban.actions        [1]: INFO      banTime: 600
2021-01-31 09:08:44,925 fail2ban.filter         [1]: INFO      encoding: UTF-8
2021-01-31 09:08:44,941 fail2ban.filter         [1]: INFO    Added logfile: '/var/log/traefik/access.log' (pos = 14521549, hash = fce6f10bfea58f8416a8a993a105da412e10e791)
2021-01-31 09:08:44,961 fail2ban.jail           [1]: INFO    Jail 'traefik-auth' started
Server ready
2021-01-31 09:13:49,867 fail2ban.filter         [1]: ERROR   Failed to process line: '{"ClientAddr":"10.244.244.244:54816","ClientHost":"10.244.244.244","ClientPort":"54816","ClientUsername":"-","DownstreamContentSize":2,"DownstreamStatus":200,"Duration":301232,"OriginContentSize":2,"OriginDuration":40659,"OriginStatus":401,"Overhead":260573,"RequestAddr":"10.244.1.244:8100","RequestContentSize":0,"RequestCount":17757,"RequestHost":"10.244.1.244","RequestMethod":"GET","RequestPath":"/ping","RequestPort":"8100","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"ping@internal","StartLocal":"2021-01-31T10:41:04.654393666Z","StartUTC":"2021-01-31T10:41:04.654393666Z","entryPointName":"traefik","level":"info","msg":"","time":"2021-01-31T10:41:04Z"}', caught exception: IndexError('string index out of range')`

ronyshtamler commented 3 years ago

I am having the same issue with a regular log file (not JSON):

Example: 2021-03-11 14:15:38,948 fail2ban.filter [1]: ERROR Failed to process line: 'c44843a4-d0ff-4493-8a40-37fb0841db04 stack traceback:', caught exception: IndexError('string index out of range')

ronyshtamler commented 3 years ago

and another error:

2021-03-11 14:21:05,710 fail2ban.filter [1]: ERROR Failed to process line: '2f06fefa-5f41-4bcb-a8c9-7de085a9a74f \t[C]: in function rename', caught exception: IndexError('string index out of range')

sandrodz commented 3 years ago

Seems this has been fixed: https://github.com/fail2ban/fail2ban/issues/2967 But I am still getting an error. hm.

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

crazy-max / docker-fail2ban