Regular Crashes: Fatal Python error: GC object already tracked

[hotzenpl0tz]

Hi, I am having problems with Sabnzbdplus from the unofficial Ubuntu repository.

apt-cache policy sabnzbdplus
sabnzbdplus:
  Installiert: 0.4.4-0ubuntu1~jcfp1~intrepid
  Kandidat: 0.4.4-0ubuntu1~jcfp1~intrepid
  Versions-Tabelle:
*** 0.4.4-0ubuntu1~jcfp1~intrepid 0
        500 http://ppa.launchpad.net intrepid/main Packages
        100 /var/lib/dpkg/status

The programm crashes regularly, but I don't think there is a special trigger like par2 check, unrar or anything - it happens when it is downloading. I am using 4 threads, set a cache value of 50M in the webinterface but other than that, nothing special I believe. I wrote a small watchdog that restarts the server if it goes down, but still this can get quite annoying. Any insights on what I could do to troubleshoot ? The error log only shows the message: Fatal Python error: GC object already tracked.
Something going wrong with some C-library ?

Thanks.

[shypike]

It's the first time anyone reports this.
When I look up this error message on the Web, it's always related to errors
in Python libraries written in C.
Since we haven't written any such library (but do use quite a few) it cannot
be a problem in SABnzbd as such.
However, some special situation may trigger it anyway.

Maybe you can send some SABnzbd logging about this problem.
Maybe we can get some info from it.

[hotzenpl0tz]

I would be very willing to do anything I can do debug this, but the logfiles are quite sparse. I only get the mentioned error message in the error.log - the normal log doesn't show anything odd when it crashes, up to now it was always just downloading some usenet post when it crashed. Is there a way to increase the logging that is being done ?

[shypike]

First set logging level (Connections page) to "debug".
Does error log contain a time stamp, so that we can relate it to the normal logging?

You say it crashes, does it stop working altogether?
If not, what stops working?

[hotzenpl0tz]

Ok, I set the loglevel to debug - since this can take fomr 2 to 8 hours, let's see when a crash occurs

To answer your questions: no, there is no time stamp. But since the daemon totally crashes (ps aux doesn't show a running sabnzbdplus process) I think you could probably relate it to the last lines of the log. I deactivated my watchdog script so I will can post the last lines of the log, now I have to find soemthing to keep the server busy

[hotzenpl0tz]

Hm, now it crashed - unfortunately there isn't anything noteworthy in the last 100 lines of the log:
http://rafb.net/p/apGGV998.html

the .error log shows the same error again.

tail -n 10 /home/user/.sabnzbd/logs/sabnzbd.error.log (cleaned the log before to be sure the error comes up when it crashes)
Fatal Python error: GC object already tracked

Hm, not sure what else I could try, short of not using the Ubuntu archive and seeing if that makes a difference ? Probably some weird threading bug in one of the used libraries, strange that I am the only one who has the error. Cpu is nothing special, AMD64 3000+ singlecore.

[shypike]

Bad luck.
It stops in the middle of downloading.
I see you are using SSL connections to the news-server, so the suspect is the pyopenssl package.

Can you try without using SSL?
Which version of pyopenssl are you using? Is there an alternative version?

[hotzenpl0tz]

Hm, I am using:
python-openssl:
  Installiert: 0.7-2
  Kandidat: 0.7-2
  Versions-Tabelle:
*** 0.7-2 0
        500 http://de.archive.ubuntu.com intrepid/main Packages
        100 /var/lib/dpkg/status

There doesn't seem to be an official alternative, have to see if there is a package with a different version somewhere that doesn't break anything with my python installation. Haven't had the time yet to try without ssl, hope to do that this evening or tomorrow.

[switch]

Could you please try the following:
Open newswrapper.py in the sabnzbd folder
change line 100 from

Code: Select all

self.sock = SSLConnection(ctx, socket.socket(af, socktype, proto))

to:

Code: Select all

self.sock = _ssl.tsafe.Connection(ctx, socket.socket(af, socktype, proto))

[hotzenpl0tz]

Just tried that, but that gives me the following in the log:

Last warnings (clear)
2008-10-26 18:45:26,029 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:45:26,029 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:45:26,032 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:45:26,032 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:45:26,035 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:45:26,036 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:45:26,039 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:45:26,039 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:47:26,053 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:47:26,053 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:47:26,056 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:47:26,056 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:47:26,059 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:47:26,059 WARNING [downloader] Thread [email protected]:563: failed to initialize
2008-10-26 18:47:26,062 ERROR [downloader] Failed to initialize [email protected]:563
2008-10-26 18:47:26,062 WARNING [downloader] Thread [email protected]:563: failed to initialize

This is the file now:
...
if sslenabled and _ssl:
            ctx = _ssl.Context(_ssl.SSLv23_METHOD)
            #self.sock = SSLConnection(ctx, socket.socket(af, socktype, proto))
            self.sock = _ssl.tsafe.Connection(ctx, socket.socket(af, socktype, proto))
        elif sslenabled and not _ssl:
            logging.error("[%s] Error importing OpenSSL module. Connecting with NON-SSL", __NAME__)
            self.sock = socket.socket(af, socktype, proto)
        else:
            self.sock = socket.socket(af, socktype, proto)
...

[switch]

Hmm, can you enter the following into a terminal:

Code: Select all

python
from OpenSSL import tsafe
tsafe.Connection
exit()

and just tell me if you get any errors?

[hotzenpl0tz]

This is what happened:

Python 2.5.2 (r252:60911, Oct  5 2008, 19:12:49)
[GCC 4.3.2] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> from OpenSSL import tsafe
>>> tsafe.Connection

>>> exit()

[hotzenpl0tz]

Ok, I can now pretty much confirm that SSL Downloads are the problem. If I turn off ssl, then there are no more crashes. Not really a solution for me, so for the moment I am going to stay with my watchdog script )
I am willing to do tests though if there are any code changes.