New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
FS#1468 - hostapd spams log #6816
Comments
jeffsf: //I am not the originator of this ticket and am not sure of its intent, but can supply some initial testing results// It appears that hostapd does not respect the value set in, for example, ''/var/run/hostapd-phy1.conf'' and continues to log "info" level messages even though it appears that the proper log-level settings are present from the settings in ''/etc/config/wireless'' I can't comment on if this is a change in behavior from the past as I manage my logging with ''syslog-ng'' and not by restricting the individual sources. OpenWrt SNAPSHOT, r6586+3-aed03d5 From ''/var/run/hostapd-phy1.conf'' From ''hostapd.conf'' in the upstream distribution
//Edit:// It looks like there are at least //two //code paths for logging in ''hostap'', one through ''wpa_printf()'' and another through ''wpa_auth_vlogger()''. |
arlit: **The following issue is not reproducible using r6501-745d0e7f4b and is likely a software regression: ** On r6671-f5195e72c0 hostapd handling of (Allow) MAC-ACL changed after [[https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=eba3b028e46dbfe54f1208e9edf47bb0c6f73ac8|commit eba3b02]] and it is now over-flooding syslog with multiple "notice" messages per second (see quote):
Please note that authentication attempts of wifi-clients (Stations) not listed in the Allow MAC-ACL result in slightly different output in syslog (see quote):
All "Not allowed to authenticate" messages overflooding hostapd are not coupled with same-MAC "handle_auth_cb" messages; As far I understand this means hostapd spams syslog while no actual connection attempt is really occurring. |
jeffsf: The log entries that brought this issue up in the forums appear to be expected 802.11 probe requests being //rejected// by ''hostapd'' as configured. In "busy" environments, users are interpreting this reporting of requested behavior as "spam". In my opinion, this should be resolved by allowing users to adjust the level of messages that appear in their log, not by removing the logging statement. |
arlit: I took care to test a previous build (r6501-745d0e7f4b) and the spamming behavior in question is absent while the "busy" environment remains unchanged (as flashing require few minutes ow downtime tests were made few minutes apart) |
arlit: Please note that if the "new behavior" introduced with commit eba3b02 is operating as intended, the entire syslog buffer will be filled by those entries in few hours. In my opinion //IF //the previous hostapd version (2017-08-24) was not operating "as intended" it had to be //purposely //meant to prevent syslog spamming with unhelpful messages. What would be the point to log rejected 802.11 probes like stated? Such amount of logspam should be caused by broadcast probes (many of those MAC I inspected belong to neighboring Access Points). In previous hostapd version (2017-08-24) Enabling MAC-ACL(allow) would have syslog list only // actual **authentication **attempt // as follows
Both entries were added to syslog or none of them at all. |
jeffsf: hostapd is an upstream project and widely used far beyond OpenWRT. ''git blame'' suggests that the change in behavior was introduced over a year ago
The translation from ''MSG_INFO'' to ''LOG_NOTICE'' occurs in ''src/utils/wpa_debug.c''
static int syslog_priority(int level)
{
switch (level) {
case MSG_MSGDUMP:
case MSG_DEBUG:
return LOG_DEBUG;
case MSG_INFO:
return LOG_NOTICE;
case MSG_WARNING:
return LOG_WARNING;
case MSG_ERROR:
return LOG_ERR;
}
return LOG_INFO;
}
I disagree that the log messages are either "spam" or "unhelpful". In diagnosing a problem or resolving an incident, every log message can potentially be the one that provides the clue. Even in a busy environment, knowing what device had just failed to connect can make it much easier to determine which MAC to add, especially for devices that do not easily reveal their MAC to the user, or not at all (IoT devices, for example). I do agree that OpenWRT users who use the ring-buffer logging system should be able to control the level of messages logged more easily than they can now. Determining why the upstream code suggests that these messages are to be logged as "info" and they appear as "notice" may provide further clues to resolving what is essentially a //logging// problem, not a functional one. //Edit// There also appear to be changes in ''handle_probe_req()'' in commit 92eb00ae that add to the puzzle as to why these are being logged at the "notice" level:
The code path suggests that one should be seeing a log message from '' ieee802_11_allowed_address()'' at the info level, then one from ''handle_probe_req()'' at the debug level. |
arlit: **How much helpful would be an 802.11ad-behavior on non-802.11ad appliances? Is it really technically unsound (or undesirable) to purposely disable such behavior on non-802.11ad modes? Despite the 802.11ad usage scenario mentioned, this new behavior still remain unwarranted for all pre-802.11ad appliances in openwrt's table of hardware support. Perhaps openwrt firmware download stats could be used to make a rough estimate of the ratio of potentially affected users (eg 802.11ad/non-802.11ad ratio) PS: Hostapd version featured in build r6501-745d0e7f4b does still behave different |
jeffsf: The probe is not directed, it is not probing //your// AP, in particular, but sending out a broadcast to discover available APs and their capabilities. This is a core part of the 802.11 stack. See https://documentation.meraki.com/MR/WiFi_Basics_and_Best_Practices/802.11_Association_process_explained as an example
Yes, it is very undesirable to //permanently// disable logging, as previously discussed. This should be handled with either the OpenWRT logger, or by "fixing" the OpenWRT patches that modify the ''hostapd'' logging so that UCI configuration can limit logging for OpenWRT users that use ring-buffer logging. |
jeffsf: Next time you build, try incorporating the attached patch. It should remove the ''MSG_INFO'' / ''LOG_NOTICE'' message when responding to a probe request. It is untested. For a "proper" patch, it should be integrated with an appropriate UCI variable to enable/disable its logic dynamically (with a ''reload_config'') |
arlit: Thanks. The patch works as intended although I guessed is_probe_request was a typo and changed it to is_probe_req. The comment from Dedy Lansky gave me the impression that his commit was meant specifically for 802.11ac modes but it doesn't appear the reason behind the new logging behavior. I attempted a test build without most openwrt's hostapd patches (I included only nr. 100, 200, 300 and 600) but the excessive output remained. It looks likely that the new behavior was introduced in hostapd after 2017-08-24 and before 2018-03-26. Logging MAC rejections during 802.11 association phase would appear the only meaningful output for diagnostic of MAC-ACL operation. I'm not an expert so I still don't understand what would be the point of logging broadcast probes if (allow)-MAC-ACL is used. Since a wireless scanner on phones whose MAC is not ACL-allowed can detect the tested router SSID and encryption, it doesn't look like those probes are rejected. |
jeffsf: Glad that could get you going -- yes, I won't claim a typo, just a derp on my part. It may well be that the phone app is just picking up the beacon frames that are periodically broadcast by the AP. Knowing what stations are in range provide valuable information to the AP operator in a couple of ways. One is when one needs to reconfigure the AP to accept a "new" device. It's often much easier to see the device in the logs, than it is to try to wade through the device's secondary settings screens (especially with a device that the AP operator is not terribly familiar with), and may be nearly impossible with many embedded devices. As an example, there's no screen on an 802.11 light switch, and the MAC address is on a sticker, often buried in the back of the electrical box. Logging the events is also valuable when you believe that your AP should generally not be in range of "strange" devices, and want to know what unexpected devices might be in range. On a "normal" system, these kinds of log messages can be filtered out into their own log, and that log managed appropriately. Without installing a different logging package, OpenWRT does not directly support this kind of log segmentation, at least that I am aware of. The patch supplied (and modified, as you indicate) the rejection should still be logged at the debug level, which is a noop unless enabled in the configuration of the compile of ''hostap'' sources. As I recall, the config parameter is ''WPA_MSG_MIN_PRIORITY'' |
arlit: Thanks for the clarification. While still retaining the old ability to report which unknown-MAC actually attempted to associate, the new behavior is akin to a proximity surveillance feature that would allow to estimate how long each unknown MACs was in range of the router and it could be probably used to track unknown-MAC movements in a WDS multi-AP area. |
arlit: The new behavior was introduced by hostapd commit 92eb00ae just like you mentioned. |
silentcreek: I'd like to add my 2 cents here, since this issue is very annoying. I see two problems here:
For now, as a temporary workaround, I've patched my build to simply log this particular message on the debug level. This way, they don't show up in my logs. A Lastly, has anyone been in touch with upstream regarding this matter? |
m0urs: It should be fixed now in hostapd. So next time the code is pulled to OpenWrt it should be fixed here as well. See https://forum.openwrt.org/t/advice-needed-about-wifi-security/13188/85?u=m0urs |
jow-: Patches cherry picked in https://git.openwrt.org/3e633bb3709611d79965fab667e3239fd3bde151 |
anomeome:
hostapd [[https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=eba3b028e46dbfe54f1208e9edf47bb0c6f73ac8|commit eba3b02]] causes the log to be spammed if
option macfilter 'allow'
list maclist 'xx:xx:xx:xx:xx:xx'
is used in wireless config stanza
[[https://forum.lede-project.org/t/advice-needed-about-wifi-security/13188/1|forum discussion]]
The text was updated successfully, but these errors were encountered: