Skip to content

[mod_shell_stream] Pop/clip noise at end of shell_stream:// playback — FreeSWITCH console log text leaks into the audio pipe via exit-time flush of the inherited stdout buffer #3120

Open

Description

@asdf3309

Describe the bug
Playing audio through shell_stream:// produces a short pop/clip noise right at the end of the stream (sounds like a hard hangup). Playing the same content as a regular WAV file is clean. The noise is not caused by the stream content or by EOF handling — it is FreeSWITCH console log text that gets written into the audio pipe.

Environment
FreeSWITCH 1.10.12 (Docker, Debian-based image), console log enabled, freeswitch -c (stdout = non-tty pipe)
Code inspection of current master shows the same issue exists there (see Root cause)
PCMA (alaw) 8 kHz RTP to a softphone; module streams 24 kHz L16
Steps to reproduce
Add a dialplan extension:








Call the extension. Expected: 4 seconds of pure silence (2 s @ 8 kHz), clean end.
Actual: after the 96,000 bytes of zeros, additional data appears in the stream and is played as loud noise for tens of milliseconds.
Any shell_stream:// playback shows the same tail noise, including real TTS scripts.

Root cause
mod_shell_stream's child branch does:

close(context->fds[0]);
dup2(context->fds[1], STDOUT_FILENO);
switch_system(context->command, SWITCH_TRUE);
printf("EOF"); /* master; 1.10.12 omits this sentinel */
close(context->fds[1]);
exit(0);

The leak chain:

During a call, FreeSWITCH logs (e.g. sofia's hash(insert/...last_dial/...) notice) go through switch_log_printf → fprintf(runtime.console = stdout) into the block-buffered FILE stream*, not flushed immediately.
switch_fork() — the child process inherits a copy of that buffered data.
dup2(fds[1], STDOUT_FILENO) points the child's stdout at the audio pipe.
switch_system() → switch_system_fork() → grandchild runs system(dcmd) (this writes the actual audio); when the grandchild exit(0)s, stdio flushes the inherited stdout buffer — write(1) now hits the audio pipe, not the console.
The play_say pump reads those log bytes and plays them as audio → the tail pop.
Evidence (captured from the module's pipe reader)
On the pure-silence repro, after exactly 96,000 bytes of zeros the pipe read returned:

pipe read=1145 first=5d20736f6669612f last=0a1b5b6d

0x5d 0x20 'sofia/' = ] sofia/, tail \n\x1b[m = the ANSI color-reset sequence FreeSWITCH appends to console lines. Content dump:

] sofia/internal/1001@192.168.49.199 hash(insert/172.17.0.2-last_dial/1001/5557)

An earlier run (with debug logging enabled) showed the module's own SS thread: pipe read=... log lines leaking the same way (87% [WAR... prefix), confirming the mechanism: whatever is buffered in stdout at fork time leaks into the audio pipe when the grandchild exits.

RTP capture confirms the audible result: after the real content ends, a full-scale noise segment appears (e.g. 58 ms, peak ±30 k L16) until the stream stops.

Suggested fix
Two changes in mod_shell_stream.c (patch against master):

Flush the inherited stdio buffers in the child before dup2 (the real fix — nothing buffered, nothing to leak):
} else { /* child /
close(context->fds[0]);
fflush(stdout); /
discard inherited console-log residue BEFORE dup2 */
fflush(stderr);
dup2(context->fds[1], STDOUT_FILENO);
switch_system(context->command, SWITCH_TRUE);
printf("EOF");
close(context->fds[1]);
exit(0);
}

The flush must happen before dup2, otherwise the logs get flushed into the pipe.

(Optional but consistent with the file-interface contract) return SWITCH_STATUS_FALSE from shell_stream_file_read once the stream is exhausted (!context->running && *len == 0), so the play pump ends immediately instead of polling an empty buffer.
With fix 1 alone: silence stream = exactly 96,000 bytes, clean EOF, no noise. Verified by RTP analysis (tail peak = alaw silence code) and by listening.

Additional context
The stream "end" signal differs between versions: master writes a 3-byte "EOF" sentinel (rlen <= 3 → break); 1.10.12 has no sentinel (break on read()==0). Neither fixes the leak above.
Verified on 1.10.12 (patched locally, deployed to Docker container); master code was inspected (file attached the same logic; the leak path is unchanged).
Only tested with 24 kHz L16 → 8 kHz alaw playback, 1 channel.

Activity

  1. asdf3309 commented on Aug 12, 2026

    @asdf3309
    Author

    Related: PR #3104 (mod_shell_stream process lifecycle) — this issue is about a different failure mode of the same module.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions