Ticket #152 (reopened Bugs)

Opened 21 months ago

Last modified 3 months ago

Blank with smart_crossfade

Reported by: karye Owned by: toots
Priority: 1 Milestone: NEAR FUTURE
Component: Liquidsoap Version: 0.3.7+svn
Keywords: Cc: paulvt
Mac OSX: yes Linux: yes
NetBSD: yes Other Operating System: yes
FreeBSD: yes

Description

Testing the new release 0.3.7 I can hear a clear blank between songs with script:

radio = playlist(mode = "normal", "/home/radioclave2/playlists/test_crossfade.m3u")
radio = smart_crossfade(start_next = 15., fade_out = 15., fade_in = 15., radio)
radio = mksafe(radio)
radio = normalize(radio)

Though the transitions are ok with earlier code from subversion installed as of 20080205.

New installation from 20080603:

[ebuild     U ] dev-lang/ocaml-3.10.2 [3.09.3-r1] USE="ocamlopt%* -X -emacs% -gdbm -latex -ncurses -tk -xemacs%" 2,232 kB
[ebuild   R   ] media-libs/libogg-1.1.3  0 kB
[ebuild     U ] dev-ml/findlib-1.2.1 [1.0.4-r1] USE="ocamlopt%* -doc% -tk" 155 kB
[ebuild   R   ] media-libs/libvorbis-1.2.0  USE="-doc" 0 kB
[ebuild   R   ] media-libs/libao-0.8.8  USE="-alsa -arts -doc -esd -mmap -nas -pulseaudio" 0 kB
[ebuild   R   ] dev-libs/libpcre-7.6-r1  USE="cxx unicode zlib -bzip2 -doc" 0 kB
[ebuild   R   ] media-libs/taglib-1.4-r1  USE="-debug" 0 kB
[ebuild   R   ] dev-ml/ocaml-ogg-0.2.0  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/pcre-ocaml-5.08.1  0 kB
[ebuild   R   ] dev-ml/ocaml-dtools-0.1.6  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-ao-0.1.9  USE="-doc" 0 kB [1]
[ebuild   R   ] media-libs/libshout-2.1  0 kB
[ebuild   R   ] dev-ml/camomile-0.7.1  USE="ocamlopt -debug" 0 kB
[ebuild   R   ] dev-ml/ocaml-taglib-0.1.2  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-vorbis-0.4.1  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-shout-0.2.6  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-duppy-0.1.1  USE="-doc" 0 kB [1]
[ebuild   R   ] media-sound/lame-3.97-r1  USE="-debug -mp3rtp" 0 kB
[ebuild   R   ] media-libs/faac-1.26-r1  0 kB
[ebuild     U ] media-libs/faad2-2.6.1-r1 [2.6.1] USE="-drm" 0 kB
[ebuild   R   ] media-libs/libmad-0.15.1b-r2  USE="debug" 0 kB
[ebuild   R   ] dev-ml/ocaml-lame-0.2.2  USE="-doc" 0 kB [1]
[ebuild   R   ] sys-apps/man-1.6f-r1  USE="nls" 0 kB
[ebuild   R   ] dev-ml/ocaml-faac-0.1.1  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-faad-0.1.1  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/ocaml-mad-0.3.4  USE="-doc" 0 kB [1]
[ebuild   R   ] media-sound/liquidsoap-0.3.7  USE="aac ao lame mp3 taglib unicode wget -alsa -doc -nativecode -rtp -speech" 0 kB [1]

Old installation from 20080205:

