port zero weirdness

Report & discuss bugs found in SABnzbd
Forum rules
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.
Post Reply
User avatar
jcfp
Release Testers
Release Testers
Posts: 1032
Joined: February 7th, 2008, 12:45 pm

port zero weirdness

Post by jcfp »

Sab accepts port 0 as a valid choice, although that doesn't work for normal user and root alike. Browser based error message claims a problem with the https port (9090 in the example), which isn't the problem as it's free on the test system and doesn't mention port 0. Afterwards, the sab process doesn't return the console, ps output for the machine shows a zombie process (xdg-open) with sab as parent. Reliably reproduces with this command line (cleanly extracted 0.7.11 sources, xubuntu 12.04, no pre-existing config at the given location):

Code: Select all

$ python SABnzbd.py --https 9090 --server 127.0.0.1:0 -l2 -f /tmp/t/SABnzbd-0.7.11/empty/sab.ini
2013-04-23 00:09:54,788::INFO::[SABnzbd:1256] --------------------------------
2013-04-23 00:09:54,788::INFO::[SABnzbd:1257] SABnzbd.py-0.7.11 (rev=a50412a32751f4d1d555020dea20a2da43d6a309)
2013-04-23 00:09:54,788::INFO::[SABnzbd:1269] Platform = posix
2013-04-23 00:09:54,789::INFO::[SABnzbd:1270] Python-version = 2.7.3 (default, Aug  1 2012, 05:14:39) 
[GCC 4.6.3]
2013-04-23 00:09:54,789::INFO::[SABnzbd:1271] Arguments = SABnzbd.py --https 9090 --server 127.0.0.1:0 -l2 -f /tmp/t/SABnzbd-0.7.11/empty/sab.ini
2013-04-23 00:09:54,789::INFO::[SABnzbd:1284] Read INI file /tmp/t/SABnzbd-0.7.11/empty/sab.ini
2013-04-23 00:09:54,789::INFO::[misc:364] download_dir directory: /tmp/t/SABnzbd-0.7.11/empty/Downloads/incomplete does not exist, try to create it
2013-04-23 00:09:54,790::INFO::[__init__:928] Loading data for bookmarks.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/bookmarks.sab
2013-04-23 00:09:54,790::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/bookmarks.sab missing, trying old cache
2013-04-23 00:09:54,791::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/bookmarks.sab missing
2013-04-23 00:09:54,791::INFO::[__init__:928] Loading data for rss_data.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/rss_data.sab
2013-04-23 00:09:54,791::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/rss_data.sab missing, trying old cache
2013-04-23 00:09:54,791::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/rss_data.sab missing
2013-04-23 00:09:54,792::INFO::[__init__:928] Loading data for totals9.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/totals9.sab
2013-04-23 00:09:54,792::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/totals9.sab missing, trying old cache
2013-04-23 00:09:54,792::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/totals9.sab missing
2013-04-23 00:09:54,792::DEBUG::[bpsmeter:142] Setting default BPS meter values
2013-04-23 00:09:54,794::INFO::[postproc:90] Loading postproc queue
2013-04-23 00:09:54,794::INFO::[__init__:928] Loading data for postproc1.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/postproc1.sab
2013-04-23 00:09:54,794::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/postproc1.sab missing, trying old cache
2013-04-23 00:09:54,794::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/postproc1.sab missing
2013-04-23 00:09:54,795::INFO::[__init__:928] Loading data for queue9.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/queue9.sab
2013-04-23 00:09:54,795::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/queue9.sab missing, trying old cache
2013-04-23 00:09:54,795::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/queue9.sab missing
2013-04-23 00:09:54,795::DEBUG::[downloader:127] Initializing downloader/decoder
2013-04-23 00:09:54,796::INFO::[__init__:928] Loading data for watched_data.sab from /tmp/t/SABnzbd-0.7.11/empty/admin/watched_data.sab
2013-04-23 00:09:54,796::INFO::[__init__:931] /tmp/t/SABnzbd-0.7.11/empty/admin/watched_data.sab missing, trying old cache
2013-04-23 00:09:54,796::INFO::[__init__:934] /tmp/t/SABnzbd-0.7.11/empty/cache/watched_data.sab missing
2013-04-23 00:09:54,797::DEBUG::[scheduler:138] Scheduling RSS interval task every 60 min (delay=52)
2013-04-23 00:09:54,797::DEBUG::[scheduler:150] Scheduling VersionCheck on day 2 at 1:31
2013-04-23 00:09:54,797::INFO::[scheduler:170] Setting schedule for midnight BPS reset
2013-04-23 00:09:54,797::INFO::[downloader:211] Resuming
2013-04-23 00:09:54,798::DEBUG::[__init__:532] PAUSED_ALL inactive
2013-04-23 00:09:54,802::INFO::[__init__:330] All processes started
2013-04-23 00:09:54,802::INFO::[SABnzbd:334] Web dir is /tmp/t/SABnzbd-0.7.11/interfaces/Plush
2013-04-23 00:09:54,803::INFO::[SABnzbd:334] Web dir is /tmp/t/SABnzbd-0.7.11/interfaces/Config
2013-04-23 00:09:54,805::INFO::[SABnzbd:463] _yenc module... found!
2013-04-23 00:09:54,805::INFO::[SABnzbd:471] par2 binary... found (/usr/bin/par2)
2013-04-23 00:09:54,805::INFO::[SABnzbd:479] unrar binary... found (/usr/bin/unrar)
2013-04-23 00:09:54,805::INFO::[SABnzbd:484] unzip binary... found (/usr/bin/unzip)
2013-04-23 00:09:54,805::INFO::[SABnzbd:490] nice binary... found (/usr/bin/nice)
2013-04-23 00:09:54,805::INFO::[SABnzbd:494] ionice binary... found (/usr/bin/ionice)
2013-04-23 00:09:54,805::INFO::[SABnzbd:499] pyOpenSSL... found (True)
2013-04-23 00:09:54,844::INFO::[SABnzbd:1483] Starting web-interface on 127.0.0.1:9090
2013-04-23 00:09:54,844::INFO::[_cplogging:55] [23/Apr/2013:00:09:54] ENGINE Bus STARTING
2013-04-23 00:09:54,845::INFO::[_cplogging:55] [23/Apr/2013:00:09:54] ENGINE Started monitor thread '_TimeoutMonitor'.
2013-04-23 00:09:59,960::ERROR::[_cplogging:55] [23/Apr/2013:00:09:59] ENGINE Error in 'start' listener <bound method ServerAdapter.start of <cherrypy.process.servers.ServerAdapter object at 0x2aadb50>>
Traceback (most recent call last):
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/wspbus.py", line 147, in publish
    output.append(listener(*args, **kwargs))
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 62, in start
    self.wait()
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 103, in wait
    wait_for_occupied_port(host, port)
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 275, in wait_for_occupied_port
    raise IOError("Port %r not bound on %r" % (port, host))
IOError: Port 0 not bound on '127.0.0.1'

2013-04-23 00:10:00,061::INFO::[_cplogging:55] [23/Apr/2013:00:10:00] ENGINE Serving on 127.0.0.1:9090
2013-04-23 00:10:00,062::ERROR::[_cplogging:55] [23/Apr/2013:00:10:00] ENGINE Shutting down due to error in start listener:
Traceback (most recent call last):
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/wspbus.py", line 184, in start
    self.publish('start')
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/wspbus.py", line 147, in publish
    output.append(listener(*args, **kwargs))
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 62, in start
    self.wait()
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 103, in wait
    wait_for_occupied_port(host, port)
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 275, in wait_for_occupied_port
    raise IOError("Port %r not bound on %r" % (port, host))
IOError: Port 0 not bound on '127.0.0.1'

2013-04-23 00:10:00,063::INFO::[_cplogging:55] [23/Apr/2013:00:10:00] ENGINE Bus STOPPING
2013-04-23 00:10:01,066::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('127.0.0.1', 9090)) shut down
2013-04-23 00:10:01,066::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('127.0.0.1', 0)) already shut down
2013-04-23 00:10:01,069::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE Stopped thread '_TimeoutMonitor'.
2013-04-23 00:10:01,069::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE Bus STOPPED
2013-04-23 00:10:01,069::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE Bus EXITING
2013-04-23 00:10:01,069::INFO::[_cplogging:55] [23/Apr/2013:00:10:01] ENGINE Bus EXITED
2013-04-23 00:10:01,070::ERROR::[SABnzbd:1498] Failed to start web-interface: 
Traceback (most recent call last):
  File "SABnzbd.py", line 1490, in main
    cherrypy.engine.start()
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/wspbus.py", line 184, in start
    self.publish('start')
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/wspbus.py", line 147, in publish
    output.append(listener(*args, **kwargs))
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 62, in start
    self.wait()
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 103, in wait
    wait_for_occupied_port(host, port)
  File "/tmp/t/SABnzbd-0.7.11/cherrypy/process/servers.py", line 275, in wait_for_occupied_port
    raise IOError("Port %r not bound on %r" % (port, host))
