stream_server enters 100% cpu loop

[sim590]

I don't know exactly the circumstance in which it occurs yet and I will update as soon as I know.

If I recall correctly, every time it happened (quite a few times), I did stop streaming sound just a little moment before, i.e. if some music player was set to forward sound to the chromecast, I stopped the music (without moving the music player from chromecast sink to any other sink), then heard my fan at 100% CPU a few minutes later. I don't recall a particular pattern around the time it took for the bug to occur after stopping the stream. It may have taken an hour, other times it may have been quite quick.

[sim590]

I have noticed this log just now when it happenned:

Dec 26 08:21:20 haxorz pulseaudio-dlna[15600]: 12-26 08:21:20 pulseaudio_dlna.pulseaudio                     INFO     on_playback_stream_removed "/org/pulseaudio/core1/playback_stream143"
Dec 26 08:21:20 haxorz pulseaudio-dlna[15600]: 12-26 08:21:20 pulseaudio_dlna.pulseaudio                     INFO     on_new_playback_stream "/org/pulseaudio/core1/playback_stream146"
Dec 26 08:21:21 haxorz pulseaudio-dlna[15600]: 12-26 08:21:21 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink2
Dec 26 08:21:21 haxorz pulseaudio-dlna[15600]: 12-26 08:21:21 pulseaudio_dlna.pulseaudio                     INFO     _async_handle_sink_update /org/pulseaudio/core1/sink2 finished!
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: 12-26 08:21:24 pulseaudio_dlna.streamserver                   INFO     StreamServer GobjectMainLoopMixin.shutdown()
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: 12-26 08:21:24 pulseaudio_dlna.streamserver                   INFO     Unregistered stream "/dWRuPSJ1dWlkOmY4ZTZkM2FjOTI4Yzk5Nzg5NDY2MDYxMjczOWUyMzM0Iix0eXBlPSJicmlk
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: WARNING: libsndfile may ignore -r and perform fseek's on the input.
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Compile without libsndfile if this is a problem.
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Assuming raw pcm input file
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: LAME 3.100 64bits (http://lame.sf.net)
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Using polyphase lowpass filter, transition band: 18671 Hz - 19205 Hz
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Encoding <stdin> to <stdout>
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Encoding as 44.1 kHz j-stereo MPEG-1 Layer III (7.3x) 192 kbps qval=3
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Error writing mp3 output
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: write() failed: Broken pipe

NOTICE: I have issued a SIGINT to the process by reflex without thinking, so I guess you may ignore the following lines:

Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: Error writing mp3 output
Dec 26 08:21:24 haxorz pulseaudio-dlna[15600]: write() failed: Broken pipe

According to the log, the issue might be related to the LAME lib.

[stuaxo]

At a guess: Maybe this happens when there is a glitch in the connection, (or when the connection becomes otherwise saturated), maybe see if you can induce it by breaking the connection deliberately, or downloading saturating the connection.

[sim590]

If I recall correctly, every time it happened (quite a few times), I did stop streaming sound just a little moment before, i.e. if some music player was set to forward sound to the chromecast, I stopped the music (without moving the music player from chromecast sink to any other sink), then heard my fan at 100% CPU a few minutes later. I don't recall a particular pattern around the time it took for the bug to occur after stopping the stream. It may have taken an hour, other times it may have been quite quick.

I don't recall experiencing the issue in the same manner in the recent past.

At a guess: Maybe this happens when there is a glitch in the connection, (or when the connection becomes otherwise saturated), maybe see if you can induce it by breaking the connection deliberately, or downloading saturating the connection.

Indeed, I think you are right. I have noticed that the CPU usage goes up to 100% when I disconnect my Thinkpad from its working station and that the Ethernet interface is not properly unconfigured (for some reason). Therefore, stream_server seems to try to write on the Ethernet interface in a loop, but obviously fails and tries again, hence the CPU 100% usage from what I can understand. Even though the bug would occur based on an event that should not happen, I think that the program should be prepared to slow down if it can't write properly on his socket.

What do you think?