SABnzbd Forums


http://45.79.196.47/

sabnzbd 0.7.3 service needs restarted periodically

http://45.79.196.47/viewtopic.php?t=11717

Page 1 of 1

sabnzbd 0.7.3 service needs restarted periodically

Posted: September 12th, 2012, 2:58 pm
by thomasmaerz
Ubuntu Server 12.04 x64
Sabnzbd is installed as a service...

I've noticed this bug before... this time I decided to document it and submit a bug report. At 3 AM-ish last night, it just stopped doing anything. It appeared to be still running when I checked it, but the web interface wasn't loading, and I looked at the RRD graphs on my pfSense router and there was no traffic coming in, so I restarted the service:

Code: Select all

niggaplz@media-PC:/mnt/raid$ sudo service sabnzbdplus status
 * SABnzbd+ binary newsgrabber: running (pid 5608)
niggaplz@media-PC:/mnt/raid$ sudo service sabnzbdplus restart
 * Stopping SABnzbd+ binary newsgrabber [ OK ]
 * Starting SABnzbd+ binary newsgrabber [ OK ]
And it came back up...
Here's the relevent information from this period of my log: (with +debug)

Code: Select all

2012-09-12 02:59:05,648::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_CgUs3A removed
2012-09-12 02:59:05,648::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_d89xpD removed
2012-09-12 02:59:05,649::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_2Iv7ae removed
2012-09-12 02:59:05,649::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_MJHNW9 removed
2012-09-12 02:59:05,649::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_CoGRYX removed
2012-09-12 02:59:05,649::INFO::[__init__:884] /home/niggaplz/Downloads/incomplete/Butterfly Effect 2004 German 720p BluRay x264 DETAiLS/__ADMIN__/SABnzbd_nzf_nMHNMd removed
2012-09-12 02:59:05,649::INFO::[postproc:84] Saving postproc queue
2012-09-12 02:59:05,649::INFO::[__init__:895] Saving data for postproc1.sab in /home/niggaplz/.sabnzbd/admin/postproc1.sab
2012-09-12 02:59:05,650::INFO::[downloader:243] Post-processing finished, resuming download
2012-09-12 14:42:28,117::WARNING::[__init__:165] Signal 15 caught, saving and exiting...
2012-09-12 14:42:28,118::INFO::[nzbqueue:176] Saving queue
2012-09-12 14:42:28,295::INFO::[__init__:895] Saving data for queue9.sab in /home/niggaplz/.sabnzbd/admin/queue9.sab
2012-09-12 14:42:28,295::INFO::[__init__:895] Saving data for totals9.sab in /home/niggaplz/.sabnzbd/admin/totals9.sab
2012-09-12 14:42:28,311::INFO::[__init__:895] Saving data for rss_data.sab in /home/niggaplz/.sabnzbd/admin/rss_data.sab
2012-09-12 14:42:28,311::INFO::[__init__:895] Saving data for bookmarks.sab in /home/niggaplz/.sabnzbd/admin/bookmarks.sab
2012-09-12 14:42:28,311::INFO::[__init__:895] Saving data for watched_data.sab in /home/niggaplz/.sabnzbd/admin/watched_data.sab
2012-09-12 14:42:28,311::INFO::[postproc:84] Saving postproc queue
2012-09-12 14:42:28,311::INFO::[__init__:895] Saving data for postproc1.sab in /home/niggaplz/.sabnzbd/admin/postproc1.sab
2012-09-12 14:42:31,216::INFO::[sabnzbdplus:1245] --------------------------------
2012-09-12 14:42:31,216::INFO::[sabnzbdplus:1246] sabnzbdplus-0.7.3 (rev=e24aedc6acf1e477887a115b9a423838bdb19172)
2012-09-12 14:42:31,217::INFO::[sabnzbdplus:1258] Platform = posix
2012-09-12 14:42:31,217::INFO::[sabnzbdplus:1259] Python-version = 2.7.3 (default, Aug  1 2012, 05:14:39) 
[GCC 4.6.3]
2012-09-12 14:42:31,217::INFO::[sabnzbdplus:1260] Arguments = /usr/bin/sabnzbdplus --daemon --server 0.0.0.0:9999
2012-09-12 14:42:31,217::INFO::[sabnzbdplus:1273] Read INI file /home/niggaplz/.sabnzbd/sabnzbd.ini
2012-09-12 14:42:31,219::INFO::[__init__:919] Loading data for bookmarks.sab from /home/niggaplz/.sabnzbd/admin/bookmarks.sab
2012-09-12 14:42:31,220::INFO::[__init__:919] Loading data for rss_data.sab from /home/niggaplz/.sabnzbd/admin/rss_data.sab
2012-09-12 14:42:31,221::INFO::[__init__:919] Loading data for totals9.sab from /home/niggaplz/.sabnzbd/admin/totals9.sab
2012-09-12 14:42:31,221::INFO::[postproc:90] Loading postproc queue
2012-09-12 14:42:31,222::INFO::[__init__:919] Loading data for postproc1.sab from /home/niggaplz/.sabnzbd/admin/postproc1.sab
2012-09-12 14:42:31,222::INFO::[__init__:919] Loading data for queue9.sab from /home/niggaplz/.sabnzbd/admin/queue9.sab
2012-09-12 14:42:31,328::INFO::[__init__:919] Loading data for watched_data.sab from /home/niggaplz/.sabnzbd/admin/watched_data.sab
2012-09-12 14:42:31,328::INFO::[downloader:208] Resuming
2012-09-12 14:42:31,328::INFO::[__init__:318] All processes started
2012-09-12 14:42:31,329::INFO::[sabnzbdplus:334] Web dir is /usr/share/sabnzbdplus/interfaces/Plush
2012-09-12 14:42:31,329::INFO::[sabnzbdplus:334] Web dir is /usr/share/sabnzbdplus/interfaces/Config
2012-09-12 14:42:31,345::INFO::[sabnzbdplus:450] _yenc module... found!
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:458] par2 binary... found (/usr/bin/par2)
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:466] unrar binary... found (/usr/bin/unrar)
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:471] unzip binary... found (/usr/bin/unzip)
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:477] nice binary... found (/usr/bin/nice)
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:481] ionice binary... found (/usr/bin/ionice)
2012-09-12 14:42:31,346::INFO::[sabnzbdplus:486] pyOpenSSL... found (True)
2012-09-12 14:42:31,348::INFO::[sabnzbdplus:1456] Starting web-interface on 0.0.0.0:9999
2012-09-12 14:42:31,351::INFO::[_cplogging:55] [12/Sep/2012:14:42:31] ENGINE Bus STARTING
2012-09-12 14:42:31,358::INFO::[_cplogging:55] [12/Sep/2012:14:42:31] ENGINE Started monitor thread '_TimeoutMonitor'.
2012-09-12 14:42:31,587::INFO::[_cplogging:55] [12/Sep/2012:14:42:31] ENGINE Serving on 0.0.0.0:9999
2012-09-12 14:42:31,588::INFO::[_cplogging:55] [12/Sep/2012:14:42:31] ENGINE Bus STARTED
2012-09-12 14:42:31,590::INFO::[notifier:87] Sending registration to localhost:23053
2012-09-12 14:42:32,089::INFO::[sabnzbdplus:1525] Starting sabnzbdplus-0.7.3
2012-09-12 14:42:32,092::INFO::[dirscanner:265] Dirscanner starting up
2012-09-12 14:42:32,095::INFO::[urlgrabber:77] URLGrabber starting up
2012-09-12 14:42:33,125::INFO::[downloader:375] 1@ssl-us.astraweb.com:563: Initiating connection
2012-09-12 14:42:33,218::INFO::[downloader:375] 2@ssl-us.astraweb.com:563: Initiating connection
2012-09-12 14:42:33,221::INFO::[downloader:375] 3@ssl-us.astraweb.com:563: Initiating connection
2012-09-12 14:42:34,646::INFO::[downloader:566] Connecting 2@ssl-us.astraweb.com:563 finished
2012-09-12 14:42:34,648::INFO::[downloader:566] Connecting 1@ssl-us.astraweb.com:563 finished
2012-09-12 14:42:34,648::INFO::[downloader:566] Connecting 3@ssl-us.astraweb.com:563 finished
2012-09-12 14:43:28,906::INFO::[__init__:895] Saving data for totals9.sab in /home/niggaplz/.sabnzbd/admin/totals9.sab
2012-09-12 14:43:28,907::INFO::[assembler:87] Decoding /home/niggaplz/Downloads/incomplete/The Victim 2011 720p BluRay AC3 5 1 x264 AXED/050912_21_20_38.rar yenc
2012-09-12 14:44:21,775::INFO::[__init__:895] Saving data for totals9.sab in /home/niggaplz/.sabnzbd/admin/totals9.sab
EDIT: Sorry, here's the required bug report information:

Version: 0.7.3
OS: Ubuntu Server 12.04
Install-type: Repository
Skin (if applicable): Plush
Firewall Software: None
Are you using IPV6? No
Is the issue reproducible? Yes and no, happens on its own periodically/intermittently. I will post logs and details on each occurrence along with any other information someone might find relevant or helpful.

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 12th, 2012, 3:02 pm
by shypike
WARNING::[__init__:165] Signal 15 caught, saving and exiting...
Something is sending a SIGTERM signal to SABnzbd and being a good citizen, it obeys.

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 12th, 2012, 5:02 pm
by thomasmaerz
shypike wrote:WARNING::[__init__:165] Signal 15 caught, saving and exiting...
Something is sending a SIGTERM signal to SABnzbd and being a good citizen, it obeys.
If you look at the timestamps, you'll see that happened at 14:42... when I restarted the sabnzbdplus service. The sigterm came from me (indirectly). If you look right above that line, you'll see that the last thing that happened was at 3AM... it sat unresponsive and not downloading anything from 3AM to almost 3PM.

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 16th, 2012, 8:59 pm
by thomasmaerz
I just caught it crashing again, this time with a different error:

Code: Select all

2012-09-16 20:40:20,557::ERROR::[_cplogging:55] [16/Sep/2012:20:40:20] ENGINE Error in HTTP server: shutting down
Traceback (most recent call last):
  File "/usr/share/sabnzbdplus/cherrypy/process/servers.py", line 75, in _start_http_thread
  File "/usr/share/sabnzbdplus/cherrypy/wsgiserver/__init__.py", line 1655, in start
    self.tick()
  File "/usr/share/sabnzbdplus/cherrypy/wsgiserver/__init__.py", line 1703, in tick
    s, addr = self.socket.accept()
  File "<string>", line 4, in accept
  File "/usr/lib/python2.7/socket.py", line 202, in accept
error: [Errno 24] Too many open files

2012-09-16 20:40:20,557::INFO::[_cplogging:55] [16/Sep/2012:20:40:20] ENGINE Bus STOPPING
2012-09-16 20:40:38,534::INFO::[_cplogging:55] [16/Sep/2012:20:40:38] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 9999)) shut down
2012-09-16 20:40:38,582::INFO::[_cplogging:55] [16/Sep/2012:20:40:38] ENGINE Stopped thread '_TimeoutMonitor'.
2012-09-16 20:40:38,583::INFO::[_cplogging:55] [16/Sep/2012:20:40:38] ENGINE Bus STOPPED
2012-09-16 20:40:38,583::INFO::[_cplogging:55] [16/Sep/2012:20:40:38] ENGINE Bus EXITING
2012-09-16 20:40:38,583::INFO::[_cplogging:55] [16/Sep/2012:20:40:38] ENGINE Bus EXITED
2012-09-16 20:55:35,758::WARNING::[__init__:165] Signal 15 caught, saving and exiting...
2012-09-16 20:55:47,156::INFO::[_cplogging:55] [16/Sep/2012:20:55:47] ENGINE Bus STARTING
2012-09-16 20:55:47,179::INFO::[_cplogging:55] [16/Sep/2012:20:55:47] ENGINE Started monitor thread '_TimeoutMonitor'.
2012-09-16 20:55:47,381::INFO::[_cplogging:55] [16/Sep/2012:20:55:47] ENGINE Serving on 0.0.0.0:9999
2012-09-16 20:55:47,381::INFO::[_cplogging:55] [16/Sep/2012:20:55:47] ENGINE Bus STARTED
That signal 15 is from me logging into webmin and restarting the service.

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 17th, 2012, 12:42 am
by sander
Possibly http://wiki.sabnzbd.org/faq#toc33 ? See check method there.

And: what kind of device are you running this? How much RAM?

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 18th, 2012, 10:36 am
by thomasmaerz
sander wrote:Possibly http://wiki.sabnzbd.org/faq#toc33 ? See check method there.

Code: Select all

niggaplz@media-PC:~$ netstat -apon | grep -e :8080 -e :9999
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:9999            0.0.0.0:*               LISTEN      7692/python      off (0.00/0/0)
tcp        0   1138 192.168.11.200:9999     192.168.11.203:49400    ESTABLISHED 7692/python      on (0.21/0/0)
tcp        0      0 192.168.11.200:9999     192.168.11.203:49649    TIME_WAIT   -                timewait (22.47/0/0)
tcp        0      0 192.168.11.200:9999     192.168.11.203:49658    TIME_WAIT   -                timewait (37.05/0/0)
tcp        0      0 192.168.11.200:9999     192.168.11.203:49394    ESTABLISHED 7692/python      off (0.00/0/0)
tcp        0      0 192.168.11.200:9999     192.168.11.203:49650    TIME_WAIT   -                timewait (22.46/0/0)
sander wrote:And: what kind of device are you running this? How much RAM?

