Hi All
Been using sabnzbd for years, but never really had a problem with it - until I started using the RSS features.
Somedays, my 'selected items from usenet' , just will not download via RSS - this was puzzling me, as the feed was enabled correctly, and showed the items in the feed, but sabnzbd just wouldn't parse it.
So I did a little digging - and this issue goes back to 0.4.8 - maybe earlier (I know, because I just upgraded to 0.4.11 and it's still there).
The issue is this :
1. My machine parses both newzbin bookmarks and RSS feeds (from my own rss source)
2. In my logs, I sometimes see an 'error' when SAB tries to access newzbin for obtaining the bookmarks (usually a '500 newzbin not available' - only happens once every couple of days).
3. Once the bookmark thread has detected this error - I no longer get the 'parsing RSS feed' log messages in my logs - I'm guessing the thread has stopped dead - SAB still looks for bookmarks every 15 minutes, but the RSS thread just doesn't appear in the logs any more unitl I restart SABNZBD
Hope this helps, and I hope it's an easy fix, I love the software and very rarely need to log into it anymore (all done now via bookmarks and RSS), but this little bug had me tearing my hair out trying to figure out what was happening.
I can provide logs if necessary to show the point at which the RSS thread stops dead - I've been looking around on the forum and several other people have reported RSS issues - I'm hoping this helps you guys out.
Cheers
catbert
RSS Thread stops working
Forum rules
Help us help you:
Help us help you:
- Are you using the latest stable version of SABnzbd? Downloads page.
- Tell us what system you run SABnzbd on.
- Adhere to the forum rules.
- Do you experience problems during downloading?
Check your connection in Status and Interface settings window.
Use Test Server in Config > Servers.
We will probably ask you to do a test using only basic settings. - Do you experience problems during repair or unpacking?
Enable +Debug logging in the Status and Interface settings window and share the relevant parts of the log here using [ code ] sections.
Re: RSS Thread stops working
Could be indeed a crash.
Do you use the binary distribution for Windows?
If so and the SABnzbd program folder (c:\program files\sabnzbd) is
writable for the current user, it will contain a file sabnzbd.exe.log.
Runtime errors will be logged in this file.
Have a look at it and if you think there's something interesting in it,
email it to [email protected]
Are you sure it says '500 newzbin not available'?
I cannot find that particular text in the program.
Do you use the binary distribution for Windows?
If so and the SABnzbd program folder (c:\program files\sabnzbd) is
writable for the current user, it will contain a file sabnzbd.exe.log.
Runtime errors will be logged in this file.
Have a look at it and if you think there's something interesting in it,
email it to [email protected]
Are you sure it says '500 newzbin not available'?
I cannot find that particular text in the program.
Last edited by shypike on September 30th, 2009, 3:56 am, edited 1 time in total.
Re: RSS Thread stops working
Hi
I don't have access to the full machine logs right now (at work ;-)), but I did copy & paste the error for today when I post on this forum :
2009-09-30 07:29:01,315::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 07:29:22,346::WARNING::[newzbin] Problem accessing Newzbin server.
- can't remember where the 500 error came from (it was definitely a '500' error).
Anyhoo, I've just taken a look through the code (hope you don't mind me downloading via svn).
Now, I've never used Python before, but I've been a programmer in different languages for the past 20 years, so I'm pretty sure I can follow what's going on :
- now, in the 'bookmarks' class in newzbin.py, you can see that if an exception occurs, the error is written out to the log, and then 'returns' from that routine.
This means that the other code which checks for the error status is never called, eg:
- I'm guessing something in there which should be run (maybe 'self.___busy=false' ?) isn't getting run because of the 'return' statement in the exception handler ?
Like I said, I don't know python, so maybe I'm just misinterpreting it - I'll take a peek at the sabnzbd.exe.log file when I get home tonight and have a look through it - the 500 error doesn't happen that often, but each and every time it does happen, the RSS feed stops (you can see in the sabnzbd.log' file that the feedparser is never used after that issue with the 'bookmark' call.
Cheers
catbert
I don't have access to the full machine logs right now (at work ;-)), but I did copy & paste the error for today when I post on this forum :
2009-09-30 07:29:01,315::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 07:29:22,346::WARNING::[newzbin] Problem accessing Newzbin server.
- can't remember where the 500 error came from (it was definitely a '500' error).
Anyhoo, I've just taken a look through the code (hope you don't mind me downloading via svn).
Now, I've never used Python before, but I've been a programmer in different languages for the past 20 years, so I'm pretty sure I can follow what's going on :
Code: Select all
class Bookmarks:
""" Get list of bookmarks from www.newzbin.com
"""
def __init__(self, username, password):
self.username = username
self.password = password
self.bookmarks = sabnzbd.load_data(BOOKMARK_FILE_NAME)
if not self.bookmarks:
self.bookmarks = []
@synchronized(BOOK_LOCK)
def run(self, delete=None):
headers = { 'User-Agent': 'SABnzbd', }
# Connect to Newzbin
try:
if _HAVE_SSL:
conn = httplib.HTTPSConnection('www.newzbin.com')
else:
conn = httplib.HTTPConnection('www.newzbin.com')
if delete:
logging.debug('[%s] Try to delete Newzbin bookmark %s', __NAME__, delete)
postdata = { 'username': self.username, 'password': self.password, 'action': 'delete', \
'reportids' : delete }
else:
logging.info('[%s] Fetching Newzbin bookmarks', __NAME__)
postdata = { 'username': self.username, 'password': self.password, 'action': 'fetch'}
postdata = urllib.urlencode(postdata)
headers['Content-type'] = 'application/x-www-form-urlencoded'
fetchurl = '/api/bookmarks/'
conn.request('POST', fetchurl, postdata, headers)
response = conn.getresponse()
except:
logging.warning('[%s] Problem accessing Newzbin server.', __NAME__)
return
This means that the other code which checks for the error status is never called, eg:
Code: Select all
data = response.read()
# Get the status
rcode = str(response.status)
# Official return codes:
# 200 = OK, NZB content follows
# 204 = No content
# 400 = Bad Request, please supply all parameters
# (this generally means reportid or fileid is missing; missing user/pass gets you a 401)
# 401 = Unauthorised, check username/password?
# 402 = Payment Required, not Premium
# 403 = Forbidden (incorrect auth)
# 500 = Internal Server Error, please report to Administrator
# 503 = Service Unavailable, site is currently down
if rcode == '204':
logging.debug("[%s] No bookmarks set", __NAME__)
elif rcode in ('401', '403'):
logging.warning("[%s] Unauthorised, check your newzbin username/password", __NAME__)
elif rcode in ('402'):
logging.warning("[%s] You have no credit on your Newzbin account", __NAME__)
elif rcode in ('500', '503'):
logging.warning('[%s] Newzbin has a server problem (%s).', __NAME__, rcode)
elif rcode != '200':
logging.error('[%s] Newzbin gives undocumented error code (%s)', __NAME__, rcode)
if rcode == '200':
if delete:
if data.startswith('1'):
logging.info('[%s] Deleted newzbin bookmark %s', __NAME__, delete)
self.bookmarks.remove(delete)
else:
logging.warning('[%s] Could not delete newzbin bookmark %s', __NAME__, delete)
else:
for line in data.split('\n'):
try:
msgid, size, text = line.split('\t', 2)
except:
msgid = size = text = None
if msgid and (msgid not in self.bookmarks):
self.bookmarks.append(msgid)
logging.info("[%s] Found new bookmarked msgid %s (%s)", __NAME__, msgid, text)
sabnzbd.add_msgid(int(msgid), None, None)
self.__busy = False
- I'm guessing something in there which should be run (maybe 'self.___busy=false' ?) isn't getting run because of the 'return' statement in the exception handler ?
Like I said, I don't know python, so maybe I'm just misinterpreting it - I'll take a peek at the sabnzbd.exe.log file when I get home tonight and have a look through it - the 500 error doesn't happen that often, but each and every time it does happen, the RSS feed stops (you can see in the sabnzbd.log' file that the feedparser is never used after that issue with the 'bookmark' call.
Cheers
catbert
Re: RSS Thread stops working
That's the very purpose of Open Source, isn't it?catbert wrote: Anyhoo, I've just taken a look through the code (hope you don't mind me downloading via svn).
The return looks OK to me, at that point newzbin isn't communicating at all.
So it makes little sense to analyze the response code, there isn't any.
A Thread-method 'run' isn't supposed to terminate, but "bookmarks" isn't a thread.
The method is called directly from the scheduler.
The self.__busy is obsolete code that should have been removed.
The RSS code is independent of the bookmark support.
So the only thing I can think of is that a crash in anything bookmark-related,
crashes the scheduler itself.
I'll look into this. Meanwhile, I would be very much helped by the crashlog file.
Thanks for thinking along with this, it gives me new clues to look into.
Re: RSS Thread stops working
There's no 'sabnzbd.exe.log' file in my directory (it's running as a service with admin rights so I'm not sure why that file didn't get generated).
Here's an excerpt from the log at the point of the very last 'rss' check (no more after that) :
(I inserted the gaps for dramatic effect ;-))
- you can see that after the '500' error in the log, there are no more checks against the RSS feed, but bookmarks continue to work.... odd huh ? As I stated above, the RSS checking always stops working after this point and I have to manually shutdown sabnzbd / restart it again to get them working - it does sound like the scheduler got a bit knackered ;-)
Cheers
catbert
Here's an excerpt from the log at the point of the very last 'rss' check (no more after that) :
Code: Select all
2009-09-30 03:02:00,046::DEBUG::[RSS] Running feedparser on http://server:82/myepisodesrss.ashx
2009-09-30 03:02:00,780::DEBUG::[RSS] Done parsing http://server:82/myepisodesrss.ashx
2009-09-30 03:02:00,780::INFO::[RSS] RSS Feed was empty: http://server:82/myepisodesrss.ashx
2009-09-30 03:04:00,780::INFO::[sabnzbd] Saving data for rss_data.sab in c:\sabnzbd\SABnzbd-0.4.11\cache\rss_data.sab
2009-09-30 03:04:00,780::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 03:04:01,250::DEBUG::[newzbin] No bookmarks set
2009-09-30 03:17:59,176::DEBUG::[RSS] Running feedparser on http://server:82/myepisodesrss.ashx
2009-09-30 03:17:59,878::DEBUG::[RSS] Done parsing http://server:82/myepisodesrss.ashx
2009-09-30 03:17:59,878::INFO::[RSS] RSS Feed was empty: http://server:82/myepisodesrss.ashx
2009-09-30 03:19:59,878::INFO::[sabnzbd] Saving data for rss_data.sab in c:\sabnzbd\SABnzbd-0.4.11\cache\rss_data.sab
2009-09-30 03:19:59,878::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 03:20:00,190::DEBUG::[newzbin] No bookmarks set
2009-09-30 03:32:00,051::DEBUG::[RSS] Running feedparser on http://server:82/myepisodesrss.ashx
2009-09-30 03:32:00,769::DEBUG::[RSS] Done parsing http://server:82/myepisodesrss.ashx
2009-09-30 03:32:00,769::INFO::[RSS] RSS Feed was empty: http://server:82/myepisodesrss.ashx
2009-09-30 03:34:00,769::INFO::[sabnzbd] Saving data for rss_data.sab in c:\sabnzbd\SABnzbd-0.4.11\cache\rss_data.sab
2009-09-30 03:34:00,769::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 03:34:01,065::DEBUG::[newzbin] No bookmarks set
2009-09-30 03:47:00,003::DEBUG::[RSS] Running feedparser on http://server:82/myepisodesrss.ashx
2009-09-30 03:47:43,910::DEBUG::[RSS] Done parsing http://server:82/myepisodesrss.ashx
2009-09-30 03:47:43,910::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 03:47:46,394::WARNING::[newzbin] Newzbin has a server problem (500).
2009-09-30 04:02:00,051::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 04:02:00,346::DEBUG::[newzbin] No bookmarks set
2009-09-30 04:17:00,096::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 04:17:00,410::DEBUG::[newzbin] No bookmarks set
2009-09-30 04:32:00,003::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 04:32:00,332::DEBUG::[newzbin] No bookmarks set
2009-09-30 04:47:00,065::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 04:47:00,503::DEBUG::[newzbin] No bookmarks set
2009-09-30 05:02:00,082::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 05:02:03,301::DEBUG::[newzbin] No bookmarks set
2009-09-30 05:17:00,065::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 05:17:00,362::DEBUG::[newzbin] No bookmarks set
2009-09-30 05:32:00,019::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 05:32:00,378::DEBUG::[newzbin] No bookmarks set
2009-09-30 05:47:00,051::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 05:47:00,394::DEBUG::[newzbin] No bookmarks set
2009-09-30 06:02:00,003::INFO::[newzbin] Fetching Newzbin bookmarks
2009-09-30 06:02:00,301::DEBUG::[newzbin] No bookmarks set
2009-09-30 06:17:00,003::INFO::[newzbin] Fetching Newzbin bookmarks
- you can see that after the '500' error in the log, there are no more checks against the RSS feed, but bookmarks continue to work.... odd huh ? As I stated above, the RSS checking always stops working after this point and I have to manually shutdown sabnzbd / restart it again to get them working - it does sound like the scheduler got a bit knackered ;-)
Cheers
catbert
Re: RSS Thread stops working
I assume that there was no syntax error involved, hence no file.catbert wrote: There's no 'sabnzbd.exe.log' file in my directory (it's running as a service with admin rights so I'm not sure why that file didn't get generated).
The error message definitely comes from the bookmark scan (line 310).
The returns are all OK.
So far, I have no idea why it influences the RSS feed scan.
I'll keep looking. Running my own test now.
PS:
You might be interested in pre-releases of 0.5.0.
The involved code is quite different and I would like to know your results with it.
You can sign-up in the "Beta Releases" board.
Re: RSS Thread stops working
I just noticed in the log, that the line :
- message was never written out to the log after the newzbin error - could the issue be there ? The feed comes from a server on my local network - but it appears that there were no issues with the machine at that point.
Also - the logs just before the 'newzbin has a problem' message show :
those last two lines happen at *EXACTLY* the same time - another hint of a thread issue possibly ? The feed schedule and the bookmarks schedule were set approximately 5 minutes apart so I'm not sure why they both happened at the same time ? wish I knew a little more about python now !
Cheers
catbert
Code: Select all
::INFO::[RSS] RSS Feed was empty: http://server:82/myepisodesrss.ashx
Also - the logs just before the 'newzbin has a problem' message show :
Code: Select all
2009-09-30 03:47:00,003::DEBUG::[RSS] Running feedparser on http://server:82/myepisodesrss.ashx
2009-09-30 03:47:43,910::DEBUG::[RSS] Done parsing http://server:82/myepisodesrss.ashx
2009-09-30 03:47:43,910::INFO::[newzbin] Fetching Newzbin bookmarks
Cheers
catbert
Re: RSS Thread stops working
Ooh - thanks for that - I'll sign up later tonight !PS:
You might be interested in pre-releases of 0.5.0.
The involved code is quite different and I would like to know your results with it.
You can sign-up in the "Beta Releases" board.
Re: RSS Thread stops working
Just added you to the Release group, no need to sign up.
BTW: the Alpha5 is quite old, you may want to wait for Alpha6 (hopefully coming weekend).
The logging library should be thread-safe, otherwise we would have more problems.
BTW: the Alpha5 is quite old, you may want to wait for Alpha6 (hopefully coming weekend).
The logging library should be thread-safe, otherwise we would have more problems.