Skip to content

Commit

Permalink
[sapphire] Minor logging code updates
Browse files Browse the repository at this point in the history
  • Loading branch information
@tysmith
tysmith committed Oct 3, 2023
1 parent 108a45b commit 0ed71bc
Show file tree
Hide file tree
Showing 3 changed files with 35 additions and 35 deletions.
18 changes: 10 additions & 8 deletions sapphire/connection_manager.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -131,9 +131,7 @@ def serve(self, timeout, continue_cb=None, shutdown_delay=SHUTDOWN_DELAY):
launches = 0
running = 0
workers = []
LOG.debug(
"accepting requests (worker limit: %d, timeout: %r)", self._limit, timeout
)
LOG.debug("accepting requests (workers: %d, timeout: %r)", self._limit, timeout)
try:
while not self._job.is_complete() and self._can_continue(continue_cb):
# launch workers
Expand All @@ -149,18 +147,22 @@ def serve(self, timeout, continue_cb=None, shutdown_delay=SHUTDOWN_DELAY):

# manage workers
if running >= self._limit:
LOG.debug("worker limit (%d) hit, waiting...", len(workers))
LOG.debug("worker limit (%d) hit, waiting...", running)
if self._job.worker_complete.wait(1):
self._job.worker_complete.clear()
workers = self._join_workers(workers)
running = len(workers)
LOG.debug("removed completed workers (%d active)", running)

finally:
LOG.debug("%d requests in %0.3f seconds", launches, time() - start_time)
LOG.debug("shutting down, waiting for %d worker(s)...", len(workers))
LOG.debug(
"serve exit: %d request(s) in %0.3fs, waiting for %d worker(s)...",
launches,
time() - start_time,
running,
)
if not self._job.is_complete():
LOG.debug("job was incomplete")
LOG.debug("job not complete")
self._job.finish()
# use shutdown_delay to avoid cutting off connections
workers = self._join_workers(workers, timeout=shutdown_delay)
Expand All @@ -171,7 +173,7 @@ def serve(self, timeout, continue_cb=None, shutdown_delay=SHUTDOWN_DELAY):
worker.close()
# join remaining workers
if self._join_workers(workers, timeout=30):
LOG.error("Failed to close workers")
LOG.error("Failed to close %d workers", len(workers))
raise RuntimeError("Failed to close workers")

# return False only if there was a timeout
Expand Down
31 changes: 13 additions & 18 deletions sapphire/job.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -82,44 +82,39 @@ def __init__(
self.forever = forever
self.server_map = server_map
self.worker_complete = Event()
self._build_queue(optional_files)
self._build_pending(optional_files)

def _build_queue(self, optional_files):
def _build_pending(self, optional_files):
# build file list to track files that must be served
# this is intended to only be called once by __init__()
for entry in self._wwwroot.rglob("*"):
if not entry.is_file():
continue
location = entry.relative_to(self._wwwroot).as_posix()
# do not add optional files to queue of required files
if optional_files and location in optional_files:
LOG.debug("optional: %r", location)
continue
if "?" in str(entry):
LOG.warning(
"Cannot add files with '?' in path. Skipping %r", str(entry)
)
LOG.warning("Path cannot contain '?', skipping '%s'", entry)
continue
self._pending.files.add(str(entry.resolve()))
LOG.debug("required: %r", location)
if entry.is_file():
self._pending.files.add(str(entry.resolve()))
LOG.debug("required: %r", location)
# if nothing was found check if the path exists
if not self._pending.files and not self._wwwroot.is_dir():
raise OSError(f"'{self._wwwroot}' does not exist")
if self.server_map:
for redirect, resource in self.server_map.redirect.items():
if resource.required:
self._pending.files.add(redirect)
LOG.debug(
"%s: %r -> %r",
"required" if resource.required else "optional",
redirect,
resource.target,
)
LOG.debug("required: %r -> %r", redirect, resource.target)
for dyn_resp, resource in self.server_map.dynamic.items():
if resource.required:
self._pending.files.add(dyn_resp)
LOG.debug("%s: %r -> %r", "required", dyn_resp, resource.target)
LOG.debug("%d files required to serve", len(self._pending.files))
LOG.debug("required: %r -> %r", dyn_resp, resource.target)
LOG.debug(
"job has %d required and %d optional file(s)",
len(self._pending.files),
len(optional_files) if optional_files else 0,
)

@classmethod
def lookup_mime(cls, url):
Expand Down
21 changes: 12 additions & 9 deletions sapphire/worker.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -155,15 +155,11 @@ def handle_request(cls, conn, serv_job):
conn.sendall(
cls._4xx_page(405, "Method Not Allowed", serv_job.auto_close)
)
LOG.debug(
"405 method %r (%d to go)",
request.method,
serv_job.pending,
)
LOG.debug("405 method %r (%d to go)", request.method, serv_job.pending)
return

# lookup resource
LOG.debug("lookup_resource(%r)", request.url.path)
LOG.debug("lookup resource %r", request.url.path)
resource = serv_job.lookup_resource(request.url.path)
if resource:
if resource.type in (Resource.URL_FILE, Resource.URL_INCLUDE):
Expand All @@ -184,7 +180,12 @@ def handle_request(cls, conn, serv_job):
# send response
if resource is None:
conn.sendall(cls._4xx_page(404, "Not Found", serv_job.auto_close))
LOG.debug("404 %r (%d to go)", request.url.path, serv_job.pending)
LOG.debug(
"404 '%s%s' (%d to go)",
"..." if len(request.url.path) > 40 else "",
request.url.path[-40:],
serv_job.pending,
)
elif resource.type == Resource.URL_REDIRECT:
redirect_to = [quote(resource.target)]
if request.url.query:
Expand Down Expand Up @@ -221,10 +222,12 @@ def handle_request(cls, conn, serv_job):
LOG.debug("403 %r (%d to go)", request.url.path, serv_job.pending)
else:
# serve the file
LOG.debug("target %r", str(resource.target))
data_size = resource.target.stat().st_size
LOG.debug(
"sending: %s bytes, mime: %r", format(data_size, ","), resource.mime
"sending: %s, %r, '%s'",
f"{data_size:,}B",
resource.mime,
resource.target,
)
with resource.target.open("rb") as in_fp:
conn.sendall(cls._200_header(data_size, resource.mime))
Expand Down

0 comments on commit 0ed71bc

Please sign in to comment.