[ebuild   R   ] media-libs/libogg-1.1.3  0 kB
[ebuild   R   ] media-libs/libvorbis-1.2.0  USE="-doc" 0 kB
[ebuild   R   ] media-libs/libpng-1.2.26-r1  0 kB
[ebuild   R   ] sys-kernel/linux-headers-2.6.23-r3  0 kB
[ebuild     U ] dev-libs/mpfr-2.3.1 [2.2.1_p5] 869 kB
[ebuild   R   ] media-libs/libao-0.8.8  USE="-alsa -arts -doc -esd -mmap -nas -pulseaudio" 0 kB
[ebuild   R   ] media-libs/taglib-1.4-r1  USE="-debug" 0 kB
[ebuild   R   ] media-libs/faac-1.26-r1  0 kB
[ebuild   R   ] media-libs/faad2-2.6.1-r1  USE="-drm" 0 kB
[ebuild   R   ] media-libs/libmad-0.15.1b-r2  USE="-debug" 0 kB
[ebuild   R   ] media-libs/libshout-2.2.2  USE="-speex -theora" 0 kB
[ebuild     U ] dev-lang/ocaml-3.10.2 [3.09.3-r1] USE="gdbm ncurses ocamlopt%* -X -emacs% -latex -tk -xemacs%" 2,232 kB
[ebuild     U ] dev-ml/findlib-1.2.1 [1.0.4-r1] USE="ocamlopt%* -doc% -tk" 155 kB
[ebuild   R   ] dev-ml/pcre-ocaml-5.08.1  0 kB
[ebuild  N    ] dev-ml/ocaml-ogg-0.1.1  USE="-doc" 0 kB [1]
[ebuild   R   ] dev-ml/camomile-0.7.1  USE="ocamlopt -debug" 0 kB
[ebuild   R   ] media-sound/lame-3.97-r1  USE="-debug -mp3rtp" 0 kB
[ebuild   R   ] dev-ml/ocaml-duppy-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-ao-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-dtools-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-ogg-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-faac-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-lame-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-faad-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-vorbis-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-taglib-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-mad-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] dev-ml/ocaml-shout-svn-1  USE="-doc" 0 kB [2]
[ebuild   R   ] media-sound/liquidsoap-svn-1  USE="aac ao lame mp3 taglib unicode wget -alsa -doc -nativecode -rtp -soundtouch -speech" 0 kB [2]

Attached log from both new and old installation.

Attachments

test_crossfade_new.log (8.3 kB) - added by karye 21 months ago.
test_crossfade_old.log (16.7 kB) - added by karye 21 months ago.
enhance_smart_crossfade.patch (3.0 kB) - added by toots 21 months ago.
Proposed enhancements..

Change History

Changed 21 months ago by karye

Changed 21 months ago by karye

  Changed 21 months ago by toots

  • owner changed from admin to toots
  • status changed from new to assigned

Hi Karye !

I've been playing with smart_crossfade yesterday, and couldn't reproduce your issue.

However, I'm wondering if there could some misunderstanding on the use of smart_crossfade. Indeed, in some cases, the transition that is selected is a sequence, hence if the songs end or begin with some silence you will hear it.

I've tweaked a bit the function in order to add some flexibility to it, please find a patch attached. The changes are:

  • Parametrize default transition when no rules apply, default: cross without fade
  • Parametrize medium, high and margin values, raised medium to -15.
  • Add more logs to understand how the transition is selected

Please, tell me if this helps you.

Changed 21 months ago by toots

Proposed enhancements..

  Changed 21 months ago by toots

  • version set to 0.3.7+svn
  • milestone 0.3.7 deleted

  Changed 16 months ago by paulvt

I experience a short silence (a hicup) just before the transition (so still in the old track), thus when liq is preparing. Maybe this is what he means. My liq is using 20% CPU and the machine is not doing anything else.

I use the current 0.3.8.1+svn20081108-1 version, by the way.

  Changed 16 months ago by toots

Indeed, I sometimes notice this sort of blanks when using a local output to the soundcard. However, in the case of streaming, I do not notice them.

Is it the same for you ?

  Changed 16 months ago by paulvt

No, I have it with icecast streaming. I always get the "We must catch up..." message.

  Changed 16 months ago by toots

Ok.

I believe there is a load issue with smart crossfade, since we have a similar load issue with another user, which may likely be related to this.

Does the "conservative=true" option changes this behaviour ? Also, what is the underlying file system ?

I didn't notice this on radiopi, where we use intensively the smart crossfade, though..

  Changed 16 months ago by paulvt

I am using conservative=true and I am using ext3.

  Changed 16 months ago by toots

So, does it change with convervative=false (default on radiopi) ?

I say that because the blank should obviously be generated by the buffering of end/beginning of tracks. Conservative changes this behaviour for the end of track: if true, then buffering is done at the beginning of the track, and only hwne the end has been detected if false.

  Changed 16 months ago by paulvt

Also with conservative=false. I always get a

2008/11/12 20:56:56 [root:2] We must catchup 1.91 seconds!

log entry.

  Changed 16 months ago by ~ok|

