def finish_connect(self, code):
if not (self.server.username or self.server.password
or self.force_login):
self.connected = True
self.user_sent = True
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
if code == 501 and self.user_sent:
# Change to a sensible text
code = 481
self.data[0] = "%d %s" % (
code, T("Authentication failed, check username/password."))
self.user_ok = True
self.pass_sent = True
if code == 480:
self.force_login = True
self.connected = False
self.user_sent = False
self.user_ok = False
self.pass_sent = False
self.pass_ok = False
if code in (400, 502):
raise NNTPPermanentError(nntp_to_msg(self.data))
elif not self.user_sent:
command = utob("authinfo user %s\r\n" % self.server.username)
self.nntp.sock.sendall(command)
self.data = []
self.user_sent = True
elif not self.user_ok:
if code == 381:
self.user_ok = True
elif code == 281:
# No login required
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
self.connected = True
if self.user_ok and not self.pass_sent:
command = utob("authinfo pass %s\r\n" % self.server.password)
self.nntp.sock.sendall(command)
self.data = []
self.pass_sent = True
elif self.user_ok and not self.pass_ok:
if code != 281:
# Assume that login failed (code 481 or other)
raise NNTPPermanentError(nntp_to_msg(self.data))
else:
self.connected = True
self.timeout = time.time() + self.server.timeout
def finish_connect(self, code):
if not (self.server.username or self.server.password
or self.force_login):
self.connected = True
self.user_sent = True
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
if code in ('501', ) and self.user_sent:
# Change to a sensible text
code = '481'
self.data[0] = T('Authentication failed, check username/password.')
self.user_ok = True
self.pass_sent = True
if code == '480':
self.force_login = True
self.connected = False
self.user_sent = False
self.user_ok = False
self.pass_sent = False
self.pass_ok = False
if code in ('400', '502'):
raise NNTPPermanentError(nntp_to_msg(self.data))
elif not self.user_sent:
command = 'authinfo user %s\r\n' % self.server.username
self.nntp.sock.sendall(command)
self.data = []
self.user_sent = True
elif not self.user_ok:
if code == '381':
self.user_ok = True
elif code == '281':
# No login required
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
self.connected = True
if self.user_ok and not self.pass_sent:
command = 'authinfo pass %s\r\n' % self.server.password
self.nntp.sock.sendall(command)
self.data = []
self.pass_sent = True
elif self.user_ok and not self.pass_ok:
if code != '281':
# Assume that login failed (code 481 or other)
raise NNTPPermanentError(nntp_to_msg(self.data))
else:
self.connected = True
self.timeout = time.time() + self.server.timeout
def finish_connect(self, code):
if not (self.server.username or self.server.password or self.force_login):
self.connected = True
self.user_sent = True
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
if code in ('501',) and self.user_sent:
# Change to a sensible text
code = '481'
self.data[0] = T('Authentication failed, check username/password.')
self.user_ok = True
self.pass_sent = True
if code == '480':
self.force_login = True
self.connected = False
self.user_sent = False
self.user_ok = False
self.pass_sent = False
self.pass_ok = False
if code in ('400', '502'):
raise NNTPPermanentError(nntp_to_msg(self.data))
elif not self.user_sent:
command = 'authinfo user %s\r\n' % self.server.username
self.nntp.sock.sendall(command)
self.data = []
self.user_sent = True
elif not self.user_ok:
if code == '381':
self.user_ok = True
elif code == '281':
# No login required
self.user_ok = True
self.pass_sent = True
self.pass_ok = True
self.connected = True
if self.user_ok and not self.pass_sent:
command = 'authinfo pass %s\r\n' % self.server.password
self.nntp.sock.sendall(command)
self.data = []
self.pass_sent = True
elif self.user_ok and not self.pass_ok:
if code != '281':
# Assume that login failed (code 481 or other)
raise NNTPPermanentError(nntp_to_msg(self.data))
else:
self.connected = True
self.timeout = time.time() + self.server.timeout
def run(self):
# First check IPv6 connectivity
sabnzbd.EXTERNAL_IPV6 = sabnzbd.test_ipv6()
logging.debug('External IPv6 test result: %s', sabnzbd.EXTERNAL_IPV6)
# Then have to check the quality of SSL verification
if sabnzbd.HAVE_SSL_CONTEXT:
try:
import ssl
ctx = ssl.create_default_context()
base_sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
ssl_sock = ctx.wrap_socket(base_sock,
server_hostname=cfg.selftest_host())
ssl_sock.settimeout(2.0)
ssl_sock.connect((cfg.selftest_host(), 443))
ssl_sock.close()
except:
# Seems something is still wrong
sabnzbd.set_https_verification(0)
sabnzbd.HAVE_SSL_CONTEXT = False
logging.debug('SSL verification test: %s', sabnzbd.HAVE_SSL_CONTEXT)
# Start decoders
for decoder in self.decoder_workers:
decoder.start()
# Kick BPS-Meter to check quota
BPSMeter.do.update()
while 1:
for server in self.servers:
for nw in server.busy_threads[:]:
if (nw.nntp and nw.nntp.error_msg) or (
nw.timeout and time.time() > nw.timeout):
if nw.nntp and nw.nntp.error_msg:
self.__reset_nw(nw, "", warn=False)
else:
self.__reset_nw(nw, "timed out")
server.bad_cons += 1
self.maybe_block_server(server)
if server.restart:
if not server.busy_threads:
newid = server.newid
server.stop(self.read_fds, self.write_fds)
self.servers.remove(server)
if newid:
self.init_server(None, newid)
self.__restart -= 1
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists()
# Have to leave this loop, because we removed element
break
else:
# Restart pending, don't add new articles
continue
if not server.idle_threads or server.restart or self.is_paused(
) or self.shutdown or self.delayed or self.postproc:
continue
if not server.active:
continue
for nw in server.idle_threads[:]:
if nw.timeout:
if time.time() < nw.timeout:
continue
else:
nw.timeout = None
if server.info is None:
self.maybe_block_server(server)
request_server_info(server)
break
article = sabnzbd.nzbqueue.NzbQueue.do.get_article(
server, self.servers)
if not article:
break
if server.retention and article.nzf.nzo.avg_stamp < time.time(
) - server.retention:
# Let's get rid of all the articles for this server at once
logging.info('Job %s too old for %s, moving on',
article.nzf.nzo.work_name, server.id)
while article:
self.decode(article, None, None)
article = article.nzf.nzo.get_article(
server, self.servers)
break
server.idle_threads.remove(nw)
server.busy_threads.append(nw)
nw.article = article
if nw.connected:
self.__request_article(nw)
else:
try:
logging.info("%s@%s: Initiating connection",
nw.thrdnum, server.id)
nw.init_connect(self.write_fds)
except:
logging.error(
T('Failed to initialize %s@%s with reason: %s'
), nw.thrdnum, server.id,
sys.exc_info()[1])
self.__reset_nw(nw, "failed to initialize")
# Exit-point
if self.shutdown:
empty = True
for server in self.servers:
if server.busy_threads:
empty = False
break
if empty:
# Start decoders
for decoder in self.decoder_workers:
decoder.stop()
decoder.join()
for server in self.servers:
server.stop(self.read_fds, self.write_fds)
logging.info("Shutting down")
break
if self.force_disconnect:
for server in self.servers:
for nw in server.idle_threads + server.busy_threads:
quit = nw.connected and server.active
self.__reset_nw(nw,
"forcing disconnect",
warn=False,
wait=False,
quit=quit)
# Make sure server address resolution is refreshed
server.info = None
self.force_disconnect = False
# => Select
readkeys = self.read_fds.keys()
writekeys = self.write_fds.keys()
if readkeys or writekeys:
read, write, error = select.select(readkeys, writekeys, (),
1.0)
# Why check so often when so few things happened?
if self.can_be_slowed and len(readkeys) >= 8 and len(
read) <= 2:
time.sleep(0.01)
# Need to initialize the check during first 20 seconds
if self.can_be_slowed is None or self.can_be_slowed_timer:
# Wait for stable speed to start testing
if not self.can_be_slowed_timer and BPSMeter.do.get_stable_speed(
timespan=10):
self.can_be_slowed_timer = time.time()
# Check 10 seconds after enabling slowdown
if self.can_be_slowed_timer and time.time(
) > self.can_be_slowed_timer + 10:
# Now let's check if it was stable in the last 10 seconds
self.can_be_slowed = (
BPSMeter.do.get_stable_speed(timespan=10) > 0)
self.can_be_slowed_timer = 0
logging.debug('Downloader-slowdown: %r',
self.can_be_slowed)
else:
read, write, error = ([], [], [])
BPSMeter.do.reset()
time.sleep(1.0)
DOWNLOADER_CV.acquire()
while (sabnzbd.nzbqueue.NzbQueue.do.is_empty() or self.is_paused() or self.delayed or self.postproc) and not \
self.shutdown and not self.__restart:
DOWNLOADER_CV.wait()
DOWNLOADER_CV.release()
self.force_disconnect = False
for selected in write:
nw = self.write_fds[selected]
fileno = nw.nntp.sock.fileno()
if fileno not in self.read_fds:
self.read_fds[fileno] = nw
if fileno in self.write_fds:
self.write_fds.pop(fileno)
if not read:
BPSMeter.do.update()
continue
for selected in read:
nw = self.read_fds[selected]
article = nw.article
server = nw.server
if article:
nzo = article.nzf.nzo
try:
bytes, done, skip = nw.recv_chunk()
except:
bytes, done, skip = (0, False, False)
if skip:
BPSMeter.do.update()
continue
if bytes < 1:
self.__reset_nw(nw,
"server closed connection",
warn=False,
wait=False)
continue
else:
if self.bandwidth_limit:
bps = BPSMeter.do.get_bps()
bps += bytes
limit = self.bandwidth_limit
if bps > limit:
while BPSMeter.do.get_bps() > limit:
time.sleep(0.05)
BPSMeter.do.update()
BPSMeter.do.update(server.id, bytes)
if nzo:
nzo.update_download_stats(BPSMeter.do.get_bps(),
server.id, bytes)
if not done and nw.status_code != '222':
if not nw.connected or nw.status_code == '480':
done = False
try:
nw.finish_connect(nw.status_code)
if sabnzbd.LOG_ALL:
logging.debug("%s@%s last message -> %s",
nw.thrdnum, nw.server.id,
nntp_to_msg(nw.data))
nw.clear_data()
except NNTPPermanentError, error:
# Handle login problems
block = False
penalty = 0
msg = error.response
ecode = msg[:3]
display_msg = ' [%s]' % msg
logging.debug('Server login problem: %s, %s',
ecode, msg)
if ecode in ('502', '400', '481',
'482') and clues_too_many(msg):
# Too many connections: remove this thread and reduce thread-setting for server
# Plan to go back to the full number after a penalty timeout
if server.active:
errormsg = T(
'Too many connections to server %s'
) % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T('Too many connections to server %s'
), server.id)
self.__reset_nw(nw,
None,
warn=False,
destroy=True,
quit=True)
self.plan_server(server.id,
_PENALTY_TOOMANY)
server.threads -= 1
elif ecode in ('502', '481',
'482') and clues_too_many_ip(msg):
# Account sharing?
if server.active:
errormsg = T('Probable account sharing'
) + display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
name = ' (%s)' % server.id
logging.warning(
T('Probable account sharing') +
name)
penalty = _PENALTY_SHARE
block = True
elif ecode in ('481', '482',
'381') or (ecode == '502'
and clues_login(msg)):
# Cannot login, block this server
if server.active:
errormsg = T('Failed login for server %s'
) % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.error(
T('Failed login for server %s'),
server.id)
penalty = _PENALTY_PERM
block = True
elif ecode in ('502', '482'):
# Cannot connect (other reasons), block this server
if server.active:
errormsg = T(
'Cannot connect to server %s [%s]') % (
'', display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T('Cannot connect to server %s [%s]'
), server.id, msg)
if clues_pay(msg):
penalty = _PENALTY_PERM
else:
penalty = _PENALTY_502
block = True
elif ecode == '400':
# Temp connection problem?
if server.active:
logging.debug(
'Unspecified error 400 from server %s',
server.id)
penalty = _PENALTY_VERYSHORT
block = True
else:
# Unknown error, just keep trying
if server.active:
errormsg = T(
'Cannot connect to server %s [%s]') % (
'', display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T('Cannot connect to server %s [%s]'
), server.id, msg)
penalty = _PENALTY_UNKNOWN
block = True
if block or (penalty and server.optional):
if server.active:
server.active = False
if penalty and (block or server.optional):
self.plan_server(server.id, penalty)
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists(
)
self.__reset_nw(nw,
None,
warn=False,
quit=True)
continue
except:
logging.error(
T('Connecting %s@%s failed, message=%s'),
nw.thrdnum, nw.server.id, nntp_to_msg(nw.data))
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished",
nw.thrdnum, nw.server.id)
self.__request_article(nw)
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished",
nw.thrdnum, nw.server.id)
self.__request_article(nw)
elif nw.status_code == '223':
done = True
logging.debug('Article <%s> is present',
article.article)
elif nw.status_code == '211':
done = False
logging.debug("group command ok -> %s",
nntp_to_msg(nw.data))
nw.group = nw.article.nzf.nzo.group
nw.clear_data()
self.__request_article(nw)
elif nw.status_code in ('411', '423', '430'):
done = True
logging.debug(
'Thread %s@%s: Article %s missing (error=%s)',
nw.thrdnum, nw.server.id, article.article,
nw.status_code)
nw.clear_data()
elif nw.status_code == '480':
if server.active:
server.active = False
def run(self):
# First check IPv6 connectivity
sabnzbd.EXTERNAL_IPV6 = sabnzbd.test_ipv6()
logging.debug("External IPv6 test result: %s", sabnzbd.EXTERNAL_IPV6)
# Then we check SSL certificate checking
sabnzbd.CERTIFICATE_VALIDATION = sabnzbd.test_cert_checking()
logging.debug("SSL verification test: %s", sabnzbd.CERTIFICATE_VALIDATION)
# Kick BPS-Meter to check quota
sabnzbd.BPSMeter.update()
# Check server expiration dates
check_server_expiration()
while 1:
now = time.time()
# Set Article to None so references from this
# thread do not keep the parent objects alive (see #1628)
article = None
for server in self.servers:
# Skip this server if there's no point searching for new stuff to do
if not server.busy_threads and server.next_article_search > now:
continue
for nw in server.busy_threads[:]:
if (nw.nntp and nw.nntp.error_msg) or (nw.timeout and now > nw.timeout):
if nw.nntp and nw.nntp.error_msg:
# Already showed error
self.__reset_nw(nw)
else:
self.__reset_nw(nw, "timed out", warn=True)
server.bad_cons += 1
self.maybe_block_server(server)
if server.restart:
if not server.busy_threads:
newid = server.newid
server.stop()
self.servers.remove(server)
if newid:
self.init_server(None, newid)
self.server_restarts -= 1
# Have to leave this loop, because we removed element
break
else:
# Restart pending, don't add new articles
continue
if (
not server.idle_threads
or server.restart
or self.is_paused()
or self.shutdown
or self.paused_for_postproc
or not server.active
):
continue
for nw in server.idle_threads[:]:
if nw.timeout:
if now < nw.timeout:
continue
else:
nw.timeout = None
if not server.info:
# Only request info if there's stuff in the queue
if not sabnzbd.NzbQueue.is_empty():
self.maybe_block_server(server)
server.request_info()
break
article = sabnzbd.NzbQueue.get_article(server, self.servers)
if not article:
# Skip this server for 0.5 second
server.next_article_search = now + 0.5
break
if server.retention and article.nzf.nzo.avg_stamp < now - server.retention:
# Let's get rid of all the articles for this server at once
logging.info("Job %s too old for %s, moving on", article.nzf.nzo.final_name, server.host)
while article:
self.decode(article, None)
article = article.nzf.nzo.get_article(server, self.servers)
break
server.idle_threads.remove(nw)
server.busy_threads.append(nw)
nw.article = article
if nw.connected:
self.__request_article(nw)
else:
try:
logging.info("%s@%s: Initiating connection", nw.thrdnum, server.host)
nw.init_connect()
except:
logging.error(
T("Failed to initialize %s@%s with reason: %s"),
nw.thrdnum,
server.host,
sys.exc_info()[1],
)
self.__reset_nw(nw, "failed to initialize", warn=True)
if self.force_disconnect or self.shutdown:
for server in self.servers:
for nw in server.idle_threads + server.busy_threads:
# Send goodbye if we have open socket
if nw.nntp:
self.__reset_nw(
nw,
"forcing disconnect",
wait=False,
count_article_try=False,
send_quit=True,
)
# Make sure server address resolution is refreshed
server.info = None
self.force_disconnect = False
# Exit-point
if self.shutdown:
logging.info("Shutting down")
break
# Use select to find sockets ready for reading/writing
readkeys = self.read_fds.keys()
if readkeys:
read, _, _ = select.select(readkeys, (), (), 1.0)
# Add a sleep if there are too few results compared to the number of active connections
if self.can_be_slowed and len(read) < 1 + len(readkeys) / 10:
time.sleep(self.sleep_time)
# Need to initialize the check during first 20 seconds
if self.can_be_slowed is None or self.can_be_slowed_timer:
# Wait for stable speed to start testing
if not self.can_be_slowed_timer and sabnzbd.BPSMeter.get_stable_speed(timespan=10):
self.can_be_slowed_timer = time.time()
# Check 10 seconds after enabling slowdown
if self.can_be_slowed_timer and time.time() > self.can_be_slowed_timer + 10:
# Now let's check if it was stable in the last 10 seconds
self.can_be_slowed = sabnzbd.BPSMeter.get_stable_speed(timespan=10)
self.can_be_slowed_timer = 0
logging.debug("Downloader-slowdown: %r", self.can_be_slowed)
else:
read = []
sabnzbd.BPSMeter.reset()
time.sleep(1.0)
with DOWNLOADER_CV:
while (
(sabnzbd.NzbQueue.is_empty() or self.is_paused() or self.paused_for_postproc)
and not self.shutdown
and not self.force_disconnect
and not self.server_restarts
):
DOWNLOADER_CV.wait()
if not read:
sabnzbd.BPSMeter.update()
continue
for selected in read:
nw = self.read_fds[selected]
article = nw.article
server = nw.server
try:
bytes_received, done, skip = nw.recv_chunk()
except:
bytes_received, done, skip = (0, False, False)
if skip:
sabnzbd.BPSMeter.update()
continue
if bytes_received < 1:
self.__reset_nw(nw, "server closed connection", wait=False)
continue
else:
try:
article.nzf.nzo.update_download_stats(sabnzbd.BPSMeter.bps, server.id, bytes_received)
except AttributeError:
# In case nzf has disappeared because the file was deleted before the update could happen
pass
if self.bandwidth_limit:
limit = self.bandwidth_limit
if bytes_received + sabnzbd.BPSMeter.bps > limit:
while sabnzbd.BPSMeter.bps > limit:
time.sleep(0.01)
sabnzbd.BPSMeter.update()
sabnzbd.BPSMeter.update(server.id, bytes_received)
if not done and nw.status_code != 222:
if not nw.connected or nw.status_code == 480:
done = False
try:
nw.finish_connect(nw.status_code)
if sabnzbd.LOG_ALL:
logging.debug(
"%s@%s last message -> %s", nw.thrdnum, nw.server.host, nntp_to_msg(nw.data)
)
nw.clear_data()
except NNTPPermanentError as error:
# Handle login problems
block = False
penalty = 0
msg = error.response
ecode = int_conv(msg[:3])
display_msg = " [%s]" % msg
logging.debug("Server login problem: %s, %s", ecode, msg)
if ecode in (502, 400, 481, 482) and clues_too_many(msg):
# Too many connections: remove this thread and reduce thread-setting for server
# Plan to go back to the full number after a penalty timeout
if server.active:
errormsg = T("Too many connections to server %s") % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T("Too many connections to server %s"), server.host)
# Don't count this for the tries (max_art_tries) on this server
self.__reset_nw(nw, count_article_try=False, send_quit=True)
self.plan_server(server, _PENALTY_TOOMANY)
server.threads -= 1
elif ecode in (502, 481, 482) and clues_too_many_ip(msg):
# Account sharing?
if server.active:
errormsg = T("Probable account sharing") + display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
name = " (%s)" % server.host
logging.warning(T("Probable account sharing") + name)
penalty = _PENALTY_SHARE
block = True
elif ecode in (452, 481, 482, 381) or (ecode == 502 and clues_login(msg)):
# Cannot login, block this server
if server.active:
errormsg = T("Failed login for server %s") % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.error(T("Failed login for server %s"), server.host)
penalty = _PENALTY_PERM
block = True
elif ecode in (502, 482):
# Cannot connect (other reasons), block this server
if server.active:
errormsg = T("Cannot connect to server %s [%s]") % ("", display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T("Cannot connect to server %s [%s]"), server.host, msg)
if clues_pay(msg):
penalty = _PENALTY_PERM
else:
penalty = _PENALTY_502
block = True
elif ecode == 400:
# Temp connection problem?
if server.active:
logging.debug("Unspecified error 400 from server %s", server.host)
penalty = _PENALTY_VERYSHORT
block = True
else:
# Unknown error, just keep trying
if server.active:
errormsg = T("Cannot connect to server %s [%s]") % ("", display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T("Cannot connect to server %s [%s]"), server.host, msg)
penalty = _PENALTY_UNKNOWN
block = True
if block or (penalty and server.optional):
if server.active:
server.active = False
if penalty and (block or server.optional):
self.plan_server(server, penalty)
# Note that this will count towards the tries (max_art_tries) on this server!
self.__reset_nw(nw, send_quit=True)
continue
except:
logging.error(
T("Connecting %s@%s failed, message=%s"),
nw.thrdnum,
nw.server.host,
nntp_to_msg(nw.data),
)
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw)
if nw.connected:
logging.info("Connecting %s@%s finished", nw.thrdnum, nw.server.host)
self.__request_article(nw)
elif nw.status_code == 223:
done = True
logging.debug("Article <%s> is present", article.article)
elif nw.status_code == 211:
done = False
logging.debug("group command ok -> %s", nntp_to_msg(nw.data))
nw.group = nw.article.nzf.nzo.group
nw.clear_data()
self.__request_article(nw)
elif nw.status_code in (411, 423, 430):
done = True
logging.debug(
"Thread %s@%s: Article %s missing (error=%s)",
nw.thrdnum,
nw.server.host,
article.article,
nw.status_code,
)
nw.clear_data()
elif nw.status_code == 500:
if article.nzf.nzo.precheck:
# Assume "STAT" command is not supported
server.have_stat = False
logging.debug("Server %s does not support STAT", server.host)
else:
# Assume "BODY" command is not supported
server.have_body = False
logging.debug("Server %s does not support BODY", server.host)
nw.clear_data()
self.__request_article(nw)
if done:
# Successful data, clear "bad" counter
server.bad_cons = 0
server.errormsg = server.warning = ""
if sabnzbd.LOG_ALL:
logging.debug("Thread %s@%s: %s done", nw.thrdnum, server.host, article.article)
self.decode(article, nw.data)
# Reset connection for new activity
nw.soft_reset()
server.busy_threads.remove(nw)
server.idle_threads.append(nw)
self.remove_socket(nw)
logging.error(T('Connecting %s@%s failed, message=%s'),
nw.thrdnum, nw.server.host, nntp_to_msg(nw.data))
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished", nw.thrdnum, nw.server.host)
self.__request_article(nw)
elif nw.status_code == '223':
done = True
logging.debug('Article <%s> is present', article.article)
elif nw.status_code == '211':
done = False
logging.debug("group command ok -> %s", nntp_to_msg(nw.data))
nw.group = nw.article.nzf.nzo.group
nw.clear_data()
self.__request_article(nw)
elif nw.status_code in ('411', '423', '430'):
done = True
logging.debug('Thread %s@%s: Article %s missing (error=%s)',
nw.thrdnum, nw.server.host, article.article, nw.status_code)
nw.clear_data()
elif nw.status_code == '480':
if server.active:
server.active = False
server.errormsg = T('Server %s requires user/password') % ''
self.plan_server(server, 0)
def run(self):
# First check IPv6 connectivity
sabnzbd.EXTERNAL_IPV6 = sabnzbd.test_ipv6()
logging.debug('External IPv6 test result: %s', sabnzbd.EXTERNAL_IPV6)
# Then have to check the quality of SSL verification
if sabnzbd.HAVE_SSL_CONTEXT:
try:
import ssl
ctx = ssl.create_default_context()
base_sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
ssl_sock = ctx.wrap_socket(base_sock, server_hostname=cfg.selftest_host())
ssl_sock.settimeout(2.0)
ssl_sock.connect((cfg.selftest_host(), 443))
ssl_sock.close()
except:
# Seems something is still wrong
sabnzbd.set_https_verification(0)
sabnzbd.HAVE_SSL_CONTEXT = False
logging.debug('SSL verification test: %s', sabnzbd.HAVE_SSL_CONTEXT)
# Start decoders
for decoder in self.decoder_workers:
decoder.start()
# Kick BPS-Meter to check quota
BPSMeter.do.update()
while 1:
for server in self.servers:
if 0: assert isinstance(server, Server) # Assert only for debug purposes
for nw in server.busy_threads[:]:
if (nw.nntp and nw.nntp.error_msg) or (nw.timeout and time.time() > nw.timeout):
if nw.nntp and nw.nntp.error_msg:
self.__reset_nw(nw, "", warn=False)
else:
self.__reset_nw(nw, "timed out")
server.bad_cons += 1
self.maybe_block_server(server)
if server.restart:
if not server.busy_threads:
newid = server.newid
server.stop(self.read_fds, self.write_fds)
self.servers.remove(server)
if newid:
self.init_server(None, newid)
self.__restart -= 1
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists()
# Have to leave this loop, because we removed element
break
else:
# Restart pending, don't add new articles
continue
if 0: assert isinstance(server, Server) # Assert only for debug purposes
if not server.idle_threads or server.restart or self.is_paused() or self.shutdown or self.delayed or self.postproc:
continue
if not server.active:
continue
for nw in server.idle_threads[:]:
if 0: assert isinstance(nw, NewsWrapper) # Assert only for debug purposes
if nw.timeout:
if time.time() < nw.timeout:
continue
else:
nw.timeout = None
if server.info is None:
self.maybe_block_server(server)
request_server_info(server)
break
article = sabnzbd.nzbqueue.NzbQueue.do.get_article(server, self.servers)
if not article:
break
if server.retention and article.nzf.nzo.avg_stamp < time.time() - server.retention:
# Article too old for the server, treat as missing
if sabnzbd.LOG_ALL:
logging.debug('Article %s too old for %s', article.article, server.id)
self.decode(article, None, None)
break
server.idle_threads.remove(nw)
server.busy_threads.append(nw)
nw.article = article
if nw.connected:
self.__request_article(nw)
else:
try:
logging.info("%s@%s: Initiating connection", nw.thrdnum, server.id)
nw.init_connect(self.write_fds)
except:
logging.error(T('Failed to initialize %s@%s with reason: %s'), nw.thrdnum, server.id, sys.exc_info()[1])
self.__reset_nw(nw, "failed to initialize")
# Exit-point
if self.shutdown:
empty = True
for server in self.servers:
if server.busy_threads:
empty = False
break
if empty:
# Start decoders
for decoder in self.decoder_workers:
decoder.stop()
decoder.join()
for server in self.servers:
server.stop(self.read_fds, self.write_fds)
logging.info("Shutting down")
break
if self.force_disconnect:
for server in self.servers:
for nw in server.idle_threads + server.busy_threads:
quit = nw.connected and server.active
self.__reset_nw(nw, "forcing disconnect", warn=False, wait=False, quit=quit)
# Make sure server address resolution is refreshed
server.info = None
self.force_disconnect = False
# => Select
readkeys = self.read_fds.keys()
writekeys = self.write_fds.keys()
if readkeys or writekeys:
read, write, error = select.select(readkeys, writekeys, (), 1.0)
# Why check so often when so few things happened?
if self.can_be_slowed and len(readkeys) >= 8 and len(read) <= 2:
time.sleep(0.01)
# Need to initialize the check during first 20 seconds
if self.can_be_slowed is None or self.can_be_slowed_timer:
# Wait for stable speed to start testing
if not self.can_be_slowed_timer and BPSMeter.do.get_stable_speed(timespan=10):
self.can_be_slowed_timer = time.time()
# Check 10 seconds after enabling slowdown
if self.can_be_slowed_timer and time.time() > self.can_be_slowed_timer + 10:
# Now let's check if it was stable in the last 10 seconds
self.can_be_slowed = (BPSMeter.do.get_stable_speed(timespan=10) > 0)
self.can_be_slowed_timer = 0
logging.debug('Downloader-slowdown: %r', self.can_be_slowed)
else:
read, write, error = ([], [], [])
BPSMeter.do.reset()
time.sleep(1.0)
CV.acquire()
while (sabnzbd.nzbqueue.NzbQueue.do.is_empty() or self.is_paused() or self.delayed or self.postproc) and not \
self.shutdown and not self.__restart:
CV.wait()
CV.release()
self.force_disconnect = False
for selected in write:
nw = self.write_fds[selected]
fileno = nw.nntp.sock.fileno()
if fileno not in self.read_fds:
self.read_fds[fileno] = nw
if fileno in self.write_fds:
self.write_fds.pop(fileno)
if not read:
BPSMeter.do.update()
continue
for selected in read:
nw = self.read_fds[selected]
article = nw.article
server = nw.server
if article:
nzo = article.nzf.nzo
try:
bytes, done, skip = nw.recv_chunk()
except:
bytes, done, skip = (0, False, False)
if skip:
BPSMeter.do.update()
continue
if bytes < 1:
self.__reset_nw(nw, "server closed connection", warn=False, wait=False)
continue
else:
if self.bandwidth_limit:
bps = BPSMeter.do.get_bps()
bps += bytes
limit = self.bandwidth_limit
if bps > limit:
while BPSMeter.do.get_bps() > limit:
time.sleep(0.05)
BPSMeter.do.update()
BPSMeter.do.update(server.id, bytes)
if nzo:
nzo.update_download_stats(BPSMeter.do.get_bps(), server.id, bytes)
if not done and nw.status_code != '222':
if not nw.connected or nw.status_code == '480':
done = False
try:
nw.finish_connect(nw.status_code)
if sabnzbd.LOG_ALL:
logging.debug("%s@%s last message -> %s", nw.thrdnum, nw.server.id, nntp_to_msg(nw.data))
nw.clear_data()
except NNTPPermanentError, error:
# Handle login problems
block = False
penalty = 0
msg = error.response
ecode = msg[:3]
display_msg = ' [%s]' % msg
logging.debug('Server login problem: %s, %s', ecode, msg)
if ecode in ('502', '400', '481', '482') and clues_too_many(msg):
# Too many connections: remove this thread and reduce thread-setting for server
# Plan to go back to the full number after a penalty timeout
if server.active:
errormsg = T('Too many connections to server %s') % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T('Too many connections to server %s'), server.id)
self.__reset_nw(nw, None, warn=False, destroy=True, quit=True)
self.plan_server(server.id, _PENALTY_TOOMANY)
server.threads -= 1
elif ecode in ('502', '481', '482') and clues_too_many_ip(msg):
# Account sharing?
if server.active:
errormsg = T('Probable account sharing') + display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
name = ' (%s)' % server.id
logging.warning(T('Probable account sharing') + name)
penalty = _PENALTY_SHARE
elif ecode in ('481', '482', '381') or (ecode == '502' and clues_login(msg)):
# Cannot login, block this server
if server.active:
errormsg = T('Failed login for server %s') % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.error(T('Failed login for server %s'), server.id)
penalty = _PENALTY_PERM
block = True
elif ecode == '502':
# Cannot connect (other reasons), block this server
if server.active:
errormsg = T('Cannot connect to server %s [%s]') % ('', display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T('Cannot connect to server %s [%s]'), server.id, msg)
if clues_pay(msg):
penalty = _PENALTY_PERM
else:
penalty = _PENALTY_502
block = True
elif ecode == '400':
# Temp connection problem?
if server.active:
logging.debug('Unspecified error 400 from server %s', server.id)
penalty = _PENALTY_VERYSHORT
block = True
else:
# Unknown error, just keep trying
if server.active:
errormsg = T('Cannot connect to server %s [%s]') % ('', display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(T('Cannot connect to server %s [%s]'), server.id, msg)
penalty = _PENALTY_UNKNOWN
if block or (penalty and server.optional):
if server.active:
server.active = False
if penalty and (block or server.optional):
self.plan_server(server.id, penalty)
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists()
self.__reset_nw(nw, None, warn=False, quit=True)
continue
except:
logging.error(T('Connecting %s@%s failed, message=%s'),
nw.thrdnum, nw.server.id, nntp_to_msg(nw.data))
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished", nw.thrdnum, nw.server.id)
self.__request_article(nw)
logging.error(T('Connecting %s@%s failed, message=%s'),
nw.thrdnum, nw.server.id, nntp_to_msg(nw.data))
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished", nw.thrdnum, nw.server.id)
self.__request_article(nw)
elif nw.status_code == '223':
done = True
logging.debug('Article <%s> is present', article.article)
elif nw.status_code == '211':
done = False
logging.debug("group command ok -> %s", nntp_to_msg(nw.data))
nw.group = nw.article.nzf.nzo.group
nw.clear_data()
self.__request_article(nw)
elif nw.status_code in ('411', '423', '430'):
done = True
logging.info('Thread %s@%s: Article %s missing (error=%s)',
nw.thrdnum, nw.server.id, article.article, nw.status_code)
nw.clear_data()
elif nw.status_code == '480':
if server.active:
server.active = False
server.errormsg = T('Server %s requires user/password') % ''
self.plan_server(server.id, 0)
def run(self):
# First check IPv6 connectivity
sabnzbd.EXTERNAL_IPV6 = sabnzbd.test_ipv6()
logging.debug("External IPv6 test result: %s", sabnzbd.EXTERNAL_IPV6)
# Then we check SSL certificate checking
sabnzbd.CERTIFICATE_VALIDATION = sabnzbd.test_cert_checking()
logging.debug("SSL verification test: %s",
sabnzbd.CERTIFICATE_VALIDATION)
# Kick BPS-Meter to check quota
BPSMeter.do.update()
while 1:
for server in self.servers:
for nw in server.busy_threads[:]:
if (nw.nntp and nw.nntp.error_msg) or (
nw.timeout and time.time() > nw.timeout):
if nw.nntp and nw.nntp.error_msg:
self.__reset_nw(nw, "", warn=False)
else:
self.__reset_nw(nw, "timed out")
server.bad_cons += 1
self.maybe_block_server(server)
if server.restart:
if not server.busy_threads:
newid = server.newid
server.stop(self.read_fds, self.write_fds)
self.servers.remove(server)
if newid:
self.init_server(None, newid)
self.__restart -= 1
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists()
# Have to leave this loop, because we removed element
break
else:
# Restart pending, don't add new articles
continue
if not server.idle_threads or server.restart or self.is_paused(
) or self.shutdown or self.postproc:
continue
if not server.active:
continue
for nw in server.idle_threads[:]:
if nw.timeout:
if time.time() < nw.timeout:
continue
else:
nw.timeout = None
if not server.info:
# Only request info if there's stuff in the queue
if not sabnzbd.nzbqueue.NzbQueue.do.is_empty():
self.maybe_block_server(server)
request_server_info(server)
break
article = sabnzbd.nzbqueue.NzbQueue.do.get_article(
server, self.servers)
if not article:
break
if server.retention and article.nzf.nzo.avg_stamp < time.time(
) - server.retention:
# Let's get rid of all the articles for this server at once
logging.info("Job %s too old for %s, moving on",
article.nzf.nzo.final_name, server.host)
while article:
self.decode(article, None)
article = article.nzf.nzo.get_article(
server, self.servers)
break
server.idle_threads.remove(nw)
server.busy_threads.append(nw)
nw.article = article
if nw.connected:
self.__request_article(nw)
else:
try:
logging.info("%s@%s: Initiating connection",
nw.thrdnum, server.host)
nw.init_connect(self.write_fds)
except:
logging.error(
T("Failed to initialize %s@%s with reason: %s"
),
nw.thrdnum,
server.host,
sys.exc_info()[1],
)
self.__reset_nw(nw, "failed to initialize")
# Exit-point
if self.shutdown:
empty = True
for server in self.servers:
if server.busy_threads:
empty = False
break
if empty:
for server in self.servers:
server.stop(self.read_fds, self.write_fds)
logging.info("Shutting down")
break
if self.force_disconnect:
for server in self.servers:
for nw in server.idle_threads + server.busy_threads:
send_quit = nw.connected and server.active
self.__reset_nw(nw,
"forcing disconnect",
warn=False,
wait=False,
send_quit=send_quit)
# Make sure server address resolution is refreshed
server.info = None
self.force_disconnect = False
# Use select to find sockets ready for reading/writing
readkeys = self.read_fds.keys()
writekeys = self.write_fds.keys()
if readkeys or writekeys:
read, write, error = select.select(readkeys, writekeys, (),
1.0)
# Why check so often when so few things happened?
if self.can_be_slowed and len(readkeys) >= 8 and len(
read) <= 2:
time.sleep(0.01)
# Need to initialize the check during first 20 seconds
if self.can_be_slowed is None or self.can_be_slowed_timer:
# Wait for stable speed to start testing
if not self.can_be_slowed_timer and BPSMeter.do.get_stable_speed(
timespan=10):
self.can_be_slowed_timer = time.time()
# Check 10 seconds after enabling slowdown
if self.can_be_slowed_timer and time.time(
) > self.can_be_slowed_timer + 10:
# Now let's check if it was stable in the last 10 seconds
self.can_be_slowed = BPSMeter.do.get_stable_speed(
timespan=10)
self.can_be_slowed_timer = 0
logging.debug("Downloader-slowdown: %r",
self.can_be_slowed)
else:
read, write, error = ([], [], [])
BPSMeter.do.reset()
time.sleep(1.0)
DOWNLOADER_CV.acquire()
while ((sabnzbd.nzbqueue.NzbQueue.do.is_empty()
or self.is_paused() or self.postproc)
and not self.shutdown and not self.__restart):
DOWNLOADER_CV.wait()
DOWNLOADER_CV.release()
self.force_disconnect = False
for selected in write:
nw = self.write_fds[selected]
fileno = nw.nntp.sock.fileno()
if fileno not in self.read_fds:
self.read_fds[fileno] = nw
if fileno in self.write_fds:
self.write_fds.pop(fileno)
if not read:
BPSMeter.do.update()
continue
for selected in read:
nw = self.read_fds[selected]
article = nw.article
server = nw.server
if article:
nzo = article.nzf.nzo
try:
bytes_received, done, skip = nw.recv_chunk()
except:
bytes_received, done, skip = (0, False, False)
if skip:
BPSMeter.do.update()
continue
if bytes_received < 1:
self.__reset_nw(nw,
"server closed connection",
warn=False,
wait=False)
continue
else:
if self.bandwidth_limit:
limit = self.bandwidth_limit
if bytes_received + BPSMeter.do.bps > limit:
while BPSMeter.do.bps > limit:
time.sleep(0.05)
BPSMeter.do.update()
BPSMeter.do.update(server.id, bytes_received)
nzo.update_download_stats(BPSMeter.do.bps, server.id,
bytes_received)
if not done and nw.status_code != 222:
if not nw.connected or nw.status_code == 480:
done = False
try:
nw.finish_connect(nw.status_code)
if sabnzbd.LOG_ALL:
logging.debug("%s@%s last message -> %s",
nw.thrdnum, nw.server.host,
nntp_to_msg(nw.data))
nw.clear_data()
except NNTPPermanentError as error:
# Handle login problems
block = False
penalty = 0
msg = error.response
ecode = int_conv(msg[:3])
display_msg = " [%s]" % msg
logging.debug("Server login problem: %s, %s",
ecode, msg)
if ecode in (502, 400, 481,
482) and clues_too_many(msg):
# Too many connections: remove this thread and reduce thread-setting for server
# Plan to go back to the full number after a penalty timeout
if server.active:
errormsg = T(
"Too many connections to server %s"
) % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T("Too many connections to server %s"
), server.host)
self.__reset_nw(nw,
None,
warn=False,
destroy=True,
send_quit=True)
self.plan_server(server, _PENALTY_TOOMANY)
server.threads -= 1
elif ecode in (502, 481,
482) and clues_too_many_ip(msg):
# Account sharing?
if server.active:
errormsg = T("Probable account sharing"
) + display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
name = " (%s)" % server.host
logging.warning(
T("Probable account sharing") +
name)
penalty = _PENALTY_SHARE
block = True
elif ecode in (452, 481, 482,
381) or (ecode == 502
and clues_login(msg)):
# Cannot login, block this server
if server.active:
errormsg = T("Failed login for server %s"
) % display_msg
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.error(
T("Failed login for server %s"),
server.host)
penalty = _PENALTY_PERM
block = True
elif ecode in (502, 482):
# Cannot connect (other reasons), block this server
if server.active:
errormsg = T(
"Cannot connect to server %s [%s]") % (
"", display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T("Cannot connect to server %s [%s]"
), server.host, msg)
if clues_pay(msg):
penalty = _PENALTY_PERM
else:
penalty = _PENALTY_502
block = True
elif ecode == 400:
# Temp connection problem?
if server.active:
logging.debug(
"Unspecified error 400 from server %s",
server.host)
penalty = _PENALTY_VERYSHORT
block = True
else:
# Unknown error, just keep trying
if server.active:
errormsg = T(
"Cannot connect to server %s [%s]") % (
"", display_msg)
if server.errormsg != errormsg:
server.errormsg = errormsg
logging.warning(
T("Cannot connect to server %s [%s]"
), server.host, msg)
penalty = _PENALTY_UNKNOWN
block = True
if block or (penalty and server.optional):
if server.active:
server.active = False
if penalty and (block or server.optional):
self.plan_server(server, penalty)
sabnzbd.nzbqueue.NzbQueue.do.reset_all_try_lists(
)
self.__reset_nw(nw,
None,
warn=False,
send_quit=True)
continue
except:
logging.error(
T("Connecting %s@%s failed, message=%s"),
nw.thrdnum,
nw.server.host,
nntp_to_msg(nw.data),
)
# No reset-warning needed, above logging is sufficient
self.__reset_nw(nw, None, warn=False)
if nw.connected:
logging.info("Connecting %s@%s finished",
nw.thrdnum, nw.server.host)
self.__request_article(nw)
elif nw.status_code == 223:
done = True
logging.debug("Article <%s> is present",
article.article)
elif nw.status_code == 211:
done = False
logging.debug("group command ok -> %s",
nntp_to_msg(nw.data))
nw.group = nw.article.nzf.nzo.group
nw.clear_data()
self.__request_article(nw)
elif nw.status_code in (411, 423, 430):
done = True
logging.debug(
"Thread %s@%s: Article %s missing (error=%s)",
nw.thrdnum,
nw.server.host,
article.article,
nw.status_code,
)
nw.clear_data()
elif nw.status_code == 500:
if nzo.precheck:
# Assume "STAT" command is not supported
server.have_stat = False
logging.debug("Server %s does not support STAT",
server.host)
else:
# Assume "BODY" command is not supported
server.have_body = False
logging.debug("Server %s does not support BODY",
server.host)
nw.clear_data()
self.__request_article(nw)
if done:
server.bad_cons = 0 # Successful data, clear "bad" counter
server.errormsg = server.warning = ""
if sabnzbd.LOG_ALL:
logging.debug("Thread %s@%s: %s done", nw.thrdnum,
server.host, article.article)
self.decode(article, nw.data)
nw.soft_reset()
server.busy_threads.remove(nw)
server.idle_threads.append(nw)
