CODEWITHSUNDEEP
google-compute-enginegoogle-cloud-platformfail2banpyinotify
Petri Riihikallio
Petri Riihikallio

Reputation: 33

Why IN_CLOSE_NOWRITE on Google Compute Engine w/Debian Stretch and pyinotify?

I tried setting up Fail2Ban on Google Cloud Compute Engine virtual machines based on stock Google images. Fail2Ban installs with apt-get and runs fine but the rules never fire. When I verify the rules with fail2ban-regex the rules do match lines in the actual log files.

After some investigation I found out that if I run pyinotify on a file that I change myself I see:

<Event dir=False mask=0x20 maskname=IN_OPEN name='' path=/tmp/test pathname=/tmp/test wd=1 >
<Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/tmp/test pathname=/tmp/test wd=1 >
<Event dir=False mask=0x8 maskname=IN_CLOSE_WRITE name='' path=/tmp/test pathname=/tmp/test wd=1 >

OTOH, the events for log files always end in IN_CLOSE_NOWRITE.

<Event dir=False mask=0x2 maskname=IN_MODIFY name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x20 maskname=IN_OPEN name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x1 maskname=IN_ACCESS name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >
<Event dir=False mask=0x10 maskname=IN_CLOSE_NOWRITE name='' path=/var/log/auth.log pathname=/var/log/auth.log wd=1 >

Is this the reason the rules don’t fire?

I have tried setting the Fail2Ban backend to polling, but without improvement. If I tail -f the log files I can see they are appended when there are events to be logged.

I have no idea if Google has tweaked their Debian images somehow or if this is a by-product of the virtualized environment.

What should be my next step?

Here is fail2ban.log:

2018-01-19 15:29:23,309 fail2ban.jail    [13935]: INFO    Jail 'sshd' uses pyinotify {}
2018-01-19 15:29:23,312 fail2ban.jail    [13935]: INFO    Initiated 'pyinotify' backend
2018-01-19 15:29:23,313 fail2ban.filter  [13935]: INFO    Set maxRetry = 5
2018-01-19 15:29:23,313 fail2ban.filter  [13935]: INFO    Added logfile = /var/log/auth.log
2018-01-19 15:29:23,314 fail2ban.filter  [13935]: INFO    Set findtime = 600
2018-01-19 15:29:23,314 fail2ban.actions [13935]: INFO    Set banTime = 600
2018-01-19 15:29:23,314 fail2ban.filter  [13935]: INFO    Set jail log file encoding to UTF-8
2018-01-19 15:29:23,315 fail2ban.filter  [13935]: INFO    Set maxlines = 10
2018-01-19 15:29:23,338 fail2ban.server  [13935]: INFO    Jail sshd is not a JournalFilter instance
2018-01-19 15:29:23,342 fail2ban.jail    [13935]: INFO    Jail 'sshd' started

No matter what auth.log gets there are no "[sshd] Found" lines.

Upvotes: 0

Views: 135

Answers (1)

Petri Riihikallio
Petri Riihikallio

Reputation: 33

Solved: I hadn't restarted the rsyslog service after setting time zone. Fail2ban was using local time while rsyslog was using UTC. Took me a while staring at the log I pasted above. I had not looked at the hours, the minutes and seconds matched. Kernel and userland were in localtime but rsyslog wasn't.

I still don't know why pyinotify would log IN_CLOSE_NOWRITE though. In my case it was a red herring after all.

Upvotes: 0

Related Questions