Airtime 1.8.2 scheduled playlist did not play out - Airtime Support Discussions on Sourcefabric Forum

James Dunn

Hi all,

We had a show scheduled to play out today at 14:00 GMT which didn't happen. The logs from /var/log/airtime/pypo-liquidsoap/main/@400000004ed393ef02a0e3c4.u and /var/log/airtime/pypo-liquidsoap/main/current are shown below - it looks like liquidsoap restarted for some reason and there are some DEBUG messages. Any ideas what is going on? This is with Airtime 1.8.2 on Ubuntu Server 11.04.
I've downloaded the file from /var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/0b089df109b41bbce04c8e00ebb1a44c.mp3 and it plays fine (although there are some clipped samples showing in Audacity...)

thanks

James


@400000004ed3934e2d6ad2cc 2011/11/28 13:57:24 [decoder:3] Method "MP3" accepted "/media/usb/airtime/stor/4f7/4f7d0dd5fab9bc3445823f1a5981e9b0.mp3".<br>@400000004ed3935339e6da64 2011/11/28 13:57:29 [stor:3] Finished with "/media/usb/airtime/stor/c6f/c6f388d4a3460d13740e03c2ef146e87.mp3".<br>@400000004ed393533b183e14 2011/11/28 13:57:29 [stor:3] Prepared "/media/usb/airtime/stor/4f7/4f7d0dd5fab9bc3445823f1a5981e9b0.mp3" (RID 0).<br>@400000004ed393540a3073ac /usr/lib/airtime/pypo/bin/scripts/notify.sh --data='0' --media-id=<br>@400000004ed393560091f924 <br>@400000004ed39356009208c4 #########################################<br>@400000004ed3935600920cac #&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; *** pypo&nbsp; ***&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed393560092147c #&nbsp;&nbsp;&nbsp;&nbsp; pypo notification gateway&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed3935600921864 #########################################<br>@400000004ed3935600921c4c NOTICE: 'media_id' command-line argument not given.<br>@400000004ed393ea003e5314 2011/11/28 14:00:00 [server:3] New client: localhost<br>@400000004ed393ea008ee02c 2011/11/28 14:00:00 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/20b852d9f8dd612dd451465d5090143b.mp3".<br>@400000004ed393ea0208f924 2011/11/28 14:00:00 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/20b852d9f8dd612dd451465d5090143b.mp3" (RID 2).<br>@400000004ed393ea024e7634 2011/11/28 14:00:00 [fallback_4502:3] Switch to src_4463 with transition.<br>@400000004ed393ea0251dd4c 2011/11/28 14:00:00 [decoder:3] Method "MP3" accepted "/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/0b089df109b41bbce04c8e00ebb1a44c.mp3".<br>@400000004ed393ea0df96674 /usr/lib/airtime/pypo/bin/scripts/notify.sh --data='96' --media-id=224<br>@400000004ed393ea3a9a097c <br>@400000004ed393ea3a9a1534 #########################################<br>@400000004ed393ea3a9a1d04 #&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; *** pypo&nbsp; ***&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed393ea3a9a20ec #&nbsp;&nbsp;&nbsp;&nbsp; pypo notification gateway&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed393ea3a9a24d4 #########################################<br>@400000004ed393ea3a9a28bc 2011-11-28 14:00:00,977 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 75] - #################################################<br>@400000004ed393eb001f0b44 2011-11-28 14:00:01,001 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 76] - # Calling server to update about what's playing #<br>@400000004ed393eb002285e4 2011-11-28 14:00:01,002 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 77] - #################################################<br>@400000004ed393eb0025588c 2011-11-28 14:00:01,002 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 78] - data = 96<br>@400000004ed393eb00299e4c 2011-11-28 14:00:01,002 DEBUG - [api_client.py : notify_media_item_start_playing() : line 286] - http://localhost:80/api/notify-media-item-start-play/api_key/%%api_key%%/media_id/224/schedule_id/96&lt;br&gt;@400000004ed393ec275df6fc 2011-11-28 14:00:02,660 INFO - [api_client.py : notify_media_item_start_playing() : line 290] - API-Status 1<br>@400000004ed393ec27d26b7c 2011-11-28 14:00:02,667 INFO - [api_client.py : notify_media_item_start_playing() : line 291] - API-Message <br>@400000004ed393ec27d83bc4 2011-11-28 14:00:02,668 DEBUG - [pypo-notify.py : notify_media_start_playing() : line 80] - Response: {"status": 1, "message": ""}<br><br><br>

