smooth_add bug #47

Closed
toots opened this Issue Mar 24, 2013 · 4 comments

Comments

Projects
None yet
4 participants
Owner

toots commented Mar 24, 2013

From the ML:

I'm experimenting with the "new" Version 1.1.0.
I found a problem in using smooth_add().

I have a time announcement mp3 every hour made by an external script.
This is added to the radio-stream this way:

clock = playlist("/music/time", id="news")
...
radio =
smooth_add(delay=0.9,p=0.3,normal=radio,special=switch([({30m00s},clock)]))
(radio is the Radio stream)

I use playlist() for the news mp3 to not confuse LS of the changing file.
/music/time contains only one file.

At the specified time i hear the announcement fade in and at the end
when it should fade back to radio, LS suddenly stopps streaming.
It stays at "End of the current overriding", and it disconnects from the
attached Icecast.
I can say the problem is at the end of the file since i tested with a
much "longer" file than only a time announcement.

LS Log:
2013/03/21 10:55:00 [news:3] Prepared "/music/news/test//news.mp3" (RID 3).
2013/03/21 10:55:00 [fallback_4881:3] Switch to switch_4880 with transition.
2013/03/21 10:55:00 [switch_4880:3] Switch to audio_to_stereo_4842.
2013/03/21 10:55:00 [amplify_4840:3] Overriding amplification: 0.648634.
2013/03/21 10:55:00 [decoder:3] Method "MAD" accepted
"/music/news/test//news.mp3".
2013/03/21 10:55:00 [smart_cross_4889:3] Analysis: -19.854205dB /
-20.468496dB (3.00s / 2.00s)
2013/03/21 10:55:00 [smart_crossfade:3] No transition: using default.
2013/03/21 10:55:07 [news:3] Finished with "/music/news/test//news.mp3".
2013/03/21 10:55:07 [amplify_4840:3] End of the current overriding.

Icecast log just mentions a "socket timeout"
[2013-03-21 10:55:37] WARN source/get_next_buffer Disconnecting source
due to socket timeout

The same code works flawlessly on the same machine with LS 1.0.1.
I have no clue what could have changed in 1.1.0 for this script not to
work anymore.

Owner

toots commented Mar 24, 2013

From @dbaelde:

The problem is caused by my most recent (but not so recent) commit on
src/operators/sequence.ml.

