def validate_basic_movie_properties(cls, movie: MovieType, stack_trace: bool = True) -> None: """ Verifies that certain fields in a Kodi VideoInfo dictionary have values. Fields with Missing fields are logged and dummy values are added. Meant to avoid Exceptions. :param movie: :param stack_trace: :return: """ if not cls._logger.isEnabledFor(LazyLogger.DEBUG_VERBOSE): return if movie is None: cls._logger.debug_verbose('movie is None') return basic_properties = {} for key in (Movie.TRAILER_TYPE, Movie.FANART, Movie.THUMBNAIL, Movie.TRAILER, Movie.SOURCE, Movie.YEAR, Movie.RATING, Movie.TITLE): basic_properties[key] = Movie.DEFAULT_MOVIE[key] failing_properties = [] is_failed = False for property_name in basic_properties.keys(): if movie.get(property_name) is None: failing_properties.append(property_name) is_failed = True movie.setdefault(property_name, basic_properties[property_name]) if len(failing_properties) > 0: msg = f'{movie.get(Movie.TITLE, "title missing")} ' \ f'{",".join(failing_properties)}' if stack_trace: LazyLogger.dump_stack('Missing basic property: ' + msg) else: cls._logger.debug_verbose('Missing properties:', msg) assert not is_failed, 'LEAK: Invalid property values'
def validate_basic_movie_properties(cls, movie, stack_trace=True): # type: (MovieType, bool) -> None """ Verifies that certain fields in a Kodi VideoInfo dictionary have values. Fields with Missing fields are logged and dummy values are added. Meant to avoid Exceptions. :param movie: :param stack_trace: :return: """ if not cls._logger.isEnabledFor(LazyLogger.DEBUG_VERBOSE): return basic_properties = { Movie.TYPE: 'default_' + Movie.TYPE, Movie.FANART: 'default_' + Movie.TYPE, Movie.THUMBNAIL: 'default_ ' + Movie.THUMBNAIL, Movie.TRAILER: 'default_' + Movie.TRAILER, Movie.SOURCE: 'default_' + Movie.SOURCE, # Movie.FILE, Movie.YEAR: 1492, Movie.RATING: 0.0, Movie.TITLE: 'default_' + Movie.TITLE } failing_properties = [] is_failed = False for property_name in basic_properties.keys(): if movie.get(property_name) is None: failing_properties.append(property_name) is_failed = True movie.setdefault(property_name, basic_properties[property_name]) if len(failing_properties) > 0: msg = ', '.join(failing_properties) if stack_trace: LazyLogger.dump_stack('Missing basic property: ' + msg) else: cls._logger.debug_verbose('Missing properties:', msg) assert not is_failed, 'LEAK: Invalid property values'
def validate_detailed_movie_properties(cls, movie: MovieType, stack_trace: bool = True, force_check: bool = False) -> bool: """ Similar to validate_basic_movie_properties. Validates additional fields :param movie: :param stack_trace: :param force_check: Check even if debug level less than DEBUG_VERBOSE :return: True if no problems found """ if not (cls._logger.isEnabledFor(LazyLogger.DEBUG_VERBOSE) or force_check): return True details_properties = { Movie.WRITER: 'default_' + Movie.WRITER, Movie.DETAIL_DIRECTORS: 'default_' + Movie.DETAIL_DIRECTORS, Movie.DETAIL_TITLE: 'default_' + Movie.TITLE, Movie.CAST: 'default_' + Movie.CAST, Movie.PLOT: 'default_' + Movie.PLOT, Movie.GENRE: 'default_' + Movie.GENRE, Movie.STUDIO: 'default_' + Movie.STUDIO, Movie.DETAIL_ACTORS: 'default_' + Movie.ACTORS, Movie.DETAIL_GENRES: 'default_' + Movie.GENRE, Movie.DETAIL_CERTIFICATION: 'default_' + Movie.DETAIL_CERTIFICATION, Movie.DETAIL_CERTIFICATION_IMAGE: 'default_' + Movie.DETAIL_CERTIFICATION_IMAGE, Movie.DETAIL_RUNTIME: 'default_' + Movie.RUNTIME, Movie.DETAIL_WRITERS: 'default_' + Movie.WRITER, # Movie.TMDB_TAGS: 'default_' + Movie.TAG, # For TMDB Movie.DETAIL_STUDIOS: 'default_' + Movie.STUDIO, Movie.RUNTIME: 0, # Movie.ADULT, Movie.MPAA: 'default_' + Movie.MPAA } cls.validate_basic_movie_properties(movie, stack_trace=stack_trace) failing_properties = [] is_ok = True for property_name in details_properties.keys(): if movie.get(property_name) is None: failing_properties.append(property_name) movie.setdefault(property_name, details_properties[property_name]) is_ok = False if len(failing_properties) > 0: msg = ', '.join(failing_properties) if stack_trace: LazyLogger.dump_stack('Missing details property: ' + msg) else: cls._logger.debug_verbose('Missing properties:', msg) country_id = Settings.get_country_iso_3166_1().lower() certifications = WorldCertifications.get_certifications(country_id) if not certifications.is_valid(movie[Movie.MPAA]): if movie[Movie.MPAA] != '': cls._logger.debug_verbose( f'Invalid certification: {movie[Movie.MPAA]} for movie: ' '{movie[Movie.TITLE]} set to NR') movie[Movie.MPAA] = certifications.get_unrated_certification() \ .get_preferred_id() # assert is_ok, 'LEAK, Invalid property values' return is_ok
def get_json( cls, url, # type; str second_attempt=False, # type: bool dump_results=False, # type: bool dump_msg='', # type: str error_msg=None, # type: Union[str, int, None] headers=None, # type: Union[dict, None] params=None, # type: Union[Dict[str, Any], None] timeout=3.0 # type: float ): # type: (...) -> (int, str) """ Queries external site for movie/trailer information. Returns JSON result. Retries once on failure. Uses hints from response to adjust delay between requests. :param url: :param second_attempt: :param dump_results: :param dump_msg: :param error_msg: :param headers: :param params: :param timeout: :return: """ if headers is None: headers = {} if params is None: params = {} destination_string = '' request_index = None site = None if 'themoviedb' in url: destination_string = 'TMDB' request_index = JsonUtilsBasic.TMDB_REQUEST_INDEX site = 'TMDB' elif backend_constants.APPLE_URL_PREFIX in url: destination_string = 'iTunes' request_index = JsonUtilsBasic.ITUNES_REQUEST_INDEX site = 'iTunes' elif backend_constants.ROTTEN_TOMATOES_URL_PREFIX in url: destination_string = 'RottenTomatoes' request_index = JsonUtilsBasic.ROTTEN_TOMATOES_REQUEST_INDEX site = 'Tomatoes' destination_data = JsonUtilsBasic.DestinationDataContainer.get_data( request_index) Monitor.throw_exception_if_abort_requested() with destination_data.get_lock(): time_delay = JsonUtilsBasic.get_delay_time(request_index) json_text = None # Some TMDB api calls do NOT give RATE-LIMIT info in header responses # In such cases we detect the failure from the status code and retry # with a forced sleep of 10 seconds, which is the maximum required # wait time. if cls._logger.isEnabledFor(LazyLogger.DEBUG_EXTRA_VERBOSE): cls._logger.debug_extra_verbose( 'requestCount:', destination_data.total_requests, 'serverBlockingRequestUntil:', destination_data.server_blocking_request_until, 'numberOfAdditionalRequestsAllowedByServer:', destination_data. number_of_additional_requests_allowed_by_server, 'hardCodedRequestsPerTimePeriod:', destination_data.hard_coded_requests_per_time_period, 'requestLimitFromServer:', destination_data.actual_max_requests_per_time_period, 'actualOldestRequestInWindowExpirationTime:', destination_data. actual_oldest_request_in_window_expiration_time, trace=Trace.TRACE_JSON) if time_delay > 0: if cls._logger.isEnabledFor(LazyLogger.DEBUG_VERBOSE): cls._logger.debug('Waiting for JSON request to', destination_string, 'for', time_delay, 'seconds', trace=[Trace.STATS, Trace.TRACE_JSON]) Monitor.throw_exception_if_abort_requested(timeout=time_delay) destination_data.total_requests += 1 requests_to_url = destination_data.total_requests request_failed = True now = datetime.datetime.now() response_time_stamp = now try: response = requests.get(url.encode('utf-8'), headers=headers, params=params, timeout=timeout) request_failed = False # We could change our minds now = datetime.datetime.now() response_time_stamp = now status_code = response.status_code if cls._logger.isEnabledFor(LazyLogger.DEBUG): cls._logger.debug('generated url:', response.url) json_text = response.json() returned_header = response.headers except AbortException: reraise(*sys.exc_info()) # # Possible Exceptions: # RequestException, Timeout, URLRequired, # TooManyRedirects, HTTPError, ConnectionError, # FileModeWarning, ConnectTimeout, ReadTimeout except (ReadTimeout, ConnectTimeout, ConnectionError) as e: if cls._logger.isEnabledFor(LazyLogger.DEBUG): cls._logger.debug('Timeout occurred. Will retry.', error_msg) request_failed = True status_code = -1 returned_header = { 'Retry-After': str(destination_data.window_time_period.total_seconds()) } except Exception as e: try: # TODO: Move this after full analysis, not nested if cls._logger.isEnabledFor(LazyLogger.DEBUG): cls._logger.debug('Exception getting movie:', error_msg, 'url:', url) cls._logger.exception('') request_failed = True status_code = -1 returned_header = {} if cls._logger.isEnabledFor(LazyLogger.DEBUG): # The exception frequently doesn't have a complete stack # trace LazyLogger.dump_stack() cls._logger.debug( 'request to', destination_string, 'FAILED.', 'url', url, 'headers:', headers, 'params', params, 'timeout', timeout, trace=[Trace.STATS, Trace.TRACE_JSON]) cls._logger.debug( 'request to', destination_string, 'FAILED total requests:', requests_to_url, trace=[Trace.STATS, Trace.TRACE_JSON]) JsonUtilsBasic.dump_delay_info(request_index) if second_attempt: status_code = -1 json_text = None return status_code, json_text if cls._logger.isEnabledFor(LazyLogger.DEBUG): JsonUtilsBasic.dump_delay_info(request_index) except AbortException: reraise(*sys.exc_info()) except Exception as e: cls._logger.exception('') if cls._logger.isEnabledFor(LazyLogger.DISABLED): cls._logger.debug_extra_verbose('Headers from:', site, returned_header) # TODO- delete or control by setting or config_logger destination_data.number_of_additional_requests_allowed_by_server = -1 destination_data.actual_max_requests_per_time_period = 0 destination_data.actual_oldest_request_in_window_expiration_time = None destination_data.server_blocking_request_until = None tmp = returned_header.get('X-RateLimit-Remaining') if tmp is not None: destination_data.number_of_additional_requests_allowed_by_server = int( tmp) tmp = returned_header.get('X-RateLimit-Limit') if tmp is not None: destination_data.actual_max_requests_per_time_period = int(tmp) # Limit will be lifted at this time, in epoch seconds tmp = returned_header.get('X-RateLimit-Reset') if tmp is not None: destination_data.actual_oldest_request_in_window_expiration_time = ( datetime.datetime.fromtimestamp(int(tmp))) else: # Some calls don't return X-RateLimit-Reset, in those cases there # should be Retry-After indicating how many more seconds to wait # before traffic can resume server_blocking_request_until_value = 0 tmp = returned_header.get('Retry-After') msg = '' if tmp is not None: if cls._logger.isEnabledFor( LazyLogger.DEBUG_EXTRA_VERBOSE): cls._logger.debug_extra_verbose('Retry-After:', tmp) seconds = float(tmp) + 1 server_blocking_request_until_value = response_time_stamp + \ datetime.timedelta(0, seconds) destination_data.server_blocking_request_until = server_blocking_request_until_value request_failed = True # TODO: This is messy. The Date string returned is probably dependent # upon the locale of the user, which means the format will be different # Note also that the time zone GMT, or any timezone, is not recognized # on input and it is assumed that you are in the same timezone (yeesh) # Have to manually clobber the TZ field and reset to UTC. tmp = returned_header.get('Date') if tmp is not None: if cls._logger.isEnabledFor( LazyLogger.DEBUG_EXTRA_VERBOSE): parsed_date = parsedate_tz(tmp) unix_time_stamp = calendar.timegm(parsed_date) time_stamp = datetime.datetime.fromtimestamp( unix_time_stamp) delta = time_stamp - response_time_stamp # cls._logger.debug_extra_verbose( # 'Date: ', tmp) if cls._logger.isEnabledFor(LazyLogger.DISABLED): cls._logger.debug_extra_verbose( 'Timestamp from server:', time_stamp, 'difference from client:', delta.total_seconds()) if request_index == JsonUtilsBasic.TMDB_REQUEST_INDEX: if cls._logger.isEnabledFor( LazyLogger.DEBUG_EXTRA_VERBOSE): cls._logger.debug_extra_verbose( 'TMDB response header missing X-RateLimit info.', msg) # Debug.myLog('get_json json_text: ' + json_text.__class__.__name__ + # ' ' + json.dumps(json_text), xbmc.LOGDEBUG) if ((status_code == Constants.TOO_MANY_TMDB_REQUESTS) and (request_index == JsonUtilsBasic.TMDB_REQUEST_INDEX)): # Too many requests, if cls._logger.isEnabledFor(LazyLogger.INFO): cls._logger.info( 'JSON Request rate to TMDB exceeds limits (' + str(destination_data. hard_coded_requests_per_time_period) + ' every', destination_data.window_time_period.total_seconds(), ' seconds). Consider getting API Key. This session\'s requests: ' + str(destination_data.total_requests), trace=Trace.TRACE_JSON) if cls._logger.isEnabledFor(LazyLogger.DEBUG_EXTRA_VERBOSE): JsonUtilsBasic.dump_delay_info(request_index) if cls._logger.isEnabledFor(LazyLogger.DEBUG_EXTRA_VERBOSE): cls._logger.debug_extra_verbose( 'JSON request source:', destination_string, 'total requests:', requests_to_url, 'serverBlockingRequestUntil:', destination_data.server_blocking_request_until, 'numberOfAdditionalRequetsAllowedByServer:', destination_data. number_of_additional_requests_allowed_by_server, 'hardCodedRequestsPerTimePeriod:', destination_data.hard_coded_requests_per_time_period, 'actualMaxRequestsPerTimePeriod:', destination_data.actual_max_requests_per_time_period, 'actualOldestRequestInWindowExpirationTime:', destination_data. actual_oldest_request_in_window_expiration_time, trace=[Trace.STATS, Trace.TRACE_JSON]) JsonUtilsBasic.record_request_timestamp(request_index, response_time_stamp, failed=request_failed) if request_failed: # # Retry only once # if not second_attempt: try: status_code, json_text = \ JsonUtilsBasic.get_json(url, second_attempt=True, headers=headers, params=params, timeout=0.50) except AbortException: reraise(*sys.exc_info()) except Exception as e: status_code = -1 json_text = None finally: JsonUtilsBasic.record_request_timestamp( request_index, response_time_stamp, failed=request_failed) #if dump_results and cls._logger.isEnabledFor(LazyLogger.DEBUG_EXTRA_VERBOSE): # cls._logger.debug_extra_verbose('JSON DUMP:', dump_msg) # cls._logger.debug_extra_verbose(json.dumps( # json_text, indent=3, sort_keys=True)) if status_code == 200: status_code = 0 return status_code, json_text