Ticket #334 (closed Bugs: fixed)

Opened 8 months ago

Last modified 2 weeks ago

harbor source feeding aborts with exception Ogg_demuxer.Invalid_stream

Reported by: LwarX Owned by: admin
Priority: 1 Milestone:
Component: Liquidsoap Version: 0.9.2+svn
Keywords: Cc: that1swede@…
Mac OSX: no Linux: yes
NetBSD: no Other Operating System: no
FreeBSD: no

Description

Original report: http://savonet.rastageeks.org/ticket/309#comment:8

This time exception handling has been disabled and liquidsoap printed exception message to console, then stopped:

$ liquidsoap /etc/liquidsoap/main.liq
Thread 5 killed on uncaught exception Ogg_demuxer.Invalid_stream

/var/log/liquidsoap/main.log (partial):

2010/01/15 19:19:32 [src_4796:3] New metadata chunk "Serakina -- Liam's Visit"
2010/01/15 19:23:45 [src_4796:3] New metadata chunk "Greg Baumont -- Respire ! (The dervish)"
2010/01/15 19:28:48 [src_4796:3] New metadata chunk "sion -- goodbye and so long"
2010/01/15 19:31:50 [src_4796:2] Feeding stopped: Ogg_demuxer.Invalid_stream
2010/01/15 19:31:50 [threads:1] Thread "harbor source feeding" aborts with exception Ogg_demuxer.Invalid_stream!
2010/01/15 19:31:50 [main:3] Shutdown started!
2010/01/15 19:31:50 [main:3] Waiting for threads to terminate...
2010/01/15 19:31:50 [root:3] Shutting down sources...
2010/01/15 19:31:50 [main(dot)ogg:3] Closing connection...
2010/01/15 19:31:50 [threads:3] Thread "root" exited (0 remaining).
2010/01/15 19:31:50 [main:3] Cleaning downloaded files...
2010/01/15 19:31:50 >>> LOG END

Liquidsoap configuration with debug statements added:

#!/usr/bin/liquidsoap

set("log.file.path", "/var/log/liquidsoap/main.log")

set("harbor.bind_addr", "127.0.0.1")
set("harbor.port", 8006)
set("harbor.password", "password1")

output.icecast.vorbis(  host = "127.0.0.1",
                        port = 8008,
                        password = "password2",
                        mount = "main.ogg",
                        restart = true,
                        restart_delay = 3,
                        name = "main",
                        description = "main stream",
                        url = "http://hostname:8008/main.ogg",
                        add(    normalize = false,
                                [input.harbor("stream.ogg",
                                debug=true,
                                dumpfile="/tmp/stream.dump",
                                logfile="/tmp/buffer.log"),
                                blank()]))

This is partial configuration snippet for Music Player Daemon (MPD), which was used as streaming source:

audio_output {
        type            "shout"
        encoding        "ogg"                   # optional
        name            "main"
        host            "localhost"
        port            "8006"
        mount           "/stream.ogg"
        password        "password1"
        quality         "5.0"
        format          "44100:16:1"
}

Message from /var/log/mpd/mpd.log at the moment when harbor died:

Jan 15 19:31 : output: "main" [shout] failed to play: Lost shout connection to localhost:8006: Socket error

And this is the link to saved audio stream dump (152 MB):  http://rapidshare.com/files/335700695/stream.dump.html

Software versions installed:

dev-lang/ocaml-3.10.2
dev-ml/ocaml-alsa-0.1.4
dev-ml/ocaml-cry-0.1.1
dev-ml/ocaml-dtools-0.1.6
dev-ml/ocaml-duppy-0.3.1
dev-ml/ocaml-lame-0.2.4
dev-ml/ocaml-mad-0.3.6
dev-ml/ocaml-ogg-0.3.1
dev-ml/ocaml-shout-0.2.7
dev-ml/ocaml-vorbis-0.5.1
dev-ml/pcre-ocaml-6.0.1
media-sound/liquidsoap-0.9.2

Change History

Changed 5 months ago by sim

 decoration Changed 1 year ago by admin

 bathtub Changed 1 year ago by admin

 solar system Changed 1 year ago by admin

 stair parts Changed 1 year ago by admin

 solar supply Changed 1 year ago by admin

Changed 4 months ago by that1swede

  • cc that1swede@… added

Changed 4 months ago by that1swede