IOError: Port 0 not bound on '127.0.0.1'
2013-04-23 00:10:01,071::ERROR::[SABnzbd:303] Failed to start web-interface : Port 0 not bound on '127.0.0.1'
2013-04-23 00:10:01,071::INFO::[panic:247] Lauching browser with /tmp/tmpvh808T.html
2013-04-23 00:10:01,076::INFO::[__init__:366] SABnzbd shutting down...
2013-04-23 00:10:01,076::INFO::[__init__:904] Saving data for bookmarks.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/bookmarks.sab
2013-04-23 00:10:01,077::DEBUG::[__init__:373] Stopping URLGrabber
2013-04-23 00:10:01,077::INFO::[urlgrabber:72] URLGrabber shutting down
2013-04-23 00:10:01,077::DEBUG::[__init__:380] Stopping Newzbin-Grabber
2013-04-23 00:10:01,077::DEBUG::[__init__:387] Stopping dirscanner
2013-04-23 00:10:01,077::INFO::[__init__:904] Saving data for watched_data.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/watched_data.sab
2013-04-23 00:10:01,078::INFO::[dirscanner:265] Dirscanner shutting down
2013-04-23 00:10:01,078::DEBUG::[__init__:396] Stopping downloader
2013-04-23 00:10:01,078::DEBUG::[notifier:112] Sending registration to localhost:23053
2013-04-23 00:10:01,079::DEBUG::[notifier:102] Checking icon
2013-04-23 00:10:01,080::DEBUG::[notifier:219] To : localhost:23053 <<class 'gntp.GNTPRegister'>>
2013-04-23 00:10:01,080::DEBUG::[growler:171] Cannot register with Growl [Errno 111] Connection refused
2013-04-23 00:10:01,579::INFO::[growler:267] Send to NotifyOSD: SABnzbd / Shutting down
2013-04-23 00:10:01,588::DEBUG::[__init__:399] Stopping assembler
2013-04-23 00:10:01,588::DEBUG::[__init__:406] Stopping postprocessor
2013-04-23 00:10:01,588::INFO::[postproc:84] Saving postproc queue
2013-04-23 00:10:01,588::INFO::[__init__:904] Saving data for postproc1.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/postproc1.sab
2013-04-23 00:10:01,589::INFO::[nzbqueue:211] Saving queue
2013-04-23 00:10:01,589::INFO::[__init__:904] Saving data for queue9.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/queue9.sab
2013-04-23 00:10:01,589::INFO::[__init__:904] Saving data for rss_data.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/rss_data.sab
2013-04-23 00:10:01,590::INFO::[__init__:904] Saving data for bookmarks.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/bookmarks.sab
2013-04-23 00:10:01,590::INFO::[__init__:904] Saving data for watched_data.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/watched_data.sab
2013-04-23 00:10:01,590::INFO::[postproc:84] Saving postproc queue
2013-04-23 00:10:01,590::INFO::[__init__:904] Saving data for postproc1.sab in /tmp/t/SABnzbd-0.7.11/empty/admin/postproc1.sab
2013-04-23 00:10:01,590::DEBUG::[scheduler:227] Terminating scheduler
2013-04-23 00:10:01,591::INFO::[__init__:426] All processes stopped
[hangs forever]
Probably best to simply refuse port 0 and reset to the default port instead. Negative and impossibly high ports don't cause issues.
Top
Post Reply

Return to “Bug Reports”