mrash / fwknop

Single Packet Authorization > Port Knocking
http://www.cipherdyne.org/fwknop/
GNU General Public License v2.0
1.09k stars 228 forks source link

Large count of “FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL” messages in the log #337

Open pwolny opened 2 years ago

pwolny commented 2 years ago

First of all thanks for this useful software.

When fwknopd is configured for multiple user access (multiple stanzas with “SOURCE ANY” directive in access.conf) I get in the log multiple FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL before the packet is matched to the right stanza. Repetition count depends on which stanza is matched. Repetition count changes by changing order of the stanzas in the access.conf.

For example I get the message once in daemon.log for authorization packet matching second stanza in access.conf: fwknopd[xxx]:(stanza #1) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #1) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #2) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: Added access rule to FWKNOP_INPUT for xxx.xxx.xxx.xxx -> 0.0.0.0/0 udp/12345, expires at xxxxxxxxxxxx fwknopd[xxx]: Removed rule 1 from FWKNOP_INPUT with expire time of xxxxxxxxxxxx

or 5 times for the 6th stanza in access.conf: fwknopd[xxx]: (stanza #1) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #1) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #2) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #2) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #3) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #3) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #4) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #4) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #5) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: [xxx.xxx.xxx.xxx] (stanza #5) Error creating fko context: Args contain invalid data: FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL fwknopd[xxx]: (stanza #6) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: Added access rule to FWKNOP_INPUT for xxx.xxx.xxx.xxx -> 0.0.0.0/0 tcp/12346, expires at xxxxxxxxxxxx fwknopd[xxx]: Removed rule 1 from FWKNOP_INPUT with expire time of xxxxxxxxxxxx

and never when the packet matches 1st stanza in access.conf. fwknopd[xxx]: (stanza #1) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match fwknopd[xxx]: Added access rule to FWKNOP_INPUT for xxx.xxx.xxx.xxx -> 0.0.0.0/0 tcp/22, expires at xxxxxxxxxxxx

I like that I have the info when the authorization packet arrives, even if it is invalid but it looks like the authorization packet is compared sequentially to all stanzas and all failures in the loop are logged.

Is it possible to log this “FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL” message only once for each received packet by changing the default settings of fwknopd?

I would like to set fwknopd in such a way that this message would never get logged if packet matches a stanza so the log does not get spammed. Of course I would like to still get this message if (once) when none of the stanzas could be matched to the received packet.

My system is: “Debian 5.10.46-4 (2021-08-03) x86_64 GNU/Linux” with: “fwknopd server 2.6.10, compiled for firewall bin: /usr/sbin/iptables”

Seb35 commented 8 months ago

The log we are discussing is this one.

We are arriving here with this stacktrace:

This log is emitted when a legitimate user sends a SPA but her/his stanza is not the first one (false positive case), and it also emitted when an attacker sends a forged SPA (true positive case).

There are various way to “fix” this issue:

  1. transform the log level LOG_WARNING to LOG_DEBUG: we are missing some informations for all errors and particularly for the true-positive cases,
  2. add an “if” specifically for this error FKO_ERROR_INVALID_DATA_HMAC_COMPAREFAIL given it may be legitimate (and emit this error with LOG_DEBUG)
  3. soften the message to say something like [LOG_INFO] “Non-corresponding HMAC for this stanza” (I’m not a native English speaker, there may be spelling issues) (NB: when removing the word "error", vi /var/log/syslog does not display the line in red)
  4. wait before emitting logs until a serious error or at the end if no stanza was found: this may be difficult to properly implement because there are many possible logs in the treatment of each stanza, and even if you buffer logs to be emitted (with some mechanism to be implemented) then the precise time will be delayed until the buffer is flushed.

Personally I vote for the 2nd and 3rd solutions together: an “if” for this error, emit the current error with LOG_DEBUG and emit a new log with LOG_INFO (to avoid losing information compared to the current situation, it may be important in case of true [sophisticated] attack).

Seb35 commented 8 months ago

Here is the PR #358 corresponding to my proposition. The result is these logs:

fwknopd[xxx]: (stanza #1) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match
fwknopd[xxx]: (stanza #1) Non-corresponding HMAC for this stanza
fwknopd[xxx]: (stanza #2) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match
fwknopd[xxx]: (stanza #2) Non-corresponding HMAC for this stanza
fwknopd[xxx]: (stanza #3) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match
fwknopd[xxx]: (stanza #3) Non-corresponding HMAC for this stanza
fwknopd[xxx]: (stanza #4) SPA Packet from IP: xxx.xxx.xxx.xxx received with access source match
fwknopd[xxx]: Added access rule to FWKNOP_INPUT for xxx.xxx.xxx.xxx -> 0.0.0.0/0 tcp/1234, expires at xxxxxx

All logs have the level INFO, so no more WARNINGs in normal operations, but still logs INFO when the sysadmin wants to keep details.