SABnzbd Forums

Posted: **September 30th, 2009, 3:32 am**

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

Posted: **September 30th, 2009, 3:48 am**

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.

Posted: **September 30th, 2009, 4:18 am**

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

:

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

- 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:

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

Posted: **September 30th, 2009, 5:45 am**

catbert wrote: Anyhoo, I've just taken a look through the code (hope you don't mind me downloading via svn).

That's the very purpose of Open Source, isn't it?

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.

Posted: **September 30th, 2009, 11:30 am**

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) :

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

(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

Posted: **September 30th, 2009, 12:25 pm**

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).

I assume that there was no syntax error involved, hence no file.

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.

Posted: **September 30th, 2009, 12:28 pm**

I just noticed in the log, that the line :

Code: Select all

::INFO::[RSS] RSS Feed was empty: http://server:82/myepisodesrss.ashx

- 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 :

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

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

Posted: **September 30th, 2009, 12:30 pm**

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.

Ooh - thanks for that - I'll sign up later tonight !

Posted: **September 30th, 2009, 12:36 pm**

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.

SABnzbd Forums

RSS Thread stops working

RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working

Re: RSS Thread stops working