Under 2.3.1 and now 2.4, can't add certain new files due to media-monitor errors! - Airtime Support Discussions on Sourcefabric Forum

Airtime Support

Under 2.3.1 and now 2.4, can't add certain new files due to media-monitor errors!

Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

Hello,

I just started getting the following errors from the media monitor log:

2013-07-06 00:28:35,982 INFO - [Thread-132] [request.py : run_request()] : LINE 34 - Attempting requ
est with 156 items.
2013-07-06 00:28:36,042 ERROR - [Thread-132] [log.py : fatal_exception()] : LINE 33 - 'Unexpected' e
xception has occured:
2013-07-06 00:28:36,042 ERROR - [Thread-132] [log.py : fatal_exception()] : LINE 34 - invalid literal for float(): 00:00:00
2013-07-06 00:28:36,142 ERROR - [Thread-132] [log.py : fatal_exception()] : LINE 35 - Traceback (most recent call last):
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 132, in safe_pack
ret = self.pack()
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 218, in pack
req_dict = self.metadata.extract()
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py", line 45, in __get__
value = self.fget(obj)
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 78, in metadata
def metadata(self): return Metadata(self.path)
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/metadata.py", line 133, in __init__
self.__metadata = global_reader.read_mutagen(fpath)
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 222, in read_mutagen
return self.read(path, normalize_mutagen(path))
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 216, in read
path, muta_hash, normalized_metadata)
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 143, in read_value
r = self.__normalizer( self.__translator(full_deps) )
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/definitions.py", line 23, in <lambda>
t.translate(lambda k: format_length(k['cuein']))
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py", line 470, in format_length
t = float(mutagen_length)
ValueError: invalid literal for float(): 00:00:00

this repeats about 18 times and then the following:

2013-07-06 00:28:36,454 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,455 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE
283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,456 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,457 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 283 - Warning: Trying to send a request element without a 'mode'
2013-07-06 00:28:36,458 DEBUG - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 284 - Here is the the request: 'invalid literal for float(): 00:00:00'
2013-07-06 00:28:36,464 INFO - [Thread-132] [api_client.py : send_media_monitor_requests()] : LINE 299 - Pumping out 138 requests...
2013-07-06 00:28:38,722 INFO - [Thread-132] [request.py : run_request()] : LINE 54 - Request was successful

All this started happening when I uploaded an Ogg Vorbis file, added it to a show. Then after the show was over, deleted it from its watched folder and re-uploaded it with a corrected TITLE tag. At that point, the file never showed up even when attempting to use the Add Media UI.

The end result is I can't add any new files either via my watched folder or the Add Media UI.

This is on an Ubuntu 12.04 LTS installation that's been working fine until now.

Thanks for any assistance!
-Bill

Post edited by Bill Burton at 2013-07-14 16:38:12

10 Comments sorted by
- Votes
- Date Added
Vote Up0Vote Down Voisses Tech July 2013
Posts: 1,423Member

I would recommend you upgrade to 2.4.

I do not recommend keep version 2:3 it had too much problems with liquidsoap and if you keep it you need to upgrade to liquidsoap 1.11