@400000004ed393ef0ead3d84 *** Daemontools: starting liquidsoap<br>@400000004ed393f2206aed64 2011/11/28 14:00:08 &gt;&gt;&gt; LOG START<br>@400000004ed393f2206caab4 2011/11/28 14:00:07 [protocols.external:3] Didn't find "ufetch".<br>@400000004ed393f2206d8574 2011/11/28 14:00:07 [protocols.external:3] Found "/usr/bin/wget".<br>@400000004ed393f2206e547c 2011/11/28 14:00:07 [main:3] Liquidsoap 1.0.0-beta+svn (default@e712df4d96c0:20110513:131226)<br>@400000004ed393f2206f3324 2011/11/28 14:00:07 [main:3] Using: pcre=6.0.1 dtools=0.2.2 duppy=0.4.0 duppy.syntax=0.4.0 cry=0.2.0 mm=0.1.0 xmlplaylist=0.1.2 ogg=0.4.1 vorbis=0.5.1 mad=0.4.0 flac=0.1.0 flac.ogg=0.1.0 lame=0.2.4 alsa=0.2.1 ao=0.2.0 samplerate=0.1.1 taglib=0.1.4 camomile=0.7.1 portaudio=@VERSION ladspa=0.1.2<br>@400000004ed393f220700de4 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f22070dcec 2011/11/28 14:00:07 [main:2] DISCLAIMER: This version of Liquidsoap has been<br>@400000004ed393f22071afdc 2011/11/28 14:00:07 [main:2] compiled from a snapshot of the development code.<br>@400000004ed393f2207286b4 2011/11/28 14:00:07 [main:2] As such, it should not be used in production<br>@400000004ed393f220735d8c 2011/11/28 14:00:07 [main:2] unless you know what you are doing!<br>@400000004ed393f220743464 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f220750754 2011/11/28 14:00:07 [main:2] We are, however, very interested in any feedback<br>@400000004ed393f22075da44 2011/11/28 14:00:07 [main:2] about our development code and committed to fix<br>@400000004ed393f22076b11c 2011/11/28 14:00:07 [main:2] issues as soon as possible.<br>@400000004ed393f22077840c 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f2209f304c 2011/11/28 14:00:07 [main:2] If you are interested in collaborating to<br>@400000004ed393f220a02e34 2011/11/28 14:00:07 [main:2] the development of Liquidsoap, feel free to<br>@400000004ed393f220a10124 2011/11/28 14:00:07 [main:2] drop us a mail at &lt;savonet-devl@lists.sf.net&gt;<br>@400000004ed393f220a1d7fc 2011/11/28 14:00:07 [main:2] or to join the #savonet IRC channel on Freenode.<br>@400000004ed393f220a2aaec 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f220a381c4 2011/11/28 14:00:07 [main:2] Please send any bug report or feature request<br>@400000004ed393f220a454b4 2011/11/28 14:00:07 [main:2] using our trac &lt;http://savonet.rastageeks.org&gt;.<br>@400000004ed393f220a5b05c 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f220a68b1c 2011/11/28 14:00:07 [main:2] We hope you enjoy this snapshot build of Liquidsoap!<br>@400000004ed393f220a75e0c 2011/11/28 14:00:07 [main:2] <br>@400000004ed393f220a830fc 2011/11/28 14:00:08 [lang:3] Did not find flac binary: flac decoder disabled.<br>@400000004ed393f220a903ec 2011/11/28 14:00:08 [lang:3] Did not find metaflac binary: flac metadata resolver disabled.<br>@400000004ed393f220a9d6dc 2011/11/28 14:00:08 [lang:3] Did not find faad binary: faad decoder disabled.<br>@400000004ed393f220aaa9cc 2011/11/28 14:00:08 [lang:3] Lastfm/audioscrobbler support was not compiled.<br>@400000004ed393f220ab78d4 2011/11/28 14:00:08 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.<br>@400000004ed393f220ac4fac 2011/11/28 14:00:08 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.<br>@400000004ed393f220ad2684 2011/11/28 14:00:08 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.<br>@400000004ed393f220adfd5c 2011/11/28 14:00:08 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.<br>@400000004ed393f220b5aa34 2011/11/28 14:00:08 [threads:3] Created thread "generic queue #1".<br>@400000004ed393f220b7f03c 2011/11/28 14:00:08 [threads:3] Created thread "non-blocking queue #1".<br>@400000004ed393f22116832c 2011/11/28 14:00:08 [stor:3] Loading playlist...<br>@400000004ed393f2211fa31c 2011/11/28 14:00:08 [stor:3] Playlist is a directory.<br>@400000004ed393f43541cbf4 2011/11/28 14:00:10 [server:3] New client: localhost<br>@400000004ed393f43541df7c 2011/11/28 14:00:10 [server:3] New client: localhost<br>@400000004ed393f4361b72b4 2011/11/28 14:00:10 [stor:3] Successfully loaded a playlist of 1417 tracks.<br>@400000004ed393f437005474 2011/11/28 14:00:10 [safe:3] Loading playlist...<br>@400000004ed393f437006414 2011/11/28 14:00:10 [safe:3] Playlist is a directory.<br>@400000004ed393f43832a284 2011/11/28 14:00:10 [decoder:3] Method "MP3" accepted "/media/usb/airtime/stor/666/666907a5d9a4a68f415c36e595631925.mp3".<br>@400000004ed393f439dd0aac TagLib: MPEG::Header::parse() -- Invalid sample rate.<br>@400000004ed393f43ad6d3fc 2011/11/28 14:00:10 [safe:3] Successfully loaded a playlist of 37 tracks.<br>@400000004ed393f43ad6e39c 2011/11/28 14:00:10 [threads:3] Created thread "ao" (1 total).<br>@400000004ed393f43b2712f4 2011/11/28 14:00:10 [airtime(dot)mp3:3] Connecting mount airtime.mp3 for source@127.0.0.1...<br>@400000004ed393f5018fba14 2011/11/28 14:00:11 [decoder:3] Method "MP3" accepted "/media/usb/safe/NTS JINGLE 8.mp3".<br>@400000004ed393f50f84d8d4 2011/11/28 14:00:11 [airtime(dot)mp3:3] Connection setup was successful.<br>@400000004ed393f50f88d074 2011/11/28 14:00:11 [threads:3] Created thread "wallclock_ao" (2 total).<br>@400000004ed393f50f8adfcc 2011/11/28 14:00:11 [clock.wallclock_ao:3] Streaming loop starts, no sync.<br>@400000004ed393f50f8c2bd4 2011/11/28 14:00:11 [mksafe:3] Switch to src_4513.<br>@400000004ed393f50f8dd984 2011/11/28 14:00:11 [fallback_4502:3] Switch to mksafe.<br>@400000004ed393f50f8f064c 2011/11/28 14:00:11 [mksafe:3] Switch to safe_blank.<br>@400000004ed393f50f96a76c 2011/11/28 14:00:11 [stor:3] Prepared "/media/usb/airtime/stor/666/666907a5d9a4a68f415c36e595631925.mp3" (RID 1).<br>@400000004ed393f50f9812b4 2011/11/28 14:00:11 [mksafe:3] Switch to fallback_4498 with transition.<br>@400000004ed393f50fb76254 2011/11/28 14:00:11 [fallback_4498:3] Switch to src_4497.<br>@400000004ed393f511bccb5c /usr/lib/airtime/pypo/bin/scripts/notify.sh --data='0' --media-id=<br>@400000004ed393f51cbee10c <br>@400000004ed393f51cbef0ac #########################################<br>@400000004ed393f51cbef494 #&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; *** pypo&nbsp; ***&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed393f51cbef87c #&nbsp;&nbsp;&nbsp;&nbsp; pypo notification gateway&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed393f51cbefc64 #########################################<br>@400000004ed393f51cbf0434 NOTICE: 'media_id' command-line argument not given.<br>@400000004ed393f51dbd0f5c 2011/11/28 14:00:11 [ao:3] Opening Advanced Linux Sound Architecture (ALSA) output (2 channels)...<br>@400000004ed39404179db144 2011/11/28 14:00:26 [safe:3] Prepared "/media/usb/safe/NTS JINGLE 8.mp3" (RID 3).<br>@400000004ed39404179f91bc 2011/11/28 14:00:26 [fallback_4498:3] Switch to safe with forgetful transition.<br>@400000004ed394041b6bd814 /usr/lib/airtime/pypo/bin/scripts/notify.sh --data='0' --media-id=<br>@400000004ed39404262de33c <br>@400000004ed39404262deb0c #########################################<br>@400000004ed39404262df2dc #&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; *** pypo&nbsp; ***&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed39404262df6c4 #&nbsp;&nbsp;&nbsp;&nbsp; pypo notification gateway&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed39404262dfaac #########################################<br>@400000004ed39404262dfe94 NOTICE: 'media_id' command-line argument not given.<br>@400000004ed39421379e5994 2011/11/28 14:00:55 [fallback_4498:3] Switch to src_4497 with transition.<br>@400000004ed394213aee6b0c /usr/lib/airtime/pypo/bin/scripts/notify.sh --data='0' --media-id=<br>@400000004ed3942209ee59cc <br>@400000004ed3942209ee6584 #########################################<br>@400000004ed3942209ee696c #&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; *** pypo&nbsp; ***&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed3942209ee6d54 #&nbsp;&nbsp;&nbsp;&nbsp; pypo notification gateway&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; #<br>@400000004ed3942209ee713c #########################################<br>@400000004ed3942209ee7524 NOTICE: 'media_id' command-line argument not given.<br>@400000004ed3a1fd272b9874 2011/11/28 15:00:03 [decoder:3] Method "MP3" accepted "/media/usb/airtime/stor/35c/35cb0f6bca242aaca8317e9fbff16fed.mp3".

