Some MP3s not playing - Still :(
  • I have some large mp3s that play fine on my machine and through the preview player, but do not in the schedule.
    • Schedule says its playing and progressing - but it is not.
    • There is no corresponding cache files created for these files in /var/tmp/airtime/pypo/cache/scheduler
    • I tried several mp3 file debuggers - all say the files are ok.

    There something odd in /var/log/airtime/pypo-liquidsoap/ls_script.log, but I am not sure what it means?


    2014/02/02 15:59:39 [stdout:3] #########################################
    2014/02/02 15:59:39 [stdout:3] #           *** pypo  ***               #
    2014/02/02 15:59:39 [stdout:3] #     pypo notification gateway         #
    2014/02/02 15:59:39 [stdout:3] #########################################
    2014/02/02 15:59:39 [server:3] New client: localhost.localdomain.
    2014/02/02 15:59:39 [server:3] Client localhost.localdomain disconnected.
    2014/02/02 15:59:49 [server:3] New client: localhost.localdomain.
    2014/02/02 15:59:49 [server:3] Client localhost.localdomain disconnected.
    2014/02/02 15:59:56 [s0:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/5.mp3".
    2014/02/02 15:59:56 [cue_cut_5468:3] End of track before cue-out point.
    2014/02/02 15:59:56 [amplify_5472:3] End of the current overriding.
    2014/02/02 15:59:56 [cross_5475:3] No next track ready yet.
    2014/02/02 15:59:56 [schedule_noise_switch:3] Switch to map_metadata_5607 with forgetful transition.
    2014/02/02 15:59:56 [lang:3] transition called...
    2014/02/02 15:59:57 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
    2014/02/02 15:59:57 [dummy(dot)1:3] Source failed (no more tracks) stopping output...
    2014/02/02 15:59:59 [server:3] New client: localhost.localdomain.
    2014/02/02 15:59:59 [server:3] Client localhost.localdomain disconnected.

    Any clues where to look? Looks @Daniel


    Post edited by John Chewter at 2014-02-02 12:12:36
    No longer using Airtime or Libretime.
  • 10 Comments sorted by
  • The same Problem i have also, I have many Testet, all mp3 resampled, all mp3 checked, 1000 % ok, but one Time every Night i have the great silence output on stream.
    I have posted in forum, this and that, all checked, icecast of error, naving, ls_script.log with errors, and answere is, that this is not a error.
    first i have deabian server, i read that give problem with liquitsoup and more, i change the server to ubuntu 12.04 lts, the same problem, every night 0 - 7 one time great silence, in airtime the playlist play, but no musik on stream.

    i think liquitsoup is buggy  ls_script.log
  • Yes, I think its liquid soap - I am trying to debug at this time.

    How big are your files Andy?
    Have you any small ones that dont play?

    What I notice is - files from some specific sources always play.
    Files from other specific sources never play

    Post edited by John Chewter at 2014-02-03 07:40:28
    No longer using Airtime or Libretime.
  • We have 7000 - 10000 songs in airtime at the moment, the files are 3 - 7 mb great, and the lang is 3 - 6 minutes circa..., sample 192 kbs cbr..., all the same source.

    We have extra playlist for the night, 0 - 8 clock to see if errors occur, all files 1000 % ok.

    On Day no problem with airtime, absolute peferkt, no problem with live DJ, no problem with Playlist, all perfekt and no problem.

    Edit, smal files played, jingle 5 - 30 seconds are ok
    Post edited by Andy at 2014-02-03 07:57:25
  • Could you please send me one of yours that does not play?
    info@coastal-computing.com

    No longer using Airtime or Libretime.
  • I have send a mail to you
  • I've actually only notice this with the player when I am previewing songs. I tend to have to play the mp3s with a desktop tool.
  • I do not or cannot confirm that this is any bug relate to liquidsoap.

    I took a 16hr. backup Mp3 and encode it in various bitrate  between 96k-320k and it worked just fine.

    My thoughts is that could run the song directly through liquidsoap and then output the logs and look at it.


    • One possibility is that is that there is a problem with either the mime type in apache or liquidsoap.
    • The Songs are not decoded  and prepared in time for liquidsoap to handle them.
    These are things  you can confirm by increase the log level to 6 and get a Verbose log.

    I explained the process here.
    Post edited by Voisses Tech at 2014-02-05 01:10:27
    Anyone reading this a find it funny about my grammar , I make no apology ,Go get a translator.
    "The Problem with education today is that it takes a university degree to switch on a light bulb"
    "You learn from your mistakes but wise people learn from others mistakes avoid Making mistakes there is not sufficient rooms to make them"
    "Innuendo","If's","Assumptions" and "Fear" are for politician.Who,What,where,When and How are for those seeking knowledge and care about Humanity.
    "I might be in Mud but that does not Make me a Wild Hog(pig)"
    “Any intelligent fool can make things bigger, more complex, and more violent. It takes a touch of genius — and a lot of courage to move in the opposite direction.”
    "The only thing that remains constant is change itself"
    May the force be with you,until our path or destiny bring us in tandem.
  • the same procedure as every day!

    5:46 Silence on Stream

    2014/02/06 05:44:29 [server:3] New client: localhost.
    2014/02/06 05:44:29 [server:3] Client localhost disconnected.
    2014/02/06 05:44:39 [server:3] New client: localhost.
    2014/02/06 05:44:39 [server:3] Client localhost disconnected.
    2014/02/06 05:44:49 [server:3] New client: localhost.
    2014/02/06 05:44:49 [server:3] Client localhost disconnected.
    2014/02/06 05:44:59 [server:3] New client: localhost.
    2014/02/06 05:44:59 [server:3] Client localhost disconnected.
    2014/02/06 05:45:09 [server:3] New client: localhost.
    2014/02/06 05:45:09 [server:3] Client localhost disconnected.
    2014/02/06 05:45:19 [server:3] New client: localhost.
    2014/02/06 05:45:19 [server:3] Client localhost disconnected.
    2014/02/06 05:45:29 [server:3] New client: localhost.
    2014/02/06 05:45:29 [server:3] Client localhost disconnected.
    2014/02/06 05:45:39 [server:3] New client: localhost.
    2014/02/06 05:45:39 [server:3] Client localhost disconnected.
    2014/02/06 05:45:49 [server:3] New client: localhost.
    2014/02/06 05:45:49 [server:3] Client localhost disconnected.
    2014/02/06 05:45:59 [server:3] New client: localhost.
    2014/02/06 05:45:59 [server:3] Client localhost disconnected.
    2014/02/06 05:46:09 [server:3] New client: localhost.
    2014/02/06 05:46:09 [server:3] Client localhost disconnected.
    2014/02/06 05:46:19 [server:3] New client: localhost.
    2014/02/06 05:46:19 [server:3] Client localhost disconnected.
    2014/02/06 05:46:29 [server:3] New client: localhost.
    2014/02/06 05:46:29 [server:3] Client localhost disconnected.
    2014/02/06 05:46:39 [server:3] New client: localhost.
    2014/02/06 05:46:39 [server:3] Client localhost disconnected.
    2014/02/06 05:46:49 [server:3] New client: localhost.
    2014/02/06 05:46:49 [server:3] Client localhost disconnected.
    2014/02/06 05:46:59 [server:3] New client: localhost.
    2014/02/06 05:46:59 [server:3] Client localhost disconnected.
    2014/02/06 05:47:09 [server:3] New client: localhost.
    2014/02/06 05:47:09 [server:3] Client localhost disconnected.

    014-02-06 05:40:54,271 DEBUG - [pyponotify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
    2014-02-06 05:44:17,085 DEBUG - [pyponotify.py : notify_media_start_playing() : line 78] - #################################################
    2014-02-06 05:44:17,085 DEBUG - [pyponotify.py : notify_media_start_playing() : line 79] - # Calling server to update about what's playing #
    2014-02-06 05:44:17,085 DEBUG - [pyponotify.py : notify_media_start_playing() : line 80] - #################################################
    2014-02-06 05:44:17,085 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/notify-media-item-start-play/api_key/0MYIX9VGIMUUPGBKAKVU/media_id/1947/
    2014-02-06 05:44:17,223 DEBUG - [pyponotify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}
    2014-02-06 05:48:00,131 DEBUG - [pyponotify.py : notify_media_start_playing() : line 78] - #################################################
    2014-02-06 05:48:00,131 DEBUG - [pyponotify.py : notify_media_start_playing() : line 79] - # Calling server to update about what's playing #
    2014-02-06 05:48:00,131 DEBUG - [pyponotify.py : notify_media_start_playing() : line 80] - #################################################
    2014-02-06 05:48:00,131 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/notify-media-item-start-play/api_key/0MYIX9VGIMUUPGBKAKVU/media_id/1948/
    2014-02-06 05:48:00,366 DEBUG - [pyponotify.py : notify_media_start_playing() : line 82] - Response: {"status": 1, "message": ""}

    Icecast error.lol

    [2014-02-06  05:44:17] INFO util/util_conv_string converting metadata from UTF-8 to ISO8859-1
    [2014-02-06  05:44:17] INFO admin/command_metadata Metadata on mountpoint /live1 changed to "Verschiedenes - Poco Loco Gang - "
    [2014-02-06  05:44:17] INFO admin/admin_handle_request Received admin command metadata on mount "/live1"
    [2014-02-06  05:44:17] INFO util/util_conv_string converting metadata from UTF-8 to ISO8859-1
    [2014-02-06  05:44:17] INFO admin/command_metadata Metadata on mountpoint /live1 changed to "Verschiedenes - Poco Loco Gang - "
    [2014-02-06  05:48:00] INFO admin/admin_handle_request Received admin command metadata on mount "/live1"
    [2014-02-06  05:48:00] INFO util/util_conv_string converting metadata from UTF-8 to ISO8859-1
    [2014-02-06  05:48:00] INFO admin/command_metadata Metadata on mountpoint /live1 changed to "Verschiedenes - Dendemann - Manah Mannah"
    [2014-02-06  05:50:35] INFO admin/admin_handle_request Received admin command metadata on mount "/live1"
    [2014-02-06  05:50:35] INFO util/util_conv_string converting metadata from UTF-8 to ISO8859-1
    [2014-02-06  05:50:35] INFO admin/command_metadata Metadata on mountpoint /live1 changed to "Verschiedenes - Baby Jane - "
    [2014-02-06  05:50:35] INFO admin/admin_handle_request Received admin command metadata on mount "/live1"

    Icecast acces.log

    85.214.221.38 - - [06/Feb/2014:05:45:17 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.61.138 - - [06/Feb/2014:05:45:20 +0100] "GET /admin/stats.xml HTTP/1.1" 200 1639 "-" "Python-urllib/2.7" 0
    85.214.221.38 - - [06/Feb/2014:05:45:34 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:45:47 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:46:02 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:46:18 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 1
    85.214.221.38 - - [06/Feb/2014:05:46:32 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:46:47 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:47:02 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.221.38 - - [06/Feb/2014:05:47:17 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 0
    85.214.61.138 - - [06/Feb/2014:05:47:20 +0100] "GET /admin/stats.xml HTTP/1.1" 200 1639 "-" "Python-urllib/2.7" 0
    81.17.208.200 - - [06/Feb/2014:05:47:22 +0100] "GET /status2.xsl HTTP/1.0" 200 403 "-" "Mozilla/5.0 (X11; U; Linux i686; en; rv:1.8.1.14) Gecko/20080504 Epiphany/2.22 Firefox/2.0.0.14" 0
    85.214.221.38 - - [06/Feb/2014:05:47:33 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 1
    85.214.221.38 - - [06/Feb/2014:05:47:48 +0100] "GET /status.xsl HTTP/1.1" 200 2538 "-" "-" 1
    85.214.61.138 - - [06/Feb/2014:05:48:00 +0100] "GET /admin/metadata HTTP/1.0" 200 177 "-" "Liquidsoap/1.1.1+scm (Unix; OCaml 3.12.1)" 0
    85.214.61.138 - - [06/Feb/2014:05:49:21 +0100] "GET /admin/stats.xml HTTP/1.1" 200 1646 "-" "Python-urllib/2.7" 0
    81.17.208.200 - - [06/Feb/2014:05:50:12 +0100] "GET /status2.xsl HTTP/1.0" 200 410 "-" "Mozilla/5.0 (X11; U; Linux i686; en; rv:1.8.1.14) Gecko/20080504 Epiphany/2.22 Firefox/2.0.0.14" 0
    85.214.61.138 - - [06/Feb/2014:05:50:35 +0100] "GET /admin/metadata HTTP/1.0" 200 177 "-" "Liquidsoap/1.1.1+scm (Unix; OCaml 3.12.1)" 0
    85.214.61.138 - - [06/Feb/2014:05:50:35 +0100] "GET /admin/metadata HTTP/1.0" 200 177 "-" "Liquidsoap/1.1.1+scm (Unix; OCaml 3.12.1)" 0
    85.214.61.138 - - [06/Feb/2014:05:50:35 +0100] "GET /admin/metadata HTTP/1.0" 200 177 "-" "Liquidsoap/1.1.1+scm (Unix; OCaml 3.12.1)" 0
    85.214.61.138 - - [06/Feb/2014:05:51:22 +0100] "GET /admin/stats.xml HTTP/1.1" 200 1634 "-" "Python-urllib/2.7" 1

    pypo.log

    2014-02-06 05:44:17,012 INFO - [pypoliqqueue.py : main() : line 38] - waiting 222.987831s until next scheduled item
    2014-02-06 05:45:20,261 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/get-stream-parameters/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:45:20,324 DEBUG - [api_client.py : get_stream_parameters() : line 504] - {u'stream_params': {u's3': {u'admin_pass': u'', u'enable': u'false', u'description': u'', u'url': u'', u'bitrate': u'48', u'mount': u'', u'liquidsoap_erro$
    2014-02-06 05:45:20,518 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/update-stream-setting-table/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:45:20,613 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/push-stream-stats/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:47:20,761 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/get-stream-parameters/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:47:20,822 DEBUG - [api_client.py : get_stream_parameters() : line 504] - {u'stream_params': {u's3': {u'admin_pass': u'', u'enable': u'false', u'description': u'', u'url': u'', u'bitrate': u'48', u'mount': u'', u'liquidsoap_erro$
    2014-02-06 05:47:20,985 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/update-stream-setting-table/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:47:21,073 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/push-stream-stats/api_key/0MYIX9VGIMUUPGBKAKVU/format/json
    2014-02-06 05:47:54,122 INFO - [replaygainupdater.py : run() : line 76] - Running replaygain updater
    2014-02-06 05:47:54,122 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/list-all-watched-dirs/format/json/api_key/0MYIX9VGIMUUPGBKAKVU
    2014-02-06 05:47:54,190 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/get-files-without-replay-gain/api_key/0MYIX9VGIMUUPGBKAKVU/dir_id/1
    2014-02-06 05:47:54,280 INFO - [replaygainupdater.py : main() : line 68] - Processed: 0 songs
    2014-02-06 05:47:54,281 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/get-files-without-replay-gain/api_key/0MYIX9VGIMUUPGBKAKVU/dir_id/3
    2014-02-06 05:47:54,374 INFO - [replaygainupdater.py : main() : line 68] - Processed: 0 songs
    2014-02-06 05:47:54,374 DEBUG - [api_client.py : __call__() : line 134] - http://airtime.radio-wolke7.de:80/api/get-files-without-replay-gain/api_key/0MYIX9VGIMUUPGBKAKVU/dir_id/2
    2014-02-06 05:47:54,463 INFO - [replaygainupdater.py : main() : line 68] - Processed: 0 songs
    2014-02-06 05:48:00,008 DEBUG - [telnetliquidsoap.py : queue_push() : line 89] - s0.push annotate:media_id="7113",liq_start_next="0",liq_fade_in="3.0",liq_fade_out="3.0",liq_cue_in="1.0",liq_cue_out="161.2",schedule_table_id="1948",replay_ga$

    2014-02-06 05:48:00,062 DEBUG - [telnetliquidsoap.py : queue_push() : line 95] - vars.show_name Verschiedenes

    2014-02-06 05:48:00,375 DEBUG - [telnetliquidsoap.py : queue_push() : line 98] - 4
    END
    Verschiedenes

    No apparent error, but silenc!
  • @Andy

    Open a new thread, Your problem seem unrelated.

    The problem above related to a track ending before its cue point.( can only be solved by looking at the track itself.

    Yours (@Andy) ,you need to look through the forum for silence and see if it relates to anything else thread

    As I said before its best you make your own thread with your own problem.

    If you have solution for another person thread then post the comment in that person thread.

    Your Problem may be unique,it may get lost by posting it in someone elses thread
    Anyone reading this a find it funny about my grammar , I make no apology ,Go get a translator.
    "The Problem with education today is that it takes a university degree to switch on a light bulb"
    "You learn from your mistakes but wise people learn from others mistakes avoid Making mistakes there is not sufficient rooms to make them"
    "Innuendo","If's","Assumptions" and "Fear" are for politician.Who,What,where,When and How are for those seeking knowledge and care about Humanity.
    "I might be in Mud but that does not Make me a Wild Hog(pig)"
    “Any intelligent fool can make things bigger, more complex, and more violent. It takes a touch of genius — and a lot of courage to move in the opposite direction.”
    "The only thing that remains constant is change itself"
    May the force be with you,until our path or destiny bring us in tandem.
  • I am with Andy. It is a pain.
    No longer using Airtime or Libretime.