Code: Select all

niggaplz@media-PC:~$ cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 16
model           : 6
model name      : AMD Athlon(tm) II X2 240 Processor
stepping        : 2
cpu MHz         : 800.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 5
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm 3dnowext 3dnow constant_tsc rep_good nopl nonstop_tsc extd_apicid pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt npt lbrv svm_lock nrip_save
bogomips        : 5600.18
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

processor       : 1
vendor_id       : AuthenticAMD
cpu family      : 16
model           : 6
model name      : AMD Athlon(tm) II X2 240 Processor
stepping        : 2
cpu MHz         : 2800.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 1
cpu cores       : 2
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 5
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm 3dnowext 3dnow constant_tsc rep_good nopl nonstop_tsc extd_apicid pni monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt npt lbrv svm_lock nrip_save
bogomips        : 5600.13
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

Code: Select all

niggaplz@media-PC:~$ cat /proc/meminfo
MemTotal:        3791636 kB
MemFree:          734636 kB
Buffers:           26628 kB
Cached:          1479788 kB
SwapCached:        40460 kB
Active:          1819104 kB
Inactive:        1031828 kB
Active(anon):    1054736 kB
Inactive(anon):   292384 kB
Active(file):     764368 kB
Inactive(file):   739444 kB
Unevictable:          68 kB
Mlocked:              68 kB
SwapTotal:       3929084 kB
SwapFree:        3857212 kB
Dirty:                44 kB
Writeback:             0 kB
AnonPages:       1318548 kB
Mapped:            57344 kB
Shmem:              2604 kB
Slab:              84780 kB
SReclaimable:      59728 kB
SUnreclaim:        25052 kB
KernelStack:        2352 kB
PageTables:        20232 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     5824900 kB
Committed_AS:    1617272 kB
VmallocTotal:   34359738367 kB
VmallocUsed:      319916 kB
VmallocChunk:   34359415292 kB
HardwareCorrupted:     0 kB
AnonHugePages:         0 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:     2731584 kB
DirectMap2M:     1200128 kB
DirectMap1G:           0 kB

Code: Select all

Operating System
----------------

-Version-
Kernel          : Linux 3.2.0-30-generic (x86_64)
Compiled                : #48-Ubuntu SMP Fri Aug 24 16:52:48 UTC 2012
C Library               : Unknown
Default C Compiler              : GNU C Compiler version 4.6.3 (Ubuntu/Linaro 4.6.3-1ubuntu5)
Distribution            : Ubuntu 12.04.1 LTS
-Current Session-
Computer Name           : media-PC
User Name               : niggaplz (niggaplz)
Home Directory          : /home/niggaplz
Desktop Environment             : Terminal
-Misc-
Uptime          : 2 days, 14 hours and 40 minutes
Load Average            : 1.83, 3.10, 3.63

Code: Select all

Filesystems
-----------

-Mounted File Systems-
/dev/sdg1       /       18.40 % (120.2 GiB of 147.3 GiB)
udev    /dev    0.00 % (1.8 GiB of 1.8 GiB)
tmpfs   /run    0.15 % (739.4 MiB of 740.6 MiB)
none    /run/lock       0.00 % (5.0 MiB of 5.0 MiB)
none    /run/shm        0.00 % (1.8 GiB of 1.8 GiB)
/dev/md127      /mnt/raid       7.29 % (17270.1 GiB of 18628.9 GiB)

Code: Select all

Storage
-------

-SCSI Disks-
ATA SAMSUNG HD204UI
ATA SAMSUNG HD204UI
ATA SAMSUNG HD204UI
ATA SAMSUNG HD204UI
ATA SAMSUNG HD204UI
ATA SAMSUNG HD204UI
ATA HDS722516VLSA80
ATA WDC WD20EARS-00M
ATA Hitachi HDS72302
ATA ST32000542AS
ATA Hitachi HDS72202
ATA ST32000542AS

Re: sabnzbd 0.7.3 service needs restarted periodically

Posted: September 18th, 2012, 2:15 pm
by sander
OK, 4GB of RAM, so that isn't the problem.

Things to try:
1) Restart SABnzbd, let it run for 30 minutes or so, and run the netstat command again.
2) Restart SABnzbd, turn off HTTPS in SABnzbd, restart SABnzbd, and let it run for a day or so to see if that is stable. Reason: the cherrypy problem described in the FAQ only seems to happen with HTTPS sessions, not with HTTP
All times are UTC-05:00
Page 1 of 1

Powered by phpBB® Forum Software © phpBB Limited