liquidsoap crashes on wrong data sent to input.harbor

[romeodeepmind]

Hi, Savonet Team!

I'm experiencing such kind of problem:

when some client connects to input.harbor with wrong stream format (or maybe it wrong protocol format?) liuidsoap crashes after some attempts to start live.

one abnormal thing here. at the end of log note that harbor return 401 on mount point request. it seems that harbor forgets about this mount.

2009/09/24 08:31:40 [harbor:3] Adding source on mountpoint '/live.ogg' with type 'application/ogg'.
2009/09/24 08:31:40 [harbor:3] Returned 401 for '/live.ogg'.
2009/09/24 08:31:40 [threads:1] Thread "non-blocking queue #1" aborts with exception Unix.Unix_error(31, "write", "")!
2009/09/24 08:31:40 [main:3] Shutdown started!

this is my config:

#!/usr/bin/liquidsoap

%include "/home/vko/misc/settings.liq"

set("server.telnet",true)
set("server.telnet.port",8091)

set("harbor.bind_addr","0.0.0.0")
set("harbor.port",8090)
set("harbor.password", playlistPasswd)

system("/home/vko/misc/live.sh")

################### [Callbacks] ###################

def liveStart(headers)
    log("[LIVE-START]: live source goes up! Switching from playlist...")
    system("/home/vko/misc/live.sh " ^ 
	    quote(headers["ice-name"]) ^ " " ^ 
	    quote(headers["ice-description"]) ^ " " ^
	    quote(headers["ice-genre"]) ^ " " ^
	    quote(headers["ice-url"]) ^ " " ^
	    quote(headers["ice-bitrate"]) ^ " " ^
	    quote(headers["ice-audio-info"]) ^ " " ^
	    quote(headers["content-type"]) ^ " " ^
	    quote(headers["user-agent"]))
	    
    title = headers["ice-name"] ^ " | " ^
	    headers["ice-description"] ^ " | " ^ 
	    headers["ice-genre"]
	    
    log("Live-meta: " ^ title)
    
    ignore(server.execute("liveMeta.insert title=\"#{title}\""))
end

def liveEnd()
    log("[LIVE-END]: live source goes down! Switching to playlist...")
    system("/home/vko/misc/live.sh")
end

def playlistStart(headers)
    log("[PLAYLIST-START]: playlist source goes up! Switching from noise...")
end

def playlistEnd()
    log("[PLAYLIST-END]: playlist source goes down! Switching to noise...")
end

################### [Live Sources] ###################

#Live Sources
liveInput = input.harbor(	id="live", 
				"live.ogg", 
				buffer=2.,
				password=livePasswd,
				on_connect=liveStart,
				on_disconnect=liveEnd)
			    				
liveInput = insert_metadata(id="liveMeta", liveInput)
				
################### [Playlists] ###################
				
playlistInput = input.harbor(id="playlist", 
				"playlist.ogg", 
				buffer=10.,
				password=playlistPasswd,
				on_connect=playlistStart,
				on_disconnect=playlistEnd)
				
################### [Noise] ###################

noiseInput = noise(id="noise")
noiseInput = amplify(id="noiseAmp", 0.05, noiseInput)
noiseInput = rewrite_metadata([("title","no signal")], noiseInput)

################### [Master Input] ###################

#Master Input
input=fallback(			id="mainFallback", 
				track_sensitive=false, 
				[liveInput, playlistInput, noiseInput])

################### [Mount Points] ###################

output.icecast.vorbis(
    id="oVorbis",
    input,
    restart=true,
    password=omegaRelayPasswd,
    mount="rvk.ogg",
    name=streamTitle,
    genre=streamGenre,
    url=streamUrl,
    description=streamDescr,
    quality=4.
)

and this is what happens