I am seeing the same issue here, from what I can tell it seems to always happen when the source is connecting (once connected it's fine until they disconnect intentionally).

This is running the latest SVN version (7299 at the time).

Below is the logged output with debugging enabled.

2010/05/04 20:09:59 [harbor:3] New client: pool-74-127-125-8.lsanca.dsl-w.verizon.net
2010/05/04 20:09:59 [harbor:4] Header: CONTENT-TYPE, value: application/ogg.
2010/05/04 20:09:59 [harbor:4] Header: ICE-NAME, value: testing.
2010/05/04 20:09:59 [harbor:4] Header: ICE-URL, value: http://www.oddsock.org.
2010/05/04 20:09:59 [harbor:4] Header: ICE-GENRE, value:  .
2010/05/04 20:09:59 [harbor:4] Header: ICE-BITRATE, value: 96.
2010/05/04 20:09:59 [harbor:4] Header: ICE-PRIVATE, value: 0.
2010/05/04 20:09:59 [harbor:4] Header: ICE-PUBLIC, value: 1.
2010/05/04 20:09:59 [harbor:4] Header: ICE-DESCRIPTION, value: testage.
2010/05/04 20:09:59 [harbor:4] Header: ICE-AUDIO-INFO, value: ice-samplerate=44100;ice-bitrate=96;ice-channels=2.
2010/05/04 20:09:59 [harbor:4] Client logged in.
2010/05/04 20:09:59 [harbor:3] SOURCE request on /.
2010/05/04 20:09:59 [decoder:4] Trying method "MP3/LIBMAD" for "application/ogg"...
2010/05/04 20:09:59 [decoder:4] Trying method "OGG" for "application/ogg"...
2010/05/04 20:09:59 [decoder:3] Method "OGG" accepted "application/ogg".
2010/05/04 20:09:59 [harbor:3] Adding source on mountpoint "/" with type "application/ogg".
2010/05/04 20:09:59 [clock:4] Currently 1 clocks allocated.
[New Thread 0xb39fcb70 (LWP 11767)]
2010/05/04 20:09:59 [threads:3] Created thread "harbor source feeding" (2 total).
2010/05/04 20:09:59 [src_6166:3] Decoding...
2010/05/04 20:09:59 [ogg.demuxer:5] Couldn't find a decoder for page in stream 213f
2010/05/04 20:09:59 [threads:1] Thread "harbor source feeding" aborts with exception Ogg_demuxer.Invalid_stream!
Thread 5 killed on uncaught exception Ogg_demuxer.Invalid_stream
Raised at file "ogg_demuxer.ml", line 120, characters 16-30
Called from file "ogg_demuxer.ml", line 146, characters 4-12
Called from file "decoder/ogg_decoder.ml", line 117, characters 6-27
Called from file "sources/harbor_input.ml", line 105, characters 34-53
Called from file "tools/tutils.ml", line 134, characters 15-18
Re-raised at file "tools/tutils.ml", line 157, characters 21-22
Called from file "thread.ml", line 38, characters 8-14
2010/05/04 20:09:59 [main:3] Shutdown started!
[Thread 0xb39fcb70 (LWP 11767) exited]
[Thread 0xb42f9b70 (LWP 11679) exited]
2010/05/04 20:09:59 [main:3] Waiting for threads to terminate...

Changed 4 months ago by toots

Hi !

Thanks for the new log. I am looking at the issue now. Would you have more logs about what hapenned before ? It seems that the ogg decoder is not properly reset or something similar...

Changed 4 months ago by toots

Hi all !

I believe those two bugs were related to different parts of the code.

I also believe both were trigered by an invalid stream, but at a different moment. The initial report mentioned a failure after some time. This should be fixed in SVN now.

The second report mentioned a failure at the initial connection. This is due to an invalid BOS (beginning of stream) as sent by the oddcast client. This is typically a bug that may not be caught with icecast because icecast does not decode the stream.

I do not think we should change the ogg decoder to fix this. We could for instance wait for a bos even if the first page is not a BOS but I see two problems with that:

  • There might be no BOS at all and liq would freeze..
  • The source client will never be fixed.

I do not know if it is an option for you to fix the source client, change it or report upstream but I believe this bug needs to be fixed there..

What will happen now is that the source client will get kicked and may reconnect with a valid stream...

Changed 4 months ago by metamorph68

  • status changed from new to closed
  • resolution set to fixed

(In [7301]) Catch any exception raised when creating a stream decoder. fixes #334

Changed 2 weeks ago by metamorph68

(In [7301]) Catch any exception raised when creating a stream decoder. fixes #334

Changed 2 weeks ago by metamorph68

(In [7301]) Catch any exception raised when creating a stream decoder. fixes #334

Note: See TracTickets for help on using tickets.