def _fail(self, value, contextinfo=None, srcexception=None, errcondition=None): """Wrapper to raise (and log) DAVError.""" e = DAVError(value, contextinfo, srcexception, errcondition) if self.verbose >= 4: _logger.warn("Raising DAVError {}".format( safe_re_encode(e.get_user_info(), sys.stdout.encoding))) raise e
def _fail(self, value, context_info=None, src_exception=None, err_condition=None): """Wrapper to raise (and log) DAVError.""" e = DAVError(value, context_info, src_exception, err_condition) if self.verbose >= 4: _logger.warning( "Raising DAVError {}".format( safe_re_encode(e.get_user_info(), sys.stdout.encoding) ) ) raise e
def get_domain_realm(self, inputURL, environ): """Resolve a relative url to the appropriate realm name.""" # we don't get the realm here, its already been resolved in # request_resolver davProvider = environ["wsgidav.provider"] if not davProvider: if environ["wsgidav.verbose"] >= 2: _logger.debug("get_domain_realm({}): '{}'".format( util.safe_re_encode(inputURL, sys.stdout.encoding), None)) return None realm = davProvider.sharePath if realm == "": realm = "/" return realm
def _calc_realm_from_path_provider(self, path_info, environ): """Internal helper for derived classes to implement get_domain_realm().""" if environ: # Called while in a request: # We don't get the share from the path_info here: it was already # resolved and stripped by the request_resolver dav_provider = environ["wsgidav.provider"] else: # Called on start-up with the share root URL _share, dav_provider = self.wsgidav_app.resolve_provider(path_info) if not dav_provider: logger.warn("_calc_realm_from_path_provider('{}'): '{}'".format( util.safe_re_encode(path_info, sys.stdout.encoding), None)) return None realm = dav_provider.share_path if realm == "": realm = "/" return realm
def _calc_realm_from_path_provider(self, path_info, environ): """Internal helper for derived classes to implement get_domain_realm().""" if environ: # Called while in a request: # We don't get the share from the path_info here: it was already # resolved and stripped by the request_resolver dav_provider = environ["wsgidav.provider"] else: # Called on start-up with the share root URL _share, dav_provider = self.wsgidav_app.resolve_provider(path_info) if not dav_provider: logger.warn( "_calc_realm_from_path_provider('{}'): '{}'".format( util.safe_re_encode(path_info, sys.stdout.encoding), None ) ) return None realm = dav_provider.share_path if realm == "": realm = "/" return realm
def _start_response_wrapper(status, response_headers, exc_info=None): # Postprocess response headers headerDict = {} for header, value in response_headers: if header.lower() in headerDict: _logger.error("Duplicate header in response: {}".format(header)) headerDict[header.lower()] = value # Check if we should close the connection after this request. # http://www.w3.org/Protocols/rfc2616/rfc2616-sec4.html#sec4.4 forceCloseConnection = False currentContentLength = headerDict.get("content-length") statusCode = int(status.split(" ", 1)[0]) contentLengthRequired = ( environ["REQUEST_METHOD"] != "HEAD" and statusCode >= 200 and statusCode not in (204, 304) ) # _logger.info(environ["REQUEST_METHOD"], statusCode, contentLengthRequired) if contentLengthRequired and currentContentLength in (None, ""): # A typical case: a GET request on a virtual resource, for which # the provider doesn't know the length _logger.error( "Missing required Content-Length header in {}-response: closing connection".format( statusCode ) ) forceCloseConnection = True elif not type(currentContentLength) is str: _logger.error( "Invalid Content-Length header in response ({!r}): closing connection".format( headerDict.get("content-length") ) ) forceCloseConnection = True # HOTFIX for Vista and Windows 7 (GC issue 13, issue 23) # It seems that we must read *all* of the request body, otherwise # clients may miss the response. # For example Vista MiniRedir didn't understand a 401 response, # when trying an anonymous PUT of big files. As a consequence, it # doesn't retry with credentials and the file copy fails. # (XP is fine however). util.read_and_discard_input(environ) # Make sure the socket is not reused, unless we are 100% sure all # current input was consumed if util.get_content_length(environ) != 0 and not environ.get( "wsgidav.all_input_read" ): _logger.warn("Input stream not completely consumed: closing connection") forceCloseConnection = True if forceCloseConnection and headerDict.get("connection") != "close": _logger.warn("Adding 'Connection: close' header") response_headers.append(("Connection", "close")) # Log request if self.verbose >= 3: userInfo = environ.get("http_authenticator.username") if not userInfo: userInfo = "(anonymous)" extra = [] if "HTTP_DESTINATION" in environ: extra.append('dest="{}"'.format(environ.get("HTTP_DESTINATION"))) if environ.get("CONTENT_LENGTH", "") != "": extra.append("length={}".format(environ.get("CONTENT_LENGTH"))) if "HTTP_DEPTH" in environ: extra.append("depth={}".format(environ.get("HTTP_DEPTH"))) if "HTTP_RANGE" in environ: extra.append("range={}".format(environ.get("HTTP_RANGE"))) if "HTTP_OVERWRITE" in environ: extra.append("overwrite={}".format(environ.get("HTTP_OVERWRITE"))) if self.verbose >= 3 and "HTTP_EXPECT" in environ: extra.append('expect="{}"'.format(environ.get("HTTP_EXPECT"))) if self.verbose >= 4 and "HTTP_CONNECTION" in environ: extra.append( 'connection="{}"'.format(environ.get("HTTP_CONNECTION")) ) if self.verbose >= 4 and "HTTP_USER_AGENT" in environ: extra.append('agent="{}"'.format(environ.get("HTTP_USER_AGENT"))) if self.verbose >= 4 and "HTTP_TRANSFER_ENCODING" in environ: extra.append( "transfer-enc={}".format(environ.get("HTTP_TRANSFER_ENCODING")) ) if self.verbose >= 3: extra.append("elap={:.3f}sec".format(time.time() - start_time)) extra = ", ".join(extra) # This is the CherryPy format: # 127.0.0.1 - - [08/Jul/2009:17:25:23] "GET /loginPrompt?redirect=/renderActionList%3Frelation%3Dpersonal%26key%3D%26filter%3DprivateSchedule&reason=0 HTTP/1.1" 200 1944 "http://127.0.0.1:8002/command?id=CMD_Schedule" "Mozilla/5.0 (Windows; U; Windows NT 6.0; de; rv:1.9.1) Gecko/20090624 Firefox/3.5" # noqa _logger.info( '{addr} - {user} - [{time}] "{method} {path}" {extra} -> {status}'.format( addr=environ.get("REMOTE_ADDR", ""), user=userInfo, time=util.get_log_time(), method=environ.get("REQUEST_METHOD"), path=safe_re_encode( environ.get("PATH_INFO", ""), sys.stdout.encoding ), extra=extra, status=status, # response_headers.get(""), # response Content-Length # referer ) ) return start_response(status, response_headers, exc_info)
def __call__(self, environ, start_response): """""" # srvcfg = environ["wsgidav.config"] verbose = self._config.get("verbose", 3) method = environ["REQUEST_METHOD"] debugBreak = False dumpRequest = False dumpResponse = False if verbose >= 5: dumpRequest = dumpResponse = True # Process URL commands if "dump_storage" in environ.get("QUERY_STRING", ""): dav = environ.get("wsgidav.provider") if dav.lockManager: dav.lockManager._dump() if dav.propManager: dav.propManager._dump() # Turn on max. debugging for selected litmus tests litmusTag = environ.get("HTTP_X_LITMUS", environ.get("HTTP_X_LITMUS_SECOND")) if litmusTag and verbose >= 3: _logger.info("----\nRunning litmus test '{}'...".format(litmusTag)) for litmusSubstring in self.debug_litmus: if litmusSubstring in litmusTag: verbose = 5 debugBreak = True dumpRequest = True dumpResponse = True break for litmusSubstring in self.break_after_litmus: if litmusSubstring in self.passedLitmus and litmusSubstring not in litmusTag: _logger.info( " *** break after litmus {}".format(litmusTag)) sys.exit(-1) if litmusSubstring in litmusTag: self.passedLitmus[litmusSubstring] = True # Turn on max. debugging for selected request methods if verbose >= 3 and method in self.debug_methods: verbose = 5 debugBreak = True dumpRequest = True dumpResponse = True # Set debug options to environment environ["wsgidav.verbose"] = verbose # environ["wsgidav.debug_methods"] = self.debug_methods environ["wsgidav.debug_break"] = debugBreak environ["wsgidav.dump_request_body"] = dumpRequest environ["wsgidav.dump_response_body"] = dumpResponse # Dump request headers if dumpRequest: _logger.info("{} Request ---".format(method)) # _logger.info("<{}> --- {} Request ---".format( # threading.currentThread().ident, method)) for k, v in environ.items(): if k == k.upper(): _logger.info("{:<20}: '{}'".format( k, safe_re_encode(v, "utf8"))) _logger.info("\n") # Intercept start_response # sub_app_start_response = util.SubAppStartResponse() nbytes = 0 first_yield = True app_iter = self.next_app(environ, sub_app_start_response) for v in app_iter: # Start response (the first time) if first_yield: # Success! start_response(sub_app_start_response.status, sub_app_start_response.response_headers, sub_app_start_response.exc_info) # Dump response headers if first_yield and dumpResponse: _logger.info("<{}> ---{} Response({}): ---".format( threading.currentThread().ident, method, sub_app_start_response.status)) headersdict = dict(sub_app_start_response.response_headers) for envitem in headersdict.keys(): _logger.info("{}: {}".format(envitem, repr(headersdict[envitem]))) _logger.info("") # Check, if response is a binary string, otherwise we probably have # calculated a wrong content-length assert compat.is_bytes(v), v # Dump response body drb = environ.get("wsgidav.dump_response_body") if compat.is_basestring(drb): # Middleware provided a formatted body representation _logger.info(drb) drb = environ["wsgidav.dump_response_body"] = None elif drb is True: # Else dump what we get, (except for long GET responses) if method == "GET": if first_yield: _logger.info("{}...".format(v[:50])) elif len(v) > 0: _logger.info(v) nbytes += len(v) first_yield = False yield v if hasattr(app_iter, "close"): app_iter.close() # Start response (if it hasn't been done yet) if first_yield: # Success! start_response(sub_app_start_response.status, sub_app_start_response.response_headers, sub_app_start_response.exc_info) if dumpResponse: _logger.info("<{}> --- End of {} Response ({:d} bytes) ---".format( threading.currentThread().ident, method, nbytes)) return
def __call__(self, environ, start_response): """""" # srvcfg = environ["wsgidav.config"] verbose = self._config.get("verbose", 3) method = environ["REQUEST_METHOD"] debugBreak = False dumpRequest = False dumpResponse = False if verbose >= 5: dumpRequest = dumpResponse = True # Process URL commands if "dump_storage" in environ.get("QUERY_STRING", ""): dav = environ.get("wsgidav.provider") if dav.lock_manager: dav.lock_manager._dump() if dav.prop_manager: dav.prop_manager._dump() # Turn on max. debugging for selected litmus tests litmusTag = environ.get("HTTP_X_LITMUS", environ.get("HTTP_X_LITMUS_SECOND")) if litmusTag and verbose >= 3: _logger.info("----\nRunning litmus test '{}'...".format(litmusTag)) for litmusSubstring in self.debug_litmus: if litmusSubstring in litmusTag: verbose = 5 debugBreak = True dumpRequest = True dumpResponse = True break for litmusSubstring in self.break_after_litmus: if ( litmusSubstring in self.passedLitmus and litmusSubstring not in litmusTag ): _logger.info(" *** break after litmus {}".format(litmusTag)) sys.exit(-1) if litmusSubstring in litmusTag: self.passedLitmus[litmusSubstring] = True # Turn on max. debugging for selected request methods if verbose >= 3 and method in self.debug_methods: verbose = 5 debugBreak = True dumpRequest = True dumpResponse = True # Set debug options to environment environ["wsgidav.verbose"] = verbose # environ["wsgidav.debug_methods"] = self.debug_methods environ["wsgidav.debug_break"] = debugBreak environ["wsgidav.dump_request_body"] = dumpRequest environ["wsgidav.dump_response_body"] = dumpResponse # Dump request headers if dumpRequest: _logger.info("{} Request ---".format(method)) # _logger.info("<{}> --- {} Request ---".format( # threading.currentThread().ident, method)) for k, v in environ.items(): if k == k.upper(): _logger.info("{:<20}: '{}'".format(k, safe_re_encode(v, "utf8"))) _logger.info("\n") # Intercept start_response # sub_app_start_response = util.SubAppStartResponse() nbytes = 0 first_yield = True app_iter = self.next_app(environ, sub_app_start_response) for v in app_iter: # Start response (the first time) if first_yield: # Success! start_response( sub_app_start_response.status, sub_app_start_response.response_headers, sub_app_start_response.exc_info, ) # Dump response headers if first_yield and dumpResponse: _logger.info( "<{}> ---{} Response({}): ---".format( threading.currentThread().ident, method, sub_app_start_response.status, ) ) headersdict = dict(sub_app_start_response.response_headers) for envitem in headersdict.keys(): _logger.info("{}: {}".format(envitem, repr(headersdict[envitem]))) _logger.info("") # Check, if response is a binary string, otherwise we probably have # calculated a wrong content-length assert compat.is_bytes(v), v # Dump response body drb = environ.get("wsgidav.dump_response_body") if compat.is_basestring(drb): # Middleware provided a formatted body representation _logger.info(drb) drb = environ["wsgidav.dump_response_body"] = None elif drb is True: # Else dump what we get, (except for long GET responses) if method == "GET": if first_yield: _logger.info("{}...".format(v[:50])) elif len(v) > 0: _logger.info(v) nbytes += len(v) first_yield = False yield v if hasattr(app_iter, "close"): app_iter.close() # Start response (if it hasn't been done yet) if first_yield: # Success! start_response( sub_app_start_response.status, sub_app_start_response.response_headers, sub_app_start_response.exc_info, ) if dumpResponse: _logger.info( "<{}> --- End of {} Response ({:d} bytes) ---".format( threading.currentThread().ident, method, nbytes ) ) return
def _start_response_wrapper(status, response_headers, exc_info=None): # Postprocess response headers headerDict = {} for header, value in response_headers: if header.lower() in headerDict: _logger.error("Duplicate header in response: {}".format(header)) headerDict[header.lower()] = value # Check if we should close the connection after this request. # http://www.w3.org/Protocols/rfc2616/rfc2616-sec4.html#sec4.4 forceCloseConnection = False currentContentLength = headerDict.get("content-length") statusCode = int(status.split(" ", 1)[0]) contentLengthRequired = ( environ["REQUEST_METHOD"] != "HEAD" and statusCode >= 200 and statusCode not in (204, 304) ) # _logger.info(environ["REQUEST_METHOD"], statusCode, contentLengthRequired) if contentLengthRequired and currentContentLength in (None, ""): # A typical case: a GET request on a virtual resource, for which # the provider doesn't know the length _logger.error( "Missing required Content-Length header in {}-response: closing connection".format( statusCode ) ) forceCloseConnection = True elif not type(currentContentLength) is str: _logger.error( "Invalid Content-Length header in response ({!r}): closing connection".format( headerDict.get("content-length") ) ) forceCloseConnection = True # HOTFIX for Vista and Windows 7 (GC issue 13, issue 23) # It seems that we must read *all* of the request body, otherwise # clients may miss the response. # For example Vista MiniRedir didn't understand a 401 response, # when trying an anonymous PUT of big files. As a consequence, it # doesn't retry with credentials and the file copy fails. # (XP is fine however). util.read_and_discard_input(environ) # Make sure the socket is not reused, unless we are 100% sure all # current input was consumed if util.get_content_length(environ) != 0 and not environ.get( "wsgidav.all_input_read" ): _logger.warning( "Input stream not completely consumed: closing connection." ) forceCloseConnection = True if forceCloseConnection and headerDict.get("connection") != "close": _logger.warning("Adding 'Connection: close' header.") response_headers.append(("Connection", "close")) # Log request if self.verbose >= 3: userInfo = environ.get("wsgidav.auth.user_name") if not userInfo: userInfo = "(anonymous)" extra = [] if "HTTP_DESTINATION" in environ: extra.append('dest="{}"'.format(environ.get("HTTP_DESTINATION"))) if environ.get("CONTENT_LENGTH", "") != "": extra.append("length={}".format(environ.get("CONTENT_LENGTH"))) if "HTTP_DEPTH" in environ: extra.append("depth={}".format(environ.get("HTTP_DEPTH"))) if "HTTP_RANGE" in environ: extra.append("range={}".format(environ.get("HTTP_RANGE"))) if "HTTP_OVERWRITE" in environ: extra.append("overwrite={}".format(environ.get("HTTP_OVERWRITE"))) if self.verbose >= 3 and "HTTP_EXPECT" in environ: extra.append('expect="{}"'.format(environ.get("HTTP_EXPECT"))) if self.verbose >= 4 and "HTTP_CONNECTION" in environ: extra.append( 'connection="{}"'.format(environ.get("HTTP_CONNECTION")) ) if self.verbose >= 4 and "HTTP_USER_AGENT" in environ: extra.append('agent="{}"'.format(environ.get("HTTP_USER_AGENT"))) if self.verbose >= 4 and "HTTP_TRANSFER_ENCODING" in environ: extra.append( "transfer-enc={}".format(environ.get("HTTP_TRANSFER_ENCODING")) ) if self.verbose >= 3: extra.append("elap={:.3f}sec".format(time.time() - start_time)) extra = ", ".join(extra) # This is the CherryPy format: # 127.0.0.1 - - [08/Jul/2009:17:25:23] "GET /loginPrompt?redirect=/renderActionList%3Frelation%3Dpersonal%26key%3D%26filter%3DprivateSchedule&reason=0 HTTP/1.1" 200 1944 "http://127.0.0.1:8002/command?id=CMD_Schedule" "Mozilla/5.0 (Windows; U; Windows NT 6.0; de; rv:1.9.1) Gecko/20090624 Firefox/3.5" # noqa _logger.info( '{addr} - {user} - [{time}] "{method} {path}" {extra} -> {status}'.format( addr=environ.get("REMOTE_ADDR", ""), user=userInfo, time=util.get_log_time(), method=environ.get("REQUEST_METHOD"), path=safe_re_encode( environ.get("PATH_INFO", ""), sys.stdout.encoding if sys.stdout.encoding else "utf-8", ), extra=extra, status=status, # response_headers.get(""), # response Content-Length # referer ) ) return start_response(status, response_headers, exc_info)