Paul Baranowski

Also, we have fixed a lot of bugs with metadata in the 1.9.X series of releases. You might want to consider upgrading.

Paul Baranowski · Post edited by Jakub Górnicki at 2011-11-29 02:27:24

Could you please send this file to me?

@400000004ed393f43832a284 2011/11/28 14:00:10 [decoder:3] Method "MP3" accepted "/media/usb/airtime/stor/666/<wbr>666907a5d9a4a68f415c36e5956319<wbr>25.mp3".<br>@400000004ed393f439dd0aac TagLib: MPEG::Header::parse() -- Invalid sample rate.<br>

James Dunn · Post edited by James Dunn at 2011-11-29 08:16:52

Hi Paul,

thanks for the response. The file 666907a5d9a4a68f415c36e595631925.mp3 is a 86mb file. I'm currently uploading it to dropbox to send you a link, but I don't see any problems with it in audacity or with sox.

Also, this is not the file that was supposed to play out. The scheduled playlist contained the files:

/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/20b852d9f8dd612dd451465d5090143b.mp3
/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/0b089df109b41bbce04c8e00ebb1a44c.mp3
/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/d39f21a39fd9f7188971757ce9f0ef80.mp3
/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/75ae62908641ff7c25fd2a774bc218b2.mp3
/var/tmp/airtime/pypo/cache/scheduler/2011-11-28-14-00-00/e435425450d267d6b8066cf0c7e93df7.mp3