Back up What you Want,Back up what you want,Back up what you want,Back up what you want, [I can over Emphasis this

my method to upgrade and still have your station up and running is to do

set up a small playlist on a machine push it via butt,m3w etc to a failover icecast mount point

I love a clean install.

so I do a
sudo apt-get remove airtime
sudo apt-get purge airtime
sudo apt-get autoremove

Reinstall as per manual (if you had added the sourcefabric repositories just update and install)

Please note there are other methods but I always love to do clean install,so I chose this method.

Warning
This method will keep your songs your media you previously install but you will have to recreate all playlist ,smartblocks and webstream,widgets,script modificatons etc.[after all this is a clean install],should you want to keep these,you can restore as allowed (like your widgets)

Post edited by Voisses Tech at 2013-07-06 05:11:37
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.
Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

Hello,

Thanks for the advice on upgrading to 2.4. I would like to upgrade very much and would do it today but someone has reported an issue with mono files. If I can't play mono files, it would be far worse than the current issue.

Right now, I'm trying to figure out how to add some debugging to the media monitor to find out which files are causing the issue.

It seems the value '00:00:00' is set as the cuein point and an exception is thrown when an attempt is made to convert this value to a float.

-Bill
Vote Up0Vote Down Voisses Tech July 2013
Posts: 1,423Member

One thing at a time at a time.Do the upgrade then we narrow it down,Mono Files should not be your problem.It might be the way you converted the files.so lets eliminate the first problem of you needing to upgrade.

I find this upgrade and installation method to be best

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.
Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

Hello,

I took your advice and upgraded to 2.4. This fixed my issue with the media monitor! The upgrade went very smoothly without any issues.

However, it's looking like some mono files do not play. Airtime just goes off-line. I hope there's a work around for this issue. All my mono files were recorded that way to begin with and are probably 70-80% of the broadcast content.

-Bill
Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

Back to this issue again but under 2.4. If the file(s) causing this issue were output in the stack trace or error messages, then I'd have a chance at addressing the issue.

Have tried patching the media monitor code to log the filename but the media monitor won't start up. Running service airtime-media-monitor status shows:

AIRTIME_STATUS_URL = ...
AIRTIME_SERVER_RESPONDING = OK
KERNEL_VERSION = 2.6.35.4-rscloud
MACHINE_ARCHITECTURE = x86_64
TOTAL_MEMORY_MBYTES = 1022536
TOTAL_SWAP_MBYTES = 2097148
AIRTIME_VERSION = 2.4.0
OS = Ubuntu 12.04.2 LTS x86_64
CPU = Quad-Core AMD Opteron(tm) Processor 2374 HE
WEB_SERVER = nginx/1.2.4
PLAYOUT_ENGINE_PROCESS_ID = 18421
PLAYOUT_ENGINE_RUNNING_SECONDS = 691655
PLAYOUT_ENGINE_MEM_PERC = 1.5%
PLAYOUT_ENGINE_CPU_PERC = 0.2%
LIQUIDSOAP_PROCESS_ID = 14762
LIQUIDSOAP_RUNNING_SECONDS = 608848
LIQUIDSOAP_MEM_PERC = 4.9%
LIQUIDSOAP_CPU_PERC = 0.0%
MEDIA_MONITOR_PROCESS_ID = FAILED
MEDIA_MONITOR_RUNNING_SECONDS = 0
MEDIA_MONITOR_MEM_PERC = 0%
MEDIA_MONITOR_CPU_PERC = 0%
-- Displaying log file /var/log/airtime/media-monitor/media-monitor.log
-- 2013-07-14 12:12:11,733 DEBUG - [Thread-29] [api_client.py : send_media_monitor_requests()] : LINE 343 - Warning: Trying to send a request element without a 'mode'
-- 2013-07-14 12:12:11,733 DEBUG - [Thread-29] [api_client.py : send_media_monitor_requests()] : LINE 344 - Here is the the request: 'invalid literal for float(): 00:00:00'
-- 2013-07-14 12:12:11,740 INFO - [Thread-29] [api_client.py : send_media_monitor_requests()] : LINE 359 - Pumping out 124 requests...
...

The root cause seems to be the cuein is sometimes set to the format "hh:mm:ss" and when this is passed to format_length() in /usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py, it fails because that's not a decimal number.

Have updated /usr/lib/airtime/media-monitor/mm2/media/metadata/definitions.py to try and log any filename with the issue but haven't figured out how yet.

In the meantime, I patched /usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py which seems to have fixed the issue:

<monitor> $ diff -u pure.py{_orig,}
--- pure.py_orig 2013-06-25 09:40:14.000000000 -0400
+++ pure.py 2013-07-14 18:50:06.000000000 -0400
@@ -475,7 +475,14 @@

def format_length(mutagen_length):
""" Convert mutagen length to airtime length """
- t = float(mutagen_length)
+ # FIX: somehow the length passed is sometimes in the format
+ # hh:mm:ss which can't be parsed because it's not a decimal
+ # number.
+ t = 0.0
+ try:
+ t = float(mutagen_length)
+ except StandardError:
+ return mutagen_length
h = int(math.floor(t / 3600))
t = t % 3600
m = int(math.floor(t / 60))

I doubt this is the best place or way to fix the issue but at least I can now load all my files.

-Bill
Vote Up0Vote Down Denise Rigato July 2013
Posts: 108Member

We had a similar issue to this which was fix for 2.4
You can see the issue here http://dev.sourcefabric.org/browse/CC-5126

What type of files are causing this error for you? Or better yet, can you attach one of the files here so we can do some test?
Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

Hello Denise, Yes, that looks like the same issue I'm having. Since the files were originally imported under 2.3.1, it could explain why the fix in 2.4 did not help.

All the files were re-encoded to .ogg using the dbPowerAmp Music Converter. Have probably converted around 100 files previously this way without issue from versions 2.2 to 2.3.1 and continuing under 2.4.

The stack trace does not show the filename which is why I can't say what it is. I had added 35 files at one time to a watched folder so I don't know which one(s) are causing the issue. When still under 2.3.1, I then removed all these 35 files from the watched folder but the errors persisted.

The format_length() method that I patched doesn't have access to the filename. I tried unsuccessfully to add a patch to display the filename as mentioned in my prior comment. As I don't know Python, it's a bit more of a challenge.
Vote Up0Vote Down Denise Rigato July 2013
Posts: 108Member

@Bill+Burton can you check /var/log/airtime/media-monitor/media-monitor.log and look for the time when airtime was attempting to import those files throwing the exception? Please post any exceptions or errors found in the log here.
Vote Up0Vote Down Bill Burton July 2013
Posts: 52Member

@Denise+Rigato, I backed out my patch to pure.py and restarted the media-monitor service. After manually refreshing my watched folder from the SYSTEM menu, the same errors show up in the media-monitor.log as originally posted above. I watched the errors show up in realtime as I was tailing the log.

Following is the first of many tracebacks:

2013-07-15 13:47:30,274 INFO - [Thread-7] [request.py : run_request()] : LINE 34 - Attempting request with 159 items.
2013-07-15 13:47:30,338 ERROR - [Thread-7] [log.py : fatal_exception()] : LINE 33 - 'Unexpected' exception has occured:
2013-07-15 13:47:30,338 ERROR - [Thread-7] [log.py : fatal_exception()] : LINE 34 - invalid literal for float(): 00:00:00
2013-07-15 13:47:30,338 ERROR - [Thread-7] [log.py : fatal_exception()] : LINE 35 - Traceback (most recent call last):
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 132, in safe_pack
ret = self.pack()
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 218, in pack
req_dict = self.metadata.extract()
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py", line 45, in __get__
value = self.fget(obj)
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/events.py", line 78, in metadata
def metadata(self): return Metadata(self.path)
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/metadata.py", line 136, in __init__
self.__metadata = global_reader.read_mutagen(fpath)
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 229, in read_mutagen
return self.read(path, normalize_mutagen(path))
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 223, in read
path, muta_hash, normalized_metadata)
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/process.py", line 147, in read_value
r = self.__normalizer( self.__translator(full_deps) )
File "/usr/lib/airtime/media-monitor/mm2/media/metadata/definitions.py", line 33, in <lambda>
t.translate(lambda k: format_length(k['cuein']))
File "/usr/lib/airtime/media-monitor/mm2/media/monitor/pure.py", line 478, in format_length
t = float(mutagen_length)
ValueError: invalid literal for float(): 00:00:00
Vote Up0Vote Down Denise Rigato July 2013
Posts: 108Member

Thanks @Bill
I was able to reproduce this error very easily.
I have a ticket open for this issue, http://dev.sourcefabric.org/browse/CC-5276

Start a New Discussion

Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

Sign In Apply for Membership

Categories

Poll

No poll attached to this discussion.

Top Posters

Albert FR 1978
Martin Konecny 1860
Andrey Podshivalov 1526
Voisses Tech 1423
John Chewter 899
Daniel James 844
Roger Wilco 784
hoerich 627
Paul Baranowski 389
Cliff Wang 339