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