media-monitor
  • Hi Everyone,
    I'm having issues with the media-monitor, and I would like to do what I can to help resolve them. I'm running a fresh install of 14.04 LTS (Trusty) with 2.5.1. I have made the Silan upgrade (to the 'sfo' version out of the repository) and that has stopped the half-length file from showing up in the library. So far so good.

    The system plays out consistently - if there are scheduled files, they play, and all is good. Here is the latest check system:

    root@peach:~# airtime-check-system
    AIRTIME_STATUS_URL             = http://peach:80/api/status/format/json/api_key/%%api_key%%
    AIRTIME_SERVER_RESPONDING      = OK
    KERNEL_VERSION                 = 3.19.0-25-generic
    MACHINE_ARCHITECTURE           = x86_64
    TOTAL_MEMORY_MBYTES            = 3789196
    TOTAL_SWAP_MBYTES              = 3930108
    AIRTIME_VERSION                = 2.5.1
    OS                             = Ubuntu 14.04.3 LTS x86_64
    CPU                            = AMD Phenom(tm) 9950 Quad-Core Processor
    WEB_SERVER                     = Apache/2.4.7 (Ubuntu)
    PLAYOUT_ENGINE_PROCESS_ID      = 1094
    PLAYOUT_ENGINE_RUNNING_SECONDS = 243801
    PLAYOUT_ENGINE_MEM_PERC        = 0.6%
    PLAYOUT_ENGINE_CPU_PERC        = 0.0%
    LIQUIDSOAP_PROCESS_ID          = 1828
    LIQUIDSOAP_RUNNING_SECONDS     = 243748
    LIQUIDSOAP_MEM_PERC            = 1.2%
    LIQUIDSOAP_CPU_PERC            = 4.7%
    MEDIA_MONITOR_PROCESS_ID       = 9335
    MEDIA_MONITOR_RUNNING_SECONDS  = 275
    MEDIA_MONITOR_MEM_PERC         = 1.5%
    MEDIA_MONITOR_CPU_PERC         = 3.2%
    -- Your installation of Airtime looks OK!
    root@peach:~#

    However, I am finding that I need to periodically restart the media-monitor in order to get it to recognize/register files that have been uploaded by the DJs. This behaviour is intermittent at best. Sometimes there are no issues - especially in the hours following a restart. I should note that when a DJ uploads a file, it invariably is entered into the DB, the issue is that it is somehow not registered by the media-monitor, and as a result, does not appear in the GUI library.

    But the longer time goes on after a restart, the more certain that the media-monitor doesn't pick up on changes to the library. I test this by executing 'touch' on a file - if the media-monitor is healthy, I see the reaction in the airtime-log:

    2015-08-24 09:19:36,173 INFO - [Thread-1] [owners.py : get_owner()] : LINE 12 - Received owner for /srv/airtime/stor/imported/2/Suuns and Jerusalem In My Heart/Suuns and Jerusalem In My Heart/1-2amoutu I7tirakan-320kbps.mp3. Owner: -1
    2015-08-24 09:19:36,174 INFO - [Thread-1] [events.py : __init__()] : LINE 93 - matched path: /srv/airtime/stor/imported/2/Suuns and Jerusalem In My Heart/Suuns and Jerusalem In My Heart/1-2amoutu I7tirakan-320kbps.mp3
    2015-08-24 09:19:36,175 INFO - [Thread-1] [watchersyncer.py : handle()] : LINE 65 - Received event 'NewFile'. Path: '/srv/airtime/stor/imported/2/Suuns and Jerusalem In My Heart/Suuns and Jerusalem In My Heart/1-2amoutu I7tirakan-320kbps.mp3'
    2015-08-24 09:19:36,175 INFO - [Thread-1] [watchersyncer.py : push_queue()] : LINE 97 - Added event into queue
    2015-08-24 09:19:38,383 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 39 - We have 1 events that are unflushed
    2015-08-24 09:19:38,384 INFO - [Thread-3] [watchersyncer.py : flush_events()] : LINE 107 - Force flushing events...
    2015-08-24 09:19:38,384 INFO - [Thread-3] [watchersyncer.py : push_request()] : LINE 146 - WatchSyncer : Unleashing request
    2015-08-24 09:19:38,384 INFO - [Thread-47] [request.py : run_request()] : LINE 34 - Attempting request with 1 items.
    2015-08-24 09:19:38,392 INFO - [Thread-47] [api_client.py : send_media_monitor_requests()] : LINE 359 - Pumping out 1 requests...
    2015-08-24 09:19:38,393 DEBUG - [Thread-47] [api_client.py : __call__()] : LINE 134 - http://peach:80/api/reload-metadata-group/format/json/api_key/11QEA1EI7WMPYDKXHOYV
    2015-08-24 09:19:38,488 INFO - [Thread-47] [request.py : run_request()] : LINE 54 - Request was successful
    If the media-monitor is 'unhealthy', or lazy... there is no reaction in the log.

    It should also be noted that there are some DJs for which their storage directories (indexed by number - and as far as I can tell their 'id' is the order in which their Airtime account was created) are somehow not registered with the watcher or the media-monitor. So a question is: what causes a file to not be registered with the media-monitor? Is it something in the DB entry? Is it related to the DJs account itself? Why are some DJs not affected by this?

    Also, it troubles me a bit that on restart of the media-monitor, it seems to scan all the items in the DB. This takes about 10 minutes (there are over 18000 items in the DB). Here is a snippet of the media-monitor log just after restarting in case anyone is interested:

    2015-08-24 09:25:53,616 DEBUG - [Thread-15] [api_client.py : __call__()] : LINE 134 - http://peach:80/api/reload-metadata-group/format/json/api_key/11QEA1EI7WMPYDKXHOYV
    2015-08-24 09:25:53,616 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 30 requests waiting to be launched
    2015-08-24 09:25:56,619 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 30 requests waiting to be launched
    2015-08-24 09:25:59,621 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 30 requests waiting to be launched
    2015-08-24 09:26:02,624 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 30 requests waiting to be launched
    2015-08-24 09:26:03,331 INFO - [Thread-15] [request.py : run_request()] : LINE 54 - Request was successful
    2015-08-24 09:26:03,332 INFO - [Thread-16] [request.py : run_request()] : LINE 34 - Attempting request with 450 items.
    2015-08-24 09:26:05,627 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 29 requests waiting to be launched
    2015-08-24 09:26:08,630 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 29 requests waiting to be launched
    2015-08-24 09:26:10,005 INFO - [Thread-16] [api_client.py : send_media_monitor_requests()] : LINE 359 - Pumping out 450 requests...
    2015-08-24 09:26:10,049 DEBUG - [Thread-16] [api_client.py : __call__()] : LINE 134 - http://peach:80/api/reload-metadata-group/format/json/api_key/11QEA1EI7WMPYDKXHOYV
    2015-08-24 09:26:11,634 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 29 requests waiting to be launched
    2015-08-24 09:26:14,635 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 29 requests waiting to be launched
    2015-08-24 09:26:17,638 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 29 requests waiting to be launched
    2015-08-24 09:26:19,869 INFO - [Thread-16] [request.py : run_request()] : LINE 54 - Request was successful
    2015-08-24 09:26:19,870 INFO - [Thread-17] [request.py : run_request()] : LINE 34 - Attempting request with 450 items.
    2015-08-24 09:26:20,639 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:23,642 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:26,647 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:27,078 INFO - [Thread-17] [api_client.py : send_media_monitor_requests()] : LINE 359 - Pumping out 450 requests...
    2015-08-24 09:26:27,118 DEBUG - [Thread-17] [api_client.py : __call__()] : LINE 134 - http://peach:80/api/reload-metadata-group/format/json/api_key/11QEA1EI7WMPYDKXHOYV
    2015-08-24 09:26:29,650 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:32,651 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:35,653 INFO - [Thread-3] [watchersyncer.py : run()] : LINE 34 - We have 28 requests waiting to be launched
    2015-08-24 09:26:36,875 INFO - [Thread-17] [request.py : run_request()] : LINE 54 - Request was successful

    To my knowledge, it was a pretty basic install, and nothing much out of the ordinary. We installed the server version of 14.04.

    I should also note that this behaviour was rampant in our previous install, which was 10.04 LTS (Precise) and 2.5.1. Although, that install ran for a very long time (over 1.5 years) without exhibiting this type of behaviour). Why the upgrade? Well, I logged into the system about 3 weeks ago to find that we could no longer access our library. So we were pumping out dead air. We decided to take the opportunity to upgrade some HW (new disk) and install a newer version of the OS. I remain unconvinced that our down time wasn't caused by this similar problem that we have been experiencing.

    I have been posting about it in the support section for a long time, but haven't really gotten anyone to bite on helping us out. I have read a lot of the posts regarding this type of problem, and there are a lot, but never a definitive answer to what the problem might be. I'm prepared to feed logs, and even give access to my machine, in the hopes that we can solve this issue. My hope is that we have missed something small and insigificant, and that this will be an easy fix. The fact is that Airtime is an amazing system, and we would like to keep using it, but the model our station is working under is to limit the amount of overhead spent dealing with these nagging issues that should not be happening. So unless we fix this, we're going to have to move on eventually. It's really too bad because this system offers us a really amazing distributed administration of our station.

    Anyhow, I can and will help, I just need some guidance from those in the know. Please help!

    Cheers,
    dave

  • 5 Comments sorted by
  • We are having the same issue on 2.5.1, some web interface elements don't work at all and most interactions take almost 10 minutes to complete. My logs look much the same as yours. We are running very overpowered hardware too (Xeon with 12 cores, none ever creep above 10% load). 
    Post edited by Brandon Martin at 2015-12-28 15:37:50
  • Just curious have either of you tried 2.5.2. I know there was attempts at improving various aspects of the software that were mainly on the backend. I'm not sure if any of these would affect the issues you are having with media monitor or not. I also heard from a friend who recently installed a instance of this that he ran into a lot of problems with 14.04 but 12.04 worked out of the box. I'm not sure if this would resolve the issue or not but I will be setting up some test instances of airtime over the next couple of days and I'll see if I run into a similar issue.
    Post edited by Robbt at 2015-12-30 09:45:25
  • Old school dictates that you never really  have people directly upload to any production systems.
    Vsftp have a method to upload the files to one directory or individual directories(djs home in your case),
    you can then change the attributes (like mode,ownerships etc)

    what comes to my mind is that anything can be upload,like m4a,mp3,wma cda etc. giving the media monitor extra work

    You may want to look at
    http://sourcefabric.booktype.pro/airtime-25-for-broadcasters/automated-file-import/
    http://sourcefabric.booktype.pro/airtime-25-for-broadcasters/preparing-media-for-ingest/
    http://sourcefabric.booktype.pro/airtime-25-for-broadcasters/using-the-airtime-import-script/

    also  search the forum for media monitor
    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 found this post because I was also running into this same issue in exactly the same way.   Restarting media-monitor would cause it to pick up files which had been uploaded to Airtime, but which were not in the library. 

    I did a bunch of investigation and found that the root cause was that media monitor makes use of a Linux OS API called inotify via a python library called pyinotify.   inotify is used to let programs know if there is a change to a file or directory.  The default for Linux is to allow a max of 8196 'watches' for files/directories.  Since media monitor is monitoring your whole library, this max will eventually be hit.  The solution I have used is to up the max number of watches, which uses more memory:    http://unix.stackexchange.com/questions/13751/kernel-inotify-watch-limit-reached

    One thing which made this difficult to figure out is that the media monitor python script does not do very good error handling when it is unable to add a new watch.  The documentation for pyinotify shows how to do error handling in case there is a problem with adding a new watch.  See https://github.com/seb-m/pyinotify/blob/master/python2/examples/not_quiet.py 

    Here is the code in media monitor:

                wd = self.wm.add_watch(path, pyinotify.ALL_EVENTS, rec=True, auto_add=True, proc_fun=listener)
                if wd: self.__wd_path[path] = wd.values()[0]

    If there is a failure to add the watch there will be no notification in the media monitor logs.

  • Vote Up0Vote Down LukeLuke
    Posts: 3Member
    Thanks Chris,

    with your suggestion i fix my problem on Debian Wheezy and airtime 2.5.1 (without reinstall).

    I agree with you about "media monitor python script does not do very good error handling when it is unable to add a new watch"

    Luke