End of track before cue-out point
  • Vote Up0Vote Down Mario CostaMario Costa
    Posts: 19Member
    Hi,

    I'm getting some erros in ls_script.log that is showing:

    End of track before cue-out point.

    Here's an example:

    2012/12/10 16:02:30 [server:3] Client localhost disconnected.
    2012/12/10 16:05:37 [decoder:3] Method "OGG" accepted "/var/tmp/airtime/pypo/cache/scheduler/1461.ogg".
    2012/12/10 16:05:38 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/417.ogg".
    2012/12/10 16:05:38 [cue_cut_5382:3] End of track before cue-out point.
    2012/12/10 16:05:38 [amplify_5387:3] End of the current overriding.
    2012/12/10 16:05:38 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/1461.ogg" (RID 43).
    2012/12/10 16:05:38 [amplify_5387:3] Overriding amplification: 0.457088.

     I've checked the file lenght in BD and:
    SELECT length,track_title,artist_name,filepath FROM cc_files WHERE id=417
    lengthtrack_titleartist_namefilepath
    00:03:23.577188 Black Heart  Stooshe  imported/Stooshe/Top2/14-Black Heart-320kbps.ogg


    SELECT starts,ends,clip_length,fade_in,fade_out,cue_in,cue_out FROM cc_schedule WHERE file_id=417 ORDER BY starts DESC
    startsendsclip_lengthfade_infade_outcue_incue_out
    2012-12-11 23:01:25.42368 2012-12-11 23:04:49.000868 00:03:23.577188 00:00:00.1 00:00:00.1 00:00:00  00:03:23.577188
    2012-12-11 00:28:22.560696 2012-12-11 00:31:46.137884 00:03:23.577188 00:00:00.1 00:00:00.1 00:00:00  00:03:23.577188
    2012-12-10 16:02:15.409182 2012-12-10 16:05:38.98637 00:03:23.577188 00:00:00.1 00:00:00.1 00:00:00  00:03:23.577188
    2012-12-09 23:04:45.507963 2012-12-09 23:08:09.085151 00:03:23.577188 00:00:00.1 00:00:00.1 00:00:00  00:03:23.577188
    2012-12-08 16:01:50.414237 2012-12-08 16:05:13.991425 00:03:23.577188 00:00:00.1 00:00:00.1 00:00:00  00:03:23.577188


    OGGINFO shows:
    ogginfo /srv/airtime/stor/imported/Stooshe/Top2/14-Black\ Heart-320kbps.ogg

    Processing file "/srv/airtime/stor/imported/Stooshe/Top2/14-Black Heart-320kbps.ogg"...

    New logical stream (#1, serial: 3f97adbc): type vorbis
    Vorbis headers parsed for stream 1, information follows...
    Version: 0
    Vendor: Xiph.Org libVorbis I 20070622 (1.2.0)
    Channels: 2
    Rate: 44100

    Nominal bitrate: 320,000000 kb/s
    Upper bitrate not set
    Lower bitrate not set
    User comments section follows...
    isrc=
    encodedby=None
    bpm=0
    conductor=
    date=2012
    composer=
    album=
    mood=mid
    genre=Mulher
    tracknumber=14
    artist=Stooshe
    copyright=
    label=top1
    website=
    title=Black Heart
    Vorbis stream 1:
    Total data length: 8927471 bytes
    Playback length: 3m:23.577s
    Average bitrate: 350,824022 kb/s
    Logical stream 1 ended



    So, seems like size is ok... why did I get this end of track before cue-out point?
    I haven't touched cue values for any track in any playlist


    normally, this generate a music repeating because airtime loses "sync" (on air turns grey)  

    Any idea?
    Thanks

    Post edited by Mario Costa at 2012-12-11 07:03:08
  • 5 Comments sorted by
  • Vote Up0Vote Down James MoonJames Moon
    Posts: 197Member
    Hi Mario,

    Does the track cuts off prematurely? or are you just curious about that log msg?
    It's usual to see such a msg in LS log file. So unless you hear the track gets cut off or something, it's ok.

    Thank you
  • Vote Up0Vote Down Mario CostaMario Costa
    Posts: 19Member
    Hi,
    Problem is that I think Airtime is "losing" some time in those tracks...
    Sometimes, The music is playing and, on the end of the track, starts the same track again:


    2012/12/23 18:14:00 [server:3] Client localhost disconnected.
    2012/12/23 18:15:41 [decoder:3] Method "OGG" accepted "/var/tmp/airtime/pypo/cache/scheduler/1040.ogg".
    2012/12/23 18:15:42 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/1040.ogg".
    2012/12/23 18:15:42 [cue_cut_5382:3] Cueing out...
    2012/12/23 18:15:42 [amplify_5387:3] End of the current overriding.
    2012/12/23 18:15:42 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/1040.ogg" (RID 0).
    2012/12/23 18:15:42 [cue_cut_5382:3] Cueing in...
    2012/12/23 18:15:42 [amplify_5387:3] Overriding amplification: 0.363915.
    2012/12/23 18:15:42 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='0' --media-id=65942 &


    on 18:15:42 should be start playing 1349.ogg but, looks like the time specified 18:15:42.xxx isn't ready yet and, the same track is repeated...


    That track it only started:
    2012/12/23 18:19:01 [decoder:3] Method "OGG" accepted "/var/tmp/airtime/pypo/cache/scheduler/1349.ogg".
    2012/12/23 18:19:01 [queue:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/1040.ogg".
    2012/12/23 18:19:01 [cue_cut_5382:3] Cueing out...
    2012/12/23 18:19:01 [amplify_5387:3] End of the current overriding.
    2012/12/23 18:19:01 [queue:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/1349.ogg" (RID 1).
    2012/12/23 18:19:01 [amplify_5387:3] Overriding amplification: 0.326964.
    2012/12/23 18:19:01 [lang:3] /usr/lib/airtime/pypo/bin/liquidsoap_scripts/notify.sh --data='0' --media-id=65943 &


    If touch the on-air playlist (change tracks order for example), you can see:

    2012/12/23 18:22:46 [server:3] Client localhost disconnected.
    2012/12/23 18:22:46 [server:3] New client: localhost.
    2012/12/23 18:22:46 [lang:3] dynamic_source.get_id
    2012/12/23 18:22:46 [server:3] Client localhost disconnected.
    2012/12/23 18:22:46 [server:3] New client: localhost.
    2012/12/23 18:22:46 [lang:3] source.skip
    2012/12/23 18:22:46 [queue:1] Finished with a non-existent file?! Something may have been moved or destroyed during decoding. It is VERY dangerous, avoid it!
    2012/12/23 18:22:46 [server:3] Client localhost disconnected.
    2012/12/23 18:22:46 [server:3] New client: localhost.
    2012/12/23 18:22:46 [lang:3] dynamic_source.output_stop
    2012/12/23 18:22:46 [lang:3] dynamic_source.id
    2012/12/23 18:22:46 [server:3] Client localhost disconnected.
    2012/12/23 18:22:46 [server:3] New client: localhost.
    2012/12/23 18:22:46 [decoder:3] Method "OGG" accepted "/var/tmp/airtime/pypo/cache/scheduler/365.ogg".


    So, I'm listening to the repeated track, I change the airtime on-air playlist and, the track on air goes out and, starts the correct track in the correct part of the next music (in the middle of the music because on that time, music should be almost finished).
    All goes into the correct timing now...


    So, this is very annoying... It happens many times per day, I thing it happens almost every 4 hours and I experience this in the last 3 versions of Airtime.





  • Vote Up0Vote Down Martin KonecnyMartin Konecny
    Posts: 1,860Member
    Hi Mario,

    What version of Airtime are you using? I believe this was fixed in Airtime 2.2.1.
    Airtime Pro Hosting: http://airtime.pro
  • Vote Up0Vote Down Mario CostaMario Costa
    Posts: 19Member
    Hi,

    I'm using 2.2.1 on Ubuntu 12.04.1 LTS

    I've already tried to re-upload the identified tracks but, errors persists...

    Thanks
  • Vote Up0Vote Down Martin KonecnyMartin Konecny
    Posts: 1,860Member
    Ticket created to investigate this:


    Airtime Pro Hosting: http://airtime.pro
Add a Comment