I believe I'm the other user who encountered this problem with track transition. And, as of a matter of fact, I still currently face the issue. Toggling the 'conservative' attribute on and off doesn't appear to matter. I was able to reduce this number of "blanks" occuring per day streamlining and optimizing the environment around the running Liquidsoap instance but never to totally remove them. P.S. the tracks are located on a local FFS (Berkeley's Fast File System) SATA-2 RAID disk. I've also tried to load the files on a distant UFS (Sun's UNIX File System) partition via NFS but it didn't make any difference regarding this issue.

  Changed 16 months ago by toots

Yes, this seems to happen sometimes. We don't know yet if this is "normal", in the sens that this is a strict consequence of how crossfading works, or if this can be made better inside liquidsoap. In particular, it works very fine on radiopi with almost 9 encoders in the same local host.

Another possibility to work around this seems to raise the buffer between liquidsoap and icecast. There does not seem to be any special parameter for that in either shout or icecast, but you can try to add some latency to your streams. Something like:

s = lag(5.,s)

Added *just before* you output s to icecast. This will add 5 sec of latency to your output, though.

Please let us known if this helps so we can update the documentation. The lag operator is still a bit experimental, so don't go too fast from tests to production, though :)

  Changed 16 months ago by toots

  • milestone set to 0.9.0

  Changed 16 months ago by toots

I forgot another remark.

We've been told that this issue appeared for some users when upgrading from a previous version. It would be *very* usefull to know what version showed the issue first.

If you are able to install the daily packages, there are a versions of liquidsoap there that are up to 0.3.5. You can find the list by going there:

ftp://savonet.rastageeks.org/

You can install an old package by doing:

apt-get install liquidsoap=VERSION

Also, if you can compile from SVN, the tags/ directory contains all previous releases, though this is less precise than the above method.

  Changed 16 months ago by ~ok|

hello, I've re-tried with a SVN from the 0.35 branch I thought worked O.K. but using the faulty script it is still a no-go situation (I don't have the original script that worked along with this version of liquidsoap anymore.)

  Changed 16 months ago by mrpingouin

This bug might be related to #204 which I'm on a good way to fix. I'll test if it helps here. However, the way I understand bug #204 it should not happen before rev5652 ,i.e., May 2008, release 0.3.7... so it's unclear.

By the way, I would normalize right after the playlist, not after the crossfade. But that shouldn't affect the blank that you hear. Also, mksafe is playing blank when the source becomes unavailable, which creates a doubt: do you hear blank produced by smartcross (or even playlist) or do you hear the unavailability. You can play a sine during the unavailability to find out.

  Changed 16 months ago by mrpingouin

In fact it's r5900 from Sept 2008, even more recent -- sorry, I thought the hg revision number corresponded to the original svn revision.

  Changed 16 months ago by ~ok|

thanks for the explanation. Reagarding your comment, I now don't know if my tests were relevant and perhaps my problem is not related afterall, I'm quite confused. Anyway, I figured out how to get around this and liquidsoap is now rock-solid as ever (my problem was likely the result of a scripting issue http://www.mail-archive.com/savonet-users@lists.sourceforge.net/msg00683.html ). Maybe it would be wise not to give you wrong directions till I can provide an accurate and descriptive bug report and clear up a bit the situation on my end (and since it appears we're only two who encountered this sort of glitch it shouldn't be on your high priority list IMHO).

  Changed 16 months ago by toots

  • status changed from assigned to closed
  • resolution set to worksforme

Apparently it works :)

  Changed 15 months ago by paulvt

What changed? I hear no difference, I still have the pre-transition skips. Unless I increase the buffer on every client.

  Changed 15 months ago by toots

Hi paulvt !

Apparently from the different feedbacks that we had, this is more a configuration issue than a bug in the software.

Two other users experiencing the same issue reported that it went away by tweaking the server's configuration.

I believe this could be the same in your case. For instance the fact that increasing the buffer on the clients fixes the issue indicates that the problem comes from the fact that your liquidsoap fails to compute the transitions at real time, hence the need to buffer.

So what you can do is try to increase the priority of your running liquidsoap, or possibly use the lag operator (just before the output), which will add a buffer into liquidsoap itself between the smart crossfade and your clients.

We'll be very interested in knowing wether adding a lag can help fixing the issue..

follow-up: ↓ 25   Changed 15 months ago by paulvt

Besides the lag, I'm not sure what to fix in my script. AFAIK I have applied changes suggested in the mail linked above by ~ok|. IIRC I have tried to add the lag() just before the output, but that seems to kill the ability to do request things?

  Changed 15 months ago by mrpingouin

Hmmm, this bug is elusive...

It seems that ~ok| doesn't experience the bug anymore. I don't know about karye, but paulvt still has a problem. I doubt everybody is having the same problem. I'm OK to re-open the ticket, but then please confirm that you hear something wrong with the script initially posted by karye, with the SVN version.

Paulvt: Your comment makes me wonder, which buffer are you talking about? Is there any chance that you're trying to do crossing over an input.harbor/http? Because, lag() or not, this is conceptually impossible.

Hope we'll square it,

David

  Changed 15 months ago by toots

  • status changed from closed to reopened
  • resolution worksforme deleted

Ok, reopening.

  Changed 15 months ago by karye

I switched to a simple crossfade() when the skips didn't go away. Haven't tried any fixes or patch though. I had no time to debug this.

/Karim

in reply to: ↑ 21   Changed 15 months ago by toots

Replying to paulvt:

Besides the lag, I'm not sure what to fix in my script. AFAIK I have applied changes suggested in the mail linked above by ~ok|. IIRC I have tried to add the lag() just before the output, but that seems to kill the ability to do request things?

The only limitation was the ability to skip. I've just removed it, but the skip will be effective after the specified delay.

  Changed 15 months ago by toots

Hi all !

I've always been dubitative about this issue because we are using it on radiopi. However, I just realized that we override the default transition.

Instead, we use an add that way:

smart_crossfade(default=(fun (a,b) -> add(normalize=false,[b,a])))

Could you check if the issue still happen when using this default transition ?

  Changed 15 months ago by paulvt

It does. I saw an occurrence of the hicup when smart_crossfade reported the transition: crossed, no fade. I'm trying to find out now, if there is a certain transition type that goes wrong.

  Changed 15 months ago by ~ok|

hello, I can confirm that liquidsoap now flawlessly works tweaking the order of the operators in the radio script. However I highly doubt our issues were related in the end. My mistake for posting in this specific bug report at first place.

  Changed 15 months ago by mrpingouin

I ran some tests with the following script, which is a simplification of paulvt's luon-radio.liq. Please read the comments in the script.

def crossfade(a,b)
  add(normalize=false,
      [ sequence([ blank(duration=2.),
                   fade.initial(duration=4.,b) ]),
        fade.final(duration=4.,a) ])
end

smart_crossfade = smart_crossfade(conservative=true,
                                  width=4., medium=-25., default=crossfade)

tracks = playlist(id="tracks", "~/media/audio/jazz")

# Override the previous with two tracks between which
# there was a noticeable underrun.
tracks = sequence([
   single("/home/dbaelde/media/audio/jazz/Chili Sauce - Prima, Louis.mp3"),
   single("/home/dbaelde/media/audio/jazz/Herbie Hancock/\
           1976 - Herbie Hancock - Man Child/06 - Heartbeat.mp3")])

# Instead of the usual mksafe() I fill failures with a sine:
tracks = fallback(track_sensitive=false,[tracks,sine(440.)])

# replace tracks by skip_blank(tracks), you get more hicups
default = smart_crossfade(tracks)

# Let's avoid the ALSA complaints:
# ... Could not set buffer size to 'frame.size' (1764 samples), got 4704.
set("frame.size",4704)
# But we still get the underruns:
# ... Underrun! You may minimize them by increasing the buffer size.

# Save the stream to an ogg file. It takes some CPU power and creates more hicups,
# but allows you to check if the stream itself is corrupted.
# Passing bufferize=true to ALSA also doesn't change much.
output.file.vorbis("~/tmp/out.ogg",output.alsa(bufferize=false,default))

I do hear some hicups, sometimes a bit before the transition, sometimes a bit after: they correspond to ALSA underruns. I don't hear any sine, except at the beginning if tracks is a playlist, not overridden by the two-file sequence -- this is normal, since a playlist takes a little time to load. This means that the stream is correct, it is only late. You can check it by listening to the out.ogg file.

Paulvt, can you confirm these observations on that simple script?

My conclusion is that the bug is not directly related to smart_crossfade. It is only a problem of too much load at some points, causing a bad realtime behavior. It would not happen with an icecast output, because it is significantly buffered. The high load is caused by operators such as smart_crossfade, but also skip_blank, normalize, etc, which analyze the stream.

In a sense, this ticket can be seen as a feature request: "avoid load peaks which kill real-time listening". I don't see it as critical since the main purpose of liquidsoap is still icecast outputs. But I am disturbed by these load peaks, since I don't understand their origin.

Paulvt, is realtime (alsa/ao/..) output your primary goal with liquidsoap, or do you only use it for testing purposes?

  Changed 15 months ago by paulvt

I don't use alsa/ao at all, I use the icecast output. And while it may be buffered, the hicups case a significant gap such that this translatens to clients being without audio stream data for a short bit. I cannot confirm your observations just yet, on the machine in question there is no useful ao/alsa output. However, if this is load peaks related, indeed lag() could solve it (were it not that it is wreaking havoc in the request/metadata department) to buffer withing liquidsoap and this could solve it for now.

  Changed 15 months ago by mrpingouin

Hi and thank you for the extra information. I still wasn't sure that you were using an icecast output. This is a real concern then. Also, you should install in your script the equivalent of my

# Instead of the usual mksafe() I fill failures with a sine:
tracks = fallback(track_sensitive=false,[tracks,sine(440.)])

that way you would be sure that your clients are really without data (you won't hear anything, maybe you'll disconnect) or if they are with blank (which will then be replaced by the sine).

I don't see the lag() as a solution. First, as you notice it is not fully satisfying in itself. More importantly, if it's a peak issue, the buffering of icecast should be enough: adding a second buffer in lag is useless and complicated, you can more simply increase the icecast buffer. But frankly, if you hear a problem through an icecast stream, it's not a mere buffering issue and we should fine out.

Please keep us informed about the sine() trick. Maybe you could record the stream so we can all hear the problem? It might help us to make a diagnostic.

  Changed 14 months ago by toots

  • cc paulvt added

Hi all !

We noticed with the lag operator that the buffered data in liquidsoap consume a lot of memory.

When preparing a transition, liquidsoap buffers data, and I am now wondering wether this buffering could cause latency with the Gc because it consumes a lot of memory.

It would be very nice if someone which experience this issue could test the patch proposed in ticket #225 (http://savonet.rastageeks.org/attachment/ticket/225/implicit_s16le_conversion.patch) and tell us if the bug still occurs with it.

  Changed 14 months ago by toots

The patch have just been comited. However, I now have little faith that it changes anything for this issue.

It would be nice if the reporter or another user experiencing this issue could test with the latest code.

In case we dont have news of this issue, I should close it...

  Changed 14 months ago by paulvt

Ok, I have updated the software and will listen carefully the following few days (the problem doesn't occur that often to detect it immediately). I haven't had any time to do the sine() trick, I will try it if I hear some gaps and will let you know.

  Changed 14 months ago by paulvt

Hi. I am afraid that I still have the stuttering or pauses in the tracks pre-crossfade, and also do not hear the sine() that I added. When I put more load on the machine the pauses get more frequent and are also longer. So it purely seems to be a load issue.

  Changed 14 months ago by toots

Ok, thanks for the report. The fact that you don't hear the sine seems to indicate that the problem is indeed related to the load.

I think you didn't mention yet it: what architecture are you using ?

We already know that there is a load peek when liquidsoap prepares a new track. We still don't know how to optimize this..

  Changed 14 months ago by mrpingouin

No, it's the other way around. If installed as I described, the sine() is played when the playlist becomes unavailable. So the load does not seem to be responsible of an emptying of the playlist's queue of ready files.

Did you try/succeed at reproducing the problem not in production but on a simple test script such as the one that I shown? I guess it's tricky if it's load-related. Also, try to note between which files it occurs and only use those files in your test.

A tip to listen at a stream and store a backup of what you're hearing:

liquidsoap  'out(output.file.vorbis("dolebrai.ogg",fallback(track_sensitive=false,[input.http("http://dolebrai.net:8000/dolebrai.ogg"),sine(220.)])))'

(In fact, what is stored is better than what you hear: for me, the ALSA output has clicks if the machine is loaded, but the vorbis file is clean.)

  Changed 13 months ago by toots

  • milestone changed from 0.9.0 to NEAR FUTURE

As discussed, this bug is not grave and since we don't know much about it, it will be handled after the 0.9.0 release..

  Changed 7 months ago by paulvt

After struggling with this for quite a few months, I am solely convinved it is a load issues. When running liquidsoap with nice level -2 it is quite ok, the skips happen sometimes. However, I see no workaround other than moving it to a faster machine (although 1GHz should generally be enough).

So, is it really a bug?

  Changed 5 months ago by toots

Hi !

Anything new with this issue ?

I believe it should be checked against a recent SVN, in particular if the issue hapenned with ogg files.

  Changed 5 months ago by paulvt

I can check it against recent SVN. But it happened with all files, not just ogg ones.

  Changed 5 months ago by mrpingouin

Note that there are other know causes for this type of problem: (1) heavy load, preventing a timely preparation of the next file (2) inaccurate estimation of the remaining time, which can be avoided by setting conservative=true.

It would be great if you could reproduce your problem in a simple example, if possible on a single file that you would send us. As shown with the ogg example, we can fix things quickly when we can reproduce them.

Note: See TracTickets for help on using tickets.