2009/09/24 07:47:22 [harbor:3] New client: 89.179.203.185
2009/09/24 07:47:22 [harbor:4] Header: CONTENT-TYPE, value: application/ogg.
2009/09/24 07:47:22 [harbor:4] Header: ICE-NAME, value: Dj Armative Mixsession.
2009/09/24 07:47:22 [harbor:4] Header: ICE-URL, value: http://radiovkontakte.net.ru.
2009/09/24 07:47:22 [harbor:4] Header: ICE-GENRE, value: House.
2009/09/24 07:47:22 [harbor:4] Header: ICE-BITRATE, value: 192.
2009/09/24 07:47:22 [harbor:4] Header: ICE-PRIVATE, value: 0.
2009/09/24 07:47:22 [harbor:4] Header: ICE-PUBLIC, value: 1.
2009/09/24 07:47:22 [harbor:4] Header: ICE-DESCRIPTION, value: Live.
2009/09/24 07:47:22 [harbor:4] Header: ICE-AUDIO-INFO, value: ice-samplerate=44100;ice-bitrate=192;ice-channels=2.
2009/09/24 07:47:22 [harbor:4] Client logged in.
2009/09/24 07:47:22 [harbor:3] SOURCE request on /live.ogg.
2009/09/24 07:47:22 [harbor:3] Adding source on mountpoint '/live.ogg' with type 'application/ogg'.
2009/09/24 07:47:22 [lang:3] [LIVE-START]: live source goes up! Switching from playlist...
2009/09/24 07:47:22 [lang:3] Live-meta: Dj Armative Mixsession | Live | House
2009/09/24 07:47:22 [live:3] Decoding...
2009/09/24 07:47:22 [threads:3] Created thread "harbor source feeding" (3 total).
2009/09/24 07:47:22 [ogg.demuxer:5] Couldn't find a decoder for page in stream c5e
2009/09/24 07:47:22 [live:2] Feeding stopped: Ogg_demuxer.Invalid_stream
2009/09/24 07:47:22 [lang:3] [LIVE-END]: live source goes down! Switching to playlist...
2009/09/24 07:47:22 [threads:3] Thread "harbor source feeding" exited (2 remaining).
2009/09/24 07:47:40 [harbor:3] New client: 89.179.203.185
2009/09/24 07:47:40 [harbor:4] Header: USER-AGENT, value: (Mozilla Compatible).
2009/09/24 07:47:40 [harbor:3] GET request on /admin/metadata.
2009/09/24 07:47:40 [harbor:4] GET Arg: mount, value: /live.ogg.
2009/09/24 07:47:40 [harbor:4] GET Arg: mode, value: updinfo.
2009/09/24 07:47:40 [harbor:4] GET Arg: pass, value: 56rvk75.
2009/09/24 07:47:40 [harbor:3] Request to update metadata for mount /live.ogg
2009/09/24 07:47:40 [harbor:4] Client logged in.
2009/09/24 07:47:40 [harbor:3] Returned 401 for '/admin/metadata?pass=56rvk75&mode=updinfo&mount=/live.ogg&song=': Source is not mp3.
2009/09/24 07:53:03 [ogg.demuxer:4] Reached last page of logical stream cf07d
2009/09/24 07:53:03 [ogg.demuxer:4] Found a ogg logical stream, serial: bd0f3
2009/09/24 07:53:03 [ogg.demuxer:4] Trying ogg/vorbis format
2009/09/24 07:53:03 [playlist:3] New metadata chunk "Bastian Harper -- Horny Night (Bastian Harper & Daniel Pele Club Mix)"
2009/09/24 07:53:12 [ogg.encoder:4] oVorbis: Setting end of track 858ad97.
2009/09/24 07:53:12 [ogg.encoder:4] oVorbis: Every ogg logical tracks have ended: setting end of stream.
2009/09/24 07:53:12 [ogg.encoder:4] oVorbis: Starting new sequentialized ogg stream.
2009/09/24 07:53:12 [ogg.encoder:4] oVorbis: Starting all streams
2009/09/24 07:59:09 [ogg.demuxer:4] Reached last page of logical stream bd0f3
2009/09/24 08:30:43 [ogg.demuxer:4] Found a ogg logical stream, serial: 17044
2009/09/24 08:30:43 [ogg.demuxer:4] Trying ogg/vorbis format
2009/09/24 08:30:43 [playlist:3] New metadata chunk "Gadjo -- It's Alright (Alex Gaudino Remix)"
2009/09/24 08:30:50 [ogg.encoder:4] oVorbis: Setting end of track 3a4f32b3.
2009/09/24 08:30:50 [ogg.encoder:4] oVorbis: Every ogg logical tracks have ended: setting end of stream.
2009/09/24 08:30:50 [ogg.encoder:4] oVorbis: Starting new sequentialized ogg stream.
2009/09/24 08:30:50 [ogg.encoder:4] oVorbis: Starting all streams
2009/09/24 08:31:40 [harbor:3] New client: 89.179.203.185
2009/09/24 08:31:40 [harbor:4] Header: CONTENT-TYPE, value: application/ogg.
2009/09/24 08:31:40 [harbor:4] Header: ICE-NAME, value: Dj Armative Mixsession.
2009/09/24 08:31:40 [harbor:4] Header: ICE-URL, value: http://radiovkontakte.net.ru.
2009/09/24 08:31:40 [harbor:4] Header: ICE-GENRE, value: House.
2009/09/24 08:31:40 [harbor:4] Header: ICE-BITRATE, value: 192.
2009/09/24 08:31:40 [harbor:4] Header: ICE-PRIVATE, value: 0.
2009/09/24 08:31:40 [harbor:4] Header: ICE-PUBLIC, value: 1.
2009/09/24 08:31:40 [harbor:4] Header: ICE-DESCRIPTION, value: Live.
2009/09/24 08:31:40 [harbor:4] Header: ICE-AUDIO-INFO, value: ice-samplerate=44100;ice-bitrate=192;ice-channels=2.
2009/09/24 08:31:40 [harbor:4] Client logged in.
2009/09/24 08:31:40 [harbor:3] SOURCE request on /live.ogg.
2009/09/24 08:31:40 [harbor:3] Adding source on mountpoint '/live.ogg' with type 'application/ogg'.
2009/09/24 08:31:40 [harbor:3] Returned 401 for '/live.ogg'.
2009/09/24 08:31:40 [threads:1] Thread "non-blocking queue #1" aborts with exception Unix.Unix_error(31, "write", "")!
2009/09/24 08:31:40 [main:3] Shutdown started!
2009/09/24 08:31:40 [main:3] Waiting for threads to terminate...
2009/09/24 08:31:40 [root:3] Shutting down sources...
2009/09/24 08:31:40 [source:4] oVorbis gets down
2009/09/24 08:31:40 [ogg.encoder:4] oVorbis: Setting end of track 23c3ffe8.
2009/09/24 08:31:41 [ogg.encoder:4] oVorbis: Every ogg logical tracks have ended: setting end of stream.
2009/09/24 08:31:41 [source:4] mainFallback gets down
2009/09/24 08:31:41 [source:4] liveMeta gets down
2009/09/24 08:31:41 [source:4] live gets down
2009/09/24 08:31:41 [live:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [liveMeta:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [playlist:4] Activations changed: static=[mainFallback:oVorbis:oVorbis], dynamic=[].
2009/09/24 08:31:41 [source:4] src_5366 gets down
2009/09/24 08:31:41 [source:4] noiseAmp gets down
2009/09/24 08:31:41 [source:4] noise gets down
2009/09/24 08:31:41 [noise:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [noiseAmp:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [src_5366:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [source:4] playlist gets down
2009/09/24 08:31:41 [lang:3] [PLAYLIST-END]: playlist source goes down! Switching to noise...
2009/09/24 08:31:41 [playlist:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [mainFallback:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [oVorbis:4] Activations changed: static=[], dynamic=[].
2009/09/24 08:31:41 [threads:3] Thread "root" exited (1 remaining).
2009/09/24 08:31:41 [playlist:2] Feeding stopped: Failure("relaying stopped")
2009/09/24 08:31:41 [threads:3] Thread "harbor source feeding" exited (0 remaining).
2009/09/24 08:31:41 [main:3] Cleaning downloaded files...
2009/09/24 08:31:41 >>> LOG END

[toots]

Hi Romeo !

This bug looks exactly like the one that was just fixed on ocaml-duppy.

Could you try to update ocaml-duppy and compile a new liquidsoap against it ? I bet this would fix the issue.

[romeodeepmind]

i have the latest one [6722]. i have upgraded yesterday. this appeared today a few hours ago

[romeodeepmind]

whoops! i meant [6755].

[toots]

Ok, so let's find out where this comes from.

Could do:

• Compile the whole liquidsoap and bindings with debugging enabled. For that you do:
  • make clean
  • ./configure --enable-debugging
  • make
• The run the new liquidsoap from the console, like this: OCAMLRUNPARAM="b" liquidsoap /path/to/script
• Try to reproduce the issue.

At this point you'll get a full backtrace of the exception and we'll be able to find exactly which line is responsible for the issue.

I have started looking at the code, I could see several places where this could come from, but an exception trace is always the best way to get a reliable fix.

[romeodeepmind]

i think i found out what happened.

by occasion i checked out latest revision into different directory. but compilled the old one.

so my actual version was [6722] as i wrote first.

now i've built latest one [6755] with debugging and verified that it's realy new one.

so i think this ticket may be closed now. i'll set the 'duplicate' resolution

[toots]

Ok.

Don't hesitate to reopen if you ever see the issue again !

[wiki]

 wrought iron stair railings  decorative railing  deck railings

[LwarX]

Folks, I'm experiencing something similar - after approximately two hours liquidsoap fails with following message:

2010/01/10 03:15:46 [src_4796:2] Feeding stopped: Ogg_demuxer.Invalid_stream
2010/01/10 03:15:46 [threads:3] Thread "harbor source feeding" exited (1 remaining).

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

Configuration file:

#!/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"),
				blank()]))

I use this setup to stream music from MPD and liquidsoap is used to prevent clients from disconnecting when MPD is stopped.

[toots]

Hi Romeo !

If I remember well, an issue in input.harbor should not crash liquidsoap. Even more, the source should just reconnect some time later.

Could you provide more informations on the topic, in particular more detailed logs ? Also, who's the client for the harbor stream ?

Thanks for you help !

[romeodeepmind]

Hi, Toots =)

My setup is now stable, but this issue is now experienced by LwarX. so, i guess he must provide you some info =)

Anyway, Thanks for your reply =)

[LwarX]

Actually I'm not Romeo, my name is Max :) I reopened this bug because it is the single result listed in Google by searching for error message "Feeding stopped: Ogg_demuxer.Invalid_stream"

Client source is MPD (Music Player Daemon) 0.15.6. I use Gentoo and modified all ebuilds to contain --enable-debugging, then recompiled all dependencies and liquidsoap itself. I reproduced this error two or three times, but log does not contain backtrace.

This is command which I used to launch liquidsoap:

liquidsoap /etc/liquidsoap/main.liq > output.txt 2>&1

When error occurs, liquidsoap does not exit (output.txt contains nothing) and error message only shown in log file:

2010/01/12 07:58:07 [src_4796:3] New metadata chunk "Serakina -- Liam's Visit"
2010/01/12 08:02:21 [src_4796:3] New metadata chunk "Reno Project -- Constellation"
2010/01/12 08:08:06 [src_4796:3] New metadata chunk "Robert Jakob -- The Art Of Coming Home"
2010/01/12 08:13:17 [src_4796:3] New metadata chunk "sion -- After Hours"
2010/01/12 08:21:32 [src_4796:3] New metadata chunk "Serakina -- 3 Days"
2010/01/12 08:26:41 [src_4796:3] New metadata chunk "Robert Jakob -- Orientation"
2010/01/12 08:32:29 [src_4796:3] New metadata chunk "sion -- Shuffle"
2010/01/12 08:38:30 [src_4796:3] New metadata chunk "sion -- goodbye and so long"
2010/01/12 08:41:31 [src_4796:3] New metadata chunk "Serakina -- Friday's Lounge"
2010/01/12 08:46:33 [src_4796:2] Feeding stopped: Ogg_demuxer.Invalid_stream
2010/01/12 08:46:33 [threads:3] Thread "harbor source feeding" exited (1 remaining).

At the same time, MPD log contains following record:

Jan 12 08:46 : output: "main" [shout] failed to play: Lost shout connection to localhost:800
6: Socket error

Hope this helps.

[toots]

Hi Max and Romeo, sorry for the confusion :-)

Yes, thanks it helps !

So, liquidsoap behaves as expected, but there is still a problem, although it's not sure whether it is MPD that is not sending a correct stream or liquidsoap that does not decode the stream correctly.

A useful thing to do to sort this then would be to dump the stream that is received by liquidsoap and inspect it to see if it is a valid stream or not. You can use the dumpfile option in the harbor operator for that.

Since liquidsoap does not crash, I believe this issue is not related to the original ticket. Hence, I will close this one. Please, open a new ticket with your specific issue and add the dump or a link to it.

[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