If you need a quick fix, change the #is_ready method from
method is_ready = head_ready || List.exists (fun s -> s#is_ready) sources
to
method is_ready = List.exists (fun s -> s#is_ready) sources

(At least, this fixes my current test.)

I won't commit a revert because I did this change for a reason.
However, I need some more time to recall what tests I was running at
the time, review my fix and understand if there's a small gap or a big
mistake. But in the meantime, it's very likely that you can safely
apply the change I proposed.

dbaelde was assigned Mar 24, 2013

Here is another test that fails under the latest 1.1.1 from cvs on ubuntu precise. At the first hit of the switch at 30 seconds past the current minute it plays the count down ("3,2,1!") and then does not resume playing music. The stream rdisconnect from Icecast, CPU goes at 100% and there is not significant trace in the log

I am attaching the test script and the log below:

----- cut here -----------
#!/usr/local/bin/liquidsoap

set("log.syslog",false)
set("log.file.path","/tmp/countdown-radio.log")
set("log.level",5)
set("log.stdout",true)
set("server.socket",false)
set("server.telnet",false)
set("init.daemon",false)
set("scheduler.log",true)
set("scheduler.event_queues",5)
set("scheduler.generic_queues",5)
set("scheduler.fast_queues",5)
set("scheduler.generic_queues",5)
set("scheduler.non_blocking_queues",5)

MYSTATION="Countdown test"
print(MYSTATION)

_1 = single("say:1!")
_2 = single("say:2!")
_3 = single("say:3!")

ac = audio_to_stereo(mksafe(playlist(id="ac",mode="random", reload=7200, "/MUSIC/AC")))

def countdown()
sequence(merge=true,[
_3,
_2,
_1,
])
end

timed_promotions =
switch([
({ 30s} , countdown()),
])

radio = ac
radio = smooth_add(delay=0.8,p=0.0,normal=radio,special=timed_promotions)

output.icecast( %aacplus(channels=2,bitrate=48), host = "127.0.0.1", port = 8000, password = "XXXX", mount = "countdown.aac", name="#{quote(MYSTATION)}",
genre="Various", url="http://10.1.1.101", description="Countdown Testing Radio", radio)

------- end cut --------

----- liquidsopa log file: cut here ------

2013/03/25 10:29:06 >>> LOG START
2013/03/25 10:29:05 [protocols.external:3] Found "/usr/bin/wget".
2013/03/25 10:29:06 [main:3] Liquidsoap 1.1.0+scm (git://github.com/savonet/liquidsoap.git@0f1401a:20130319:193440)
2013/03/25 10:29:06 [main:3] Using: graphics=[distributed with Ocaml] pcre=6.2.3 dtools=0.3.0 duppy=0.4.2 duppy.syntax=0.4.2 cry=0.2.2 mm=0.2.1 xmlplaylist=0.
1.3 lastfm=0.3.0 ogg=0.4.4 vorbis=0.6.1 speex=0.2.0 mad=0.4.4 flac=0.1.1 flac.ogg=0.1.1 dynlink=[distributed with Ocaml] lame=0.3.1 gstreamer=0.2.0 aacplus=0.
2.1 voaacenc=0.1.0 theora=0.3.0 schroedinger=0.1.0 gavl=0.1.5 bjack=0.1.4 alsa=0.2.1 ao=0.2.0 samplerate=0.1.2 taglib=0.3.0 magic=0.7.3 camomile=0.8.3 faad=0.
3.2 soundtouch=0.1.7 portaudio=0.2.0 pulseaudio=0.1.2 ladspa=0.1.4 dssi=0.1.1 camlimages=4.0.0 lo=0.1.0
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [main:2] DISCLAIMER: This version of Liquidsoap has been
2013/03/25 10:29:06 [main:2] compiled from a snapshot of the development code.
2013/03/25 10:29:06 [main:2] As such, it should not be used in production
2013/03/25 10:29:06 [main:2] unless you know what you are doing!
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [main:2] We are, however, very interested in any feedback
2013/03/25 10:29:06 [main:2] about our development code and committed to fix
2013/03/25 10:29:06 [main:2] issues as soon as possible.
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [main:2] If you are interested in collaborating to
2013/03/25 10:29:06 [main:2] the development of Liquidsoap, feel free to
2013/03/25 10:29:06 [main:2] drop us a mail at savonet-devl@lists.sf.net
2013/03/25 10:29:06 [main:2] or to join the #savonet IRC channel on Freenode.
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [main:2] Please send any bug report or feature request
2013/03/25 10:29:06 [main:2] at https://github.com/savonet/liquidsoap/issues.
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [main:2] We hope you enjoy this snapshot build of Liquidsoap!
2013/03/25 10:29:06 [main:2]
2013/03/25 10:29:06 [lang:2] WARNING: there is no configuration key named "log.syslog"!
2013/03/25 10:29:06 [lang:2] WARNING: there is no configuration key named "scheduler.event_queues"!
2013/03/25 10:29:06 [single:3] "say:1!" is static, resolving once for all...
2013/03/25 10:29:06 [protocols.say:3] Synthetizing "1!" to "/tmp/say78645b.wav"
2013/03/25 10:29:06 [decoder:4] Trying method "META" for "/tmp/say78645b.wav"...
2013/03/25 10:29:06 [decoder:4] Trying method "WAV" for "/tmp/say78645b.wav"...
2013/03/25 10:29:06 [decoder.wav:4] "/tmp/say78645b.wav" recognized as WAV file (s16le,16000Hz,2 channels).
2013/03/25 10:29:06 [decoder:3] Method "WAV" accepted "/tmp/say78645b.wav".
2013/03/25 10:29:06 [metadata.flac:4] Invalid MIME type for "/tmp/say78645b.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.flac:4] Invalid file extension for "/tmp/say78645b.wav"!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid MIME type for "/tmp/say78645b.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid file extension for "/tmp/say78645b.wav"!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid MIME type for "/tmp/say78645b.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid file extension for "/tmp/say78645b.wav"!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid MIME type for "/tmp/say78645b.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid file extension for "/tmp/say78645b.wav"!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid MIME type for "/tmp/say78645b.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid file extension for "/tmp/say78645b.wav"!
2013/03/25 10:29:06 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
2013/03/25 10:29:06 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
2013/03/25 10:29:06 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
2013/03/25 10:29:06 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
2013/03/25 10:29:06 [single:3] "say:2!" is static, resolving once for all...
2013/03/25 10:29:06 [protocols.say:3] Synthetizing "2!" to "/tmp/sayeef912.wav"
2013/03/25 10:29:06 [decoder:4] Trying method "META" for "/tmp/sayeef912.wav"...
2013/03/25 10:29:06 [decoder:4] Trying method "WAV" for "/tmp/sayeef912.wav"...
2013/03/25 10:29:06 [decoder.wav:4] "/tmp/sayeef912.wav" recognized as WAV file (s16le,16000Hz,2 channels).
2013/03/25 10:29:06 [decoder:3] Method "WAV" accepted "/tmp/sayeef912.wav".
2013/03/25 10:29:06 [metadata.flac:4] Invalid MIME type for "/tmp/sayeef912.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.flac:4] Invalid file extension for "/tmp/sayeef912.wav"!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid MIME type for "/tmp/sayeef912.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid file extension for "/tmp/sayeef912.wav"!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid MIME type for "/tmp/sayeef912.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid file extension for "/tmp/sayeef912.wav"!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid MIME type for "/tmp/sayeef912.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid file extension for "/tmp/sayeef912.wav"!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid MIME type for "/tmp/sayeef912.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid file extension for "/tmp/sayeef912.wav"!
2013/03/25 10:29:06 [single:3] "say:3!" is static, resolving once for all...
2013/03/25 10:29:06 [protocols.say:3] Synthetizing "3!" to "/tmp/saydfa376.wav"
2013/03/25 10:29:06 [decoder:4] Trying method "META" for "/tmp/saydfa376.wav"...
2013/03/25 10:29:06 [decoder:4] Trying method "WAV" for "/tmp/saydfa376.wav"...
2013/03/25 10:29:06 [decoder.wav:4] "/tmp/saydfa376.wav" recognized as WAV file (s16le,16000Hz,2 channels).
2013/03/25 10:29:06 [decoder:3] Method "WAV" accepted "/tmp/saydfa376.wav".
2013/03/25 10:29:06 [metadata.flac:4] Invalid MIME type for "/tmp/saydfa376.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.flac:4] Invalid file extension for "/tmp/saydfa376.wav"!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid MIME type for "/tmp/saydfa376.wav": audio/x-wav!
2013/03/25 10:29:06 [metadata.mp4:4] Invalid file extension for "/tmp/saydfa376.wav"!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid MIME type for "/tmp/saydfa376.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.ogg:4] Invalid file extension for "/tmp/saydfa376.wav"!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid MIME type for "/tmp/saydfa376.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.taglib:4] Invalid file extension for "/tmp/saydfa376.wav"!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid MIME type for "/tmp/saydfa376.wav": audio/x-wav!
2013/03/25 10:29:06 [decoder.gstreamer:4] Invalid file extension for "/tmp/saydfa376.wav"!
2013/03/25 10:29:06 [video.converter:4] Using preferred video converter: gavl.
2013/03/25 10:29:06 [audio.converter:4] Using preferred samplerate converter: libsamplerate.
2013/03/25 10:29:06 [threads:3] Created thread "generic queue #1".
2013/03/25 10:29:06 [threads:3] Created thread "generic queue #2".
2013/03/25 10:29:06 [threads:3] Created thread "generic queue #3".
2013/03/25 10:29:06 [threads:3] Created thread "generic queue #4".
2013/03/25 10:29:06 [threads:3] Created thread "generic queue #5".
2013/03/25 10:29:06 [threads:3] Created thread "fast queue #1".
2013/03/25 10:29:06 [threads:3] Created thread "fast queue #2".
2013/03/25 10:29:06 [fast queue #2:4] Queue #1 starting...
2013/03/25 10:29:06 [fast queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [generic queue #4:4] Queue #3 starting...
2013/03/25 10:29:06 [fast queue #1:4] Queue #4 starting...
2013/03/25 10:29:06 [generic queue #1:4] Queue #5 starting...
2013/03/25 10:29:06 [threads:3] Created thread "fast queue #3".
2013/03/25 10:29:06 [fast queue #3:4] Queue #6 starting...
2013/03/25 10:29:06 [generic queue #2:4] Queue #7 starting...
2013/03/25 10:29:06 [generic queue #5:4] Queue #2 starting...
2013/03/25 10:29:06 [generic queue #3:4] Queue #8 starting...
2013/03/25 10:29:06 [fast queue #2:4] Enter select at 1364203746.238934, timeout -1.000000 (2/0/0).
2013/03/25 10:29:06 [generic queue #4:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #1:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #4:4] Queue #9 starting...
2013/03/25 10:29:06 [generic queue #1:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #2:4] Left select at 1364203746.239726 (1/0/0).
2013/03/25 10:29:06 [threads:3] Created thread "fast queue #4".
2013/03/25 10:29:06 [fast queue #3:4] There are 0 ready tasks.
2013/03/25 10:29:06 [generic queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #5:4] Queue #10 starting...
2013/03/25 10:29:06 [threads:3] Created thread "fast queue #5".
2013/03/25 10:29:06 [generic queue #5:4] There are 0 ready tasks.
2013/03/25 10:29:06 [clock:4] Currently 1 clocks allocated.
2013/03/25 10:29:06 [generic queue #3:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #4:4] There are 0 ready tasks.
2013/03/25 10:29:06 [clock.wallclock_main:4] Starting 1 sources...
2013/03/25 10:29:06 [source:4] Source output.icecast_5941 gets up.
2013/03/25 10:29:06 [fast queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [source:4] Source fallback_5939 gets up.
2013/03/25 10:29:06 [source:4] Source switch_5936 gets up.
2013/03/25 10:29:06 [fast queue #5:4] There are 0 ready tasks.
2013/03/25 10:29:06 [fast queue #2:4] Enter select at 1364203746.240838, timeout -1.000000 (2/0/0).
2013/03/25 10:29:06 [source:4] Source sequence_5935 gets up.
2013/03/25 10:29:06 [source:4] Source single_5927 gets up.
2013/03/25 10:29:06 [single_5927:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:06 [single_5927:4] Activations changed: static=[sequence_5935:switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [source:4] Source single_5925 gets up.
2013/03/25 10:29:06 [single_5925:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:06 [single_5925:4] Activations changed: static=[sequence_5935:switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [source:4] Source single_5923 gets up.
2013/03/25 10:29:06 [single_5923:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:06 [single_5923:4] Activations changed: static=[sequence_5935:switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [sequence_5935:4] Activations changed: static=[], dynamic=[switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [switch_5936:4] Activations changed: static=[], dynamic=[fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [source:4] Source audio_to_stereo_5932 gets up.
2013/03/25 10:29:06 [audio_to_stereo_5932:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:06 [source:4] Source mksafe gets up.
2013/03/25 10:29:06 [source:4] Source ac gets up.
2013/03/25 10:29:06 [ac:3] Loading playlist...
2013/03/25 10:29:06 [ac:3] Playlist is a directory.
2013/03/25 10:29:06 [ac:3] Successfully loaded a playlist of 3589 tracks.
2013/03/25 10:29:06 [ac:4] Content kind is {audio=1+;video=0;midi=0}.
2013/03/25 10:29:06 [ac:4] Activations changed: static=[], dynamic=[mksafe:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [source:4] Source safe_blank gets up.
2013/03/25 10:29:06 [safe_blank:4] Content kind is {audio=1+;video=0;midi=0}.
2013/03/25 10:29:06 [safe_blank:4] Activations changed: static=[], dynamic=[mksafe:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [mksafe:4] Activations changed: static=[audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [fast queue #2:4] Left select at 1364203746.258437 (1/0/0).
2013/03/25 10:29:06 [fast queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [audio_to_stereo_5932:4] Activations changed: static=[], dynamic=[fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [fallback_5939:4] Activations changed: static=[countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [fast queue #2:4] Enter select at 1364203746.258636, timeout -1.000000 (3/0/0).
2013/03/25 10:29:06 [fast queue #2:4] Left select at 1364203746.258851 (1/0/0).
2013/03/25 10:29:06 [ac:5] Queue is empty!
2013/03/25 10:29:06 [ac:5] Failed to prepare track: no file.
2013/03/25 10:29:06 [fast queue #2:4] There are 1 ready tasks.
2013/03/25 10:29:06 [generic queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [generic queue #2:4] Enter select at 1364203746.259187, timeout -1.000000 (2/0/0).
2013/03/25 10:29:06 [countdown(dot)aac:4] Activations changed: static=[countdown(dot)aac], dynamic=[].
2013/03/25 10:29:06 [fast queue #3:4] There are 0 ready tasks.
2013/03/25 10:29:06 [countdown(dot)aac:4] Enabling caching mode: active source.

.......

2013/03/25 10:29:06 [ac:4] Remaining: 0.0s, queued: 0.0s, adding: 30.0s (RID 4)
2013/03/25 10:29:06 [fast queue #2:4] There are 1 ready tasks.
2013/03/25 10:29:06 [fast queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [generic queue #2:4] Left select at 1364203746.285961 (1/0/0).
2013/03/25 10:29:06 [generic queue #2:4] There are 0 ready tasks.
2013/03/25 10:29:06 [generic queue #2:4] Enter select at 1364203746.286055, timeout -1.000000 (3/0/0).
2013/03/25 10:29:06 [countdown(dot)aac:3] Connection setup was successful.
2013/03/25 10:29:06 [threads:3] Created thread "wallclock_main" (1 total).
2013/03/25 10:29:06 [clock:4] Main phase starts.
2013/03/25 10:29:06 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
2013/03/25 10:29:06 [fallback_5939:3] Switch to audio_to_stereo_5932.
2013/03/25 10:29:06 [audio_to_stereo_5932:4] Activations changed: static=[fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[fallback_5939:countdown
(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [mksafe:3] Switch to safe_blank.
2013/03/25 10:29:06 [safe_blank:4] Activations changed: static=[mksafe:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[mksaf
e:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [ac:4] Remaining: 0.0s, queued: 30.0s, taking: 30.0s
2013/03/25 10:29:06 [ac:3] Prepared "/disk3/irn_content/MUSIC/AC/Unknown album (04-05-2012 16-44-36)/03 Does Anybody Really Know What Time It Is-.mp3" (RID 4)
.
2013/03/25 10:29:06 [mksafe:3] Switch to ac with transition.
2013/03/25 10:29:06 [safe_blank:4] Activations changed: static=[], dynamic=[mksafe:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:06 [ac:4] Activations changed: static=[mksafe:audio_to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[mksafe:audio_
to_stereo_5932:fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [single_5927:3] Prepared "/tmp/saydfa376.wav" (RID 2).
2013/03/25 10:29:30 [fallback_5939:3] Switch to switch_5936 with transition.
2013/03/25 10:29:30 [audio_to_stereo_5932:4] Activations changed: static=[], dynamic=[fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [source:4] Source add_6006 gets up.
2013/03/25 10:29:30 [add_6006:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [source:4] Source amplify_6000 gets up.
2013/03/25 10:29:30 [amplify_6000:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [audio_to_stereo_5932:4] Activations changed: static=[amplify_6000:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[f
allback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [amplify_6000:4] Activations changed: static=[add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [source:4] Source amplify_6002 gets up.
2013/03/25 10:29:30 [amplify_6002:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [source:4] Source fade_out_6001 gets up.
2013/03/25 10:29:30 [fade_out_6001:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [audio_to_stereo_5932:4] Activations changed: static=[fade_out_6001:amplify_6002:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aa
c, amplify_6000:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [audio_to_stereo_5932:4] Enabling caching mode: two static activations.
2013/03/25 10:29:30 [fade_out_6001:4] Activations changed: static=[amplify_6002:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [amplify_6002:4] Activations changed: static=[add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [source:4] Source sequence_6005 gets up.
2013/03/25 10:29:30 [source:4] Source blank_6003 gets up.
2013/03/25 10:29:30 [blank_6003:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [blank_6003:4] Activations changed: static=[sequence_6005:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [source:4] Source amplify_6004 gets up.
2013/03/25 10:29:30 [amplify_6004:4] Content kind is {audio=2;video=0;midi=0}.
2013/03/25 10:29:30 [switch_5936:4] Activations changed: static=[amplify_6004:sequence_6005:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynam
ic=[fallback_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [amplify_6004:4] Activations changed: static=[sequence_6005:add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [sequence_6005:4] Activations changed: static=[add_6006:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [add_6006:4] Activations changed: static=[fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[].
2013/03/25 10:29:30 [blank_6003:4] Activations changed: static=[], dynamic=[].
2013/03/25 10:29:30 [source:4] Source blank_6003 gets down.
2013/03/25 10:29:30 [switch_5936:3] Switch to sequence_5935.
2013/03/25 10:29:30 [sequence_5935:4] Activations changed: static=[switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac], dynamic=[switch_5936:fallba
ck_5939:countdown(dot)aac:countdown(dot)aac].
2013/03/25 10:29:30 [decoder.wav:4] WAV header read (16000Hz, 16bits, 67208bytes), starting decoding...
2013/03/25 10:29:31 [decoder:4] Decoding "/tmp/saydfa376.wav" ended: Wav_decoder.End_of_stream.
2013/03/25 10:29:31 [single_5927:3] Finished with "/tmp/saydfa376.wav".
2013/03/25 10:29:31 [single_5927:4] Activations changed: static=[], dynamic=[].
2013/03/25 10:29:31 [source:4] Source single_5927 gets down.
2013/03/25 10:29:31 [single_5925:3] Prepared "/tmp/sayeef912.wav" (RID 1).
2013/03/25 10:29:31 [decoder.wav:4] WAV header read (16000Hz, 16bits, 64648bytes), starting decoding...
2013/03/25 10:29:32 [decoder:4] Decoding "/tmp/sayeef912.wav" ended: Wav_decoder.End_of_stream.
2013/03/25 10:29:32 [single_5925:3] Finished with "/tmp/sayeef912.wav".
2013/03/25 10:29:32 [single_5925:4] Activations changed: static=[], dynamic=[].
2013/03/25 10:29:32 [source:4] Source single_5925 gets down.
2013/03/25 10:29:32 [single_5923:3] Prepared "/tmp/say78645b.wav" (RID 0).
2013/03/25 10:29:32 [decoder.wav:4] WAV header read (16000Hz, 16bits, 64008bytes), starting decoding...
2013/03/25 10:29:33 [decoder:4] Decoding "/tmp/say78645b.wav" ended: Wav_decoder.End_of_stream.
2013/03/25 10:29:33 [single_5923:3] Finished with "/tmp/say78645b.wav".
2013/03/25 10:29:33 [sequence_5935:4] Activations changed: static=[], dynamic=[switch_5936:fallback_5939:countdown(dot)aac:countdown(dot)aac].

----- liquidsoap log file: end cut ----------

------ icecast error log file cut here ----------
[2013-03-25 10:29:49] WARN source/get_next_buffer Disconnecting source due to socket timeout
------ icecast log file end cut ----------

Owner

dbaelde commented Apr 26, 2013

For me, the bug is gone on the new master. The responsible line (although I can't explain it fully) is head_ready <- hd#is_ready from Samuel's latest modification on sequence.ml.

Please confirm so we can close. Otherwise I suggest reverting my previous change, ie. using head_ready in #is_ready.

Owner

smimram commented May 6, 2013

The user confirmed that the bug is gone on the ML. Feel free to reopen if it's not the case.

smimram closed this May 6, 2013

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