Esempio n. 1
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:
                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)
Esempio n. 2
0
    def run(self):
        from sabnzbd.nzbqueue import NzbQueue
        self.decoder.start()

        # Kick BPS-Meter to check quota
        BPSMeter.do.update()

        while 1:
            for server in self.servers:
                assert isinstance(server, Server)
                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
                        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

                assert isinstance(server, Server)
                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 and NzbQueue.do.has_articles_for(server)):
                    continue

                for nw in server.idle_threads[:]:
                    assert isinstance(nw, NewsWrapper)
                    if nw.timeout:
                        if time.time() < nw.timeout:
                            continue
                        else:
                            nw.timeout = None

                    if not server.active:
                        break

                    if server.info is None:
                        self.maybe_block_server(server)
                        request_server_info(server)
                        break

                    article = NzbQueue.do.get_article(server)

                    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:%s', article.article, server.host, server.port)
                        self.decoder.decode(article, 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:%s: Initiating connection",
                                              nw.thrdnum, server.host, server.port)
                            nw.init_connect(self.write_fds)
                        except:
                            logging.error(Ta('Failed to initialize %s@%s:%s'),
                                              nw.thrdnum, server.host,
                                              server.port)
                            logging.info("Traceback: ", exc_info = True)
                            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:
                    self.decoder.stop()
                    self.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)

            else:
                read, write, error = ([], [], [])

                BPSMeter.do.reset()

                time.sleep(1.0)

                CV.acquire()
                while (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 * 1024
                        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.bytes_downloaded += bytes
                        nzo.update_avg_kbs(BPSMeter.do.get_bps())

                if len(nw.lines) == 1:
                    code = nw.lines[0][:3]
                    if not nw.connected or code == '480':
                        done = False

                        try:
                            nw.finish_connect(code)
                            if sabnzbd.LOG_ALL:
                                logging.debug("%s@%s:%s last message -> %s", nw.thrdnum, nw.server.host,
                                              nw.server.port, nw.lines[0])
                            nw.lines = []
                            nw.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')) and clues_too_many(msg)) or \
                                (ecode == '481' 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:
                                    server.errormsg = Ta('Too many connections to server %s:%s') % ('', display_msg)
                                    logging.error(Ta('Too many connections to server %s:%s'), server.host, server.port)
                                    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') and clues_too_many_ip(msg):
                                # Account sharing?
                                if server.active:
                                    server.errormsg = Ta('Probable account sharing') + display_msg
                                    name = ' (%s:%s)' % (server.host, server.port)
                                    logging.error(Ta('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:
                                    server.errormsg = Ta('Failed login for server %s') % display_msg
                                    logging.error(Ta('Failed login for server %s'), '%s:%s' % (server.host, server.port))
                                penalty = _PENALTY_PERM
                                block = True
                            elif ecode == '502':
                                # Cannot connect (other reasons), block this server
                                if server.active:
                                    server.errormsg = Ta('Cannot connect to server %s [%s]') % ('', display_msg)
                                    logging.warning(Ta('Cannot connect to server %s [%s]'), '%s:%s' % (server.host, server.port), msg)
                                if clues_pay(msg):
                                    penalty = _PENALTY_PERM
                                else:
                                    penalty = _PENALTY_502
                                block = True
                            else:
                                # Unknown error, just keep trying
                                if server.active:
                                    server.errormsg = Ta('Cannot connect to server %s [%s]') % ('', display_msg)
                                    logging.error(Ta('Cannot connect to server %s [%s]'),  '%s:%s' % (server.host, server.port), msg)
                                    penalty = _PENALTY_UNKNOWN
                            if block or (penalty and server.optional):
                                if server.active:
                                    server.active = False
                                    if (not server.optional) and cfg.no_penalties():
                                        penalty = _PENALTY_SHORT
                                    if penalty and (block or server.optional):
                                        logging.info('Server %s ignored for %s minutes', server.id, penalty)
                                        self.plan_server(server.id, penalty)
                                    NzbQueue.do.reset_all_try_lists()
                                self.__reset_nw(nw, None, warn=False, quit=True)
                            continue
                        except:
                            logging.error(Ta('Connecting %s@%s:%s failed, message=%s'),
                                              nw.thrdnum,
                                              nw.server.host, nw.server.port, nw.lines[0])
                            # No reset-warning needed, above logging is sufficient
                            self.__reset_nw(nw, None, warn=False)

                        if nw.connected:
                            logging.info("Connecting %s@%s:%s finished",
                                         nw.thrdnum, nw.server.host,
                                         nw.server.port)
                            self.__request_article(nw)
Esempio n. 3
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)
Esempio n. 4
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)