Opened 6 years ago

Closed 6 years ago

#14270 closed bug (fixed)

Stuttering audio playback after updating to hrev52094

Reported by: khallebal Owned by: waddlesplash
Priority: normal Milestone: Unscheduled
Component: Drivers/Network/atheroswifi Version: R1/Development
Keywords: Cc:
Blocked By: Blocking:
Platform: x86

Description

After updating my system to hrev52094 the new atheroswifi driver does work but renders the audio playback slower and stuttering, to make sure that it's not something else causing this behaviour, i extracted the driver to an earlier hrev52084 and the result is the same, the syslog is fludded with kernel messages. See syslog below.

Attachments (3)

previous_syslog (262.3 KB ) - added by khallebal 6 years ago.
syslog (161.0 KB ) - added by khallebal 6 years ago.
syslog.2 (424.9 KB ) - added by khallebal 6 years ago.

Download all attachments as: .zip

Change History (15)

by khallebal, 6 years ago

Attachment: previous_syslog added

comment:1 by waddlesplash, 6 years ago

Please try again after hrev52098.

comment:2 by khallebal, 6 years ago

Stuttering reduced but not completely gone and frequent enough to be annoying, and spamming also continues.

KERN: [net/atheroswifi/0] ieee80211_newstate_cb: INIT -> SCAN arg 0
KERN: [net/atheroswifi/0] sta_newstate: INIT -> SCAN (0)
KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0xcdd18000<00:21:27:e8:f9:0c> refcnt 3
KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0xcdd18000<00:21:27:e8:f9:0c> refcnt 4
KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0xcdd18000<00:21:27:e8:f9:0c> refcnt 3
KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0xcdd18000<00:21:27:e8:f9:0c> refcnt 5
KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0xcdd18000<00:21:27:e8:f9:0c> refcnt 3

See also korli's ticket #14273 which might be related.

by khallebal, 6 years ago

Attachment: syslog added

comment:3 by waddlesplash, 6 years ago

Please try again after hrev52099.

comment:4 by khallebal, 6 years ago

With hrev52102 alots of different messages are spamming the log, it's hard to tell which ones are responsible for the stuttering audio.

KERN: [net/atheroswifi/0] set WME_AC_BE (chan) [acm 0 aifsn 3 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/atheroswifi/0] set WME_AC_BE (bss ) [acm 0 aifsn 3 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/atheroswifi/0] set WME_AC_BK (chan) [acm 0 aifsn 7 logcwmin 4 logcwmax 10 txop 0]
KERN: [net/atheroswifi/0] set WME_AC_BK (bss ) [acm 0 aifsn 7 logcwmin 4 logcwmax 10 txop 0]

KERN: /dev/net/atheroswifi/0: media change, media 0x8300ae quality 1000 speed 10000000
KERN: /dev/net/atheroswifi/0: media change, media 0x8300af quality 1000 speed 10000000
KERN: /dev/net/atheroswifi/0: media change, media 0x8300b0 quality 1000 speed 1000000000
KERN: /dev/net/atheroswifi/0: media change, media 0x8300b1 quality 1000 speed 10000000

KERN: acquire_advisory_lock(vnode = 0xd0413970, flock = 0x818f6efc, wait = no)
KERN: bfs: bfs_access:1525: Permission denied
KERN: acquire_advisory_lock(vnode = 0xd0413970, flock = 0x818f6efc, wait = no)
KERN: acquire_advisory_lock(vnode = 0xd4f2fb20, flock = 0xcce8fefc, wait = no)
KERN: acquire_advisory_lock(vnode = 0xd0413970, flock = 0x818f6efc, wait = no)
KERN: Last message repeated 3 times.

by khallebal, 6 years ago

Attachment: syslog.2 added

comment:5 by waddlesplash, 6 years ago

From the first boot, the media change messages seem to occur every 10-20 seconds. For the second boot, the media change messages occur even more infrequently; and the other spams occur every 4 seconds or so. Is either of those the interval you see stuttering at?