All of which appear to be fine with the sox/play command.

Looking at the log posted above, it seems that liquidsoap restarted itself at 14:00:08 and I was assuming this was what caused the scheduled content to not play out. Why this happened is not clear though.

I should also mention that I have modified /usr/lib/airtime/pypo/bin/scripts/ls_script.liq to say:

archive = (playlist(mode='random', "/media/usb/airtime/stor"))
backup = (playlist(mode='random', "/media/usb/safe"))
default = mksafe(fallback(track_sensitive=false,[ strip_blank(threshold=-45.,length=15.,archive) , backup ]))

#default = amplify(0.00001, noise())
#default = rewrite_metadata([("artist","Airtime"), ("title", "offline")],default)

So the file 666907a5d9a4a68f415c36e595631925.mp3 is playing out from the 'default' option.

We plan to upgrade soon, as soon as we can get a new computer

many thanks

James 

Albert FR · Post edited by Albert FR at 2011-11-29 10:17:01

if you are on 1.8.2 try to add this line :

# -*- coding: utf-8 -*-

at the first line of :

/var/lib/airtime/tmp/python_apps/media-monitor/MediaMonitor. py

James Dunn

Hi Albert,

thanks for the suggestion, however I do not have the file /var/lib/airtime/tmp/python_apps/media-monitor/MediaMonitor.py
in 1.8.2, I think this was introduced with version 1.9.x, no?

I've checked the metadata with both sox --info file.mp3 and in the Airtime web ui and there are no strange characters - all filenames are in English with either spaces or hyphens.

thanks
James

James Dunn · Post edited by James Dunn at 2011-11-29 11:55:04

also, here's the link to the file you requested Paul:

http://db.tt/mbn1DQZh

Paul Baranowski

I've created a ticket here for this:
http://dev.sourcefabric.org/browse/CC-3167

Please note that even if we found a problem and provided a fix to you, you would need to be able to upgrade to be able to get the benefits of that fix.

Howdy, Stranger!

Categories

Poll

Top Posters