I'm not sure what the bfs_access message is caused by (some userland application periodically trying to access some location, and failing. I've seen Qt apps do this, and haven't taken the time to investigate yet.)

in reply to:  5 comment:6 by khallebal, 6 years ago

Replying to waddlesplash:

From the first boot, the media change messages seem to occur every 10-20 seconds. For the second boot, the media change messages occur even more infrequently; and the other spams occur every 4 seconds or so. Is either of those the interval you see stuttering at?

well, as i said in comment-2 the frequency has been reduced, so it's certainely not every 4 secs

I'm not sure what the bfs_access message is caused by (some userland application periodically trying to access some location, and failing. I've seen Qt apps do this, and haven't taken the time to investigate yet.)

As for the Qt apps i have several of them, but QMPay2 and Otter-browser are the ones i use extensively, one of those or both are responsible for that message.

comment:7 by waddlesplash, 6 years ago

OK. Can you please run this command in a Terminal:

tail -f /var/log/syslog

and then try to reproduce the stuttering. See which messages appear in the Terminal when the stuttering occurs.

comment:8 by khallebal, 6 years ago

The stuttering is caused by these messages

KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode on
KERN: [net/atheroswifi/0] ieee80211_sta_tim_notify: wake up from bgscan vap sleep
KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode off
KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode on
KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode off
KERN: ieee80211_notify_scan_done
KERN: wlan_control: 9235, 76

Hopefully these are the only ones

comment:9 by waddlesplash, 6 years ago

As far as I can tell, those messages are legitimate, and that probably means the earlier ones that occurred in-between before I disabled them

2869	KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode on
2870	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2871	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2872	KERN: bfs: bfs_access:1525: Permission denied
2873	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2874	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2875	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2876	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2877	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2878	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2879	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2880	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2881	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2882	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2883	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2884	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2885	KERN: bfs: bfs_access:1525: Permission denied
2886	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2887	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2888	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2889	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2890	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2891	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2892	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2893	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2894	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2895	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2896	KERN: bfs: bfs_access:1525: Permission denied
2897	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 4
2898	KERN: [net/atheroswifi/0] ieee80211_ref_node (ieee80211_send_probereq:2105) 0x818a0000<88:ce:fa:4d:a2:ca> refcnt 5
2899	KERN: [net/atheroswifi/0] [88:ce:fa:4d:a2:ca] sta power save mode off

are legitimate and indicative of some other problem.

Can you run ActivityMonitor and take a screenshot of CPU usage during the stuttering?

Also, it seems that this may be caused by your WiFi access point going into power-save mode. As a workaround, try disabling power-save mode in your router's settings and see if that helps.

comment:10 by waddlesplash, 6 years ago

Also, at this point, are you sure this isn't #12594 all over again?

Version 0, edited 6 years ago by waddlesplash (next)

in reply to:  9 comment:11 by khallebal, 6 years ago

Replying to waddlesplash:

As far as I can tell, those messages are legitimate, and that probably means the earlier ones that occurred in-between before I disabled them are legitimate and indicative of some other problem.

Can you run ActivityMonitor and take a screenshot of CPU usage during the stuttering?

Also, it seems that this may be caused by your WiFi access point going into power-save mode. As a workaround, try disabling power-save mode in your router's settings and see if that helps.

Well at least the first ones you silenced were very important, because they improved the playback a great deal. As for the symptoms in #12594 they somewhat differ, because the stuttering occurs when i am not connected to my wifi, while with the new driver it's the other way around. but they might be related. So, i suggest we close this ticket as fixed without further changes, i'll live with some stuttering every now and then until this issue is fixed for good in this #12594 ticket. Thanks so much for bearing with me Augustin.

comment:12 by waddlesplash, 6 years ago

Resolution: fixed
Status: newclosed

OK, thanks for the feedback!

Note: See TracTickets for help on using tickets.