use logging instead of sentry.capture_* (#646)

This commit is contained in:
Osma Ahvenlampi 2023-10-23 19:33:55 +03:00 committed by GitHub
parent 84ded2f3a5
commit 9368996a5b
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
13 changed files with 69 additions and 95 deletions

View file

@ -1,5 +1,6 @@
import datetime
import json
import logging
import mimetypes
import ssl
from collections.abc import Iterable
@ -27,7 +28,7 @@ from activities.models.post_types import (
PostTypeDataEncoder,
QuestionData,
)
from core.exceptions import ActivityPubFormatError, capture_message
from core.exceptions import ActivityPubFormatError
from core.html import ContentRenderer, FediverseHtmlParser
from core.ld import (
canonicalise,
@ -896,7 +897,7 @@ class Post(StatorModel):
# don't have content, but this shouldn't be a total failure
post.content = get_value_or_map(data, "content", "contentMap")
except ActivityPubFormatError as err:
capture_message(f"{err} on {post.url}")
logging.warning(f"{err} on {post.url}")
post.content = None
# Document types have names, not summaries
post.summary = data.get("summary") or data.get("name")
@ -992,7 +993,7 @@ class Post(StatorModel):
try:
cls.ensure_object_uri(post.in_reply_to, reason=post.object_uri)
except ValueError:
capture_message(
logging.warning(
f"Cannot fetch ancestor of Post={post.pk}, ancestor_uri={post.in_reply_to}"
)
else:

View file

@ -1,3 +1,5 @@
import logging
from activities.models import (
Post,
PostInteraction,
@ -5,7 +7,6 @@ from activities.models import (
PostStates,
TimelineEvent,
)
from core.exceptions import capture_message
from users.models import Identity
@ -98,7 +99,7 @@ class PostService:
try:
Post.ensure_object_uri(object_uri, reason=reason)
except ValueError:
capture_message(
logging.error(
f"Cannot fetch ancestor Post={self.post.pk}, ancestor_uri={object_uri}"
)
break

View file

@ -1,8 +1,3 @@
import traceback
from django.conf import settings
class ActivityPubError(BaseException):
"""
A problem with an ActivityPub message
@ -19,29 +14,3 @@ class ActorMismatchError(ActivityPubError):
"""
The actor is not authorised to do the action we saw
"""
def capture_message(message: str, level: str | None = None, scope=None, **scope_args):
"""
Sends the informational message to Sentry if it's configured
"""
if settings.SETUP.SENTRY_DSN and settings.SETUP.SENTRY_CAPTURE_MESSAGES:
from sentry_sdk import capture_message
capture_message(message, level, scope, **scope_args)
elif settings.DEBUG:
if scope or scope_args:
message += f"; {scope=}, {scope_args=}"
print(message)
def capture_exception(exception: BaseException, scope=None, **scope_args):
"""
Sends the exception to Sentry if it's configured
"""
if settings.SETUP.SENTRY_DSN:
from sentry_sdk import capture_exception
capture_exception(exception, scope, **scope_args)
elif settings.DEBUG:
traceback.print_exc()

View file

@ -1,11 +1,12 @@
import datetime
import logging
import os
import urllib.parse as urllib_parse
from dateutil import parser
from pyld import jsonld
from core.exceptions import ActivityPubFormatError, capture_message
from core.exceptions import ActivityPubFormatError
schemas = {
"unknown": {
@ -629,7 +630,7 @@ def builtin_document_loader(url: str, options={}):
# Get URL without scheme
pieces = urllib_parse.urlparse(url)
if pieces.hostname is None:
capture_message(f"No host name for json-ld schema: {url!r}")
logging.info(f"No host name for json-ld schema: {url!r}")
return schemas["unknown"]
key = pieces.hostname + pieces.path.rstrip("/")
try:
@ -640,7 +641,7 @@ def builtin_document_loader(url: str, options={}):
return schemas[key]
except KeyError:
# return an empty context instead of throwing an error
capture_message(f"Ignoring unknown json-ld schema: {url!r}")
logging.info(f"Ignoring unknown json-ld schema: {url!r}")
return schemas["unknown"]

View file

@ -1,5 +1,6 @@
import base64
import json
import logging
from ssl import SSLCertVerificationError, SSLError
from typing import Literal, TypedDict, cast
from urllib.parse import urlparse
@ -258,7 +259,7 @@ class HttpSignature:
)
except SSLError as invalid_cert:
# Not our problem if the other end doesn't have proper SSL
print(f"{uri} {invalid_cert}")
logging.info(f"{uri} {invalid_cert}")
raise SSLCertVerificationError(invalid_cert) from invalid_cert
except InvalidCodepoint as ex:
# Convert to a more generic error we handle

View file

@ -1,3 +1,4 @@
import logging
from typing import cast
from django.apps import apps
@ -73,7 +74,9 @@ class Command(BaseCommand):
if not models:
models = StatorModel.subclasses
models = [model for model in models if model not in excluded]
print("Running for models: " + " ".join(m._meta.label_lower for m in models))
logging.info(
"Running for models: " + " ".join(m._meta.label_lower for m in models)
)
# Run a runner
runner = StatorRunner(
models,
@ -85,4 +88,4 @@ class Command(BaseCommand):
try:
runner.run()
except KeyboardInterrupt:
print("Ctrl-C received")
logging.critical("Ctrl-C received")

View file

@ -1,5 +1,5 @@
import datetime
import traceback
import logging
from typing import ClassVar
from asgiref.sync import async_to_sync, iscoroutinefunction
@ -8,7 +8,6 @@ from django.db.models.signals import class_prepared
from django.utils import timezone
from django.utils.functional import classproperty
from core import exceptions
from stator.exceptions import TryAgainLater
from stator.graph import State, StateGraph
@ -190,7 +189,7 @@ class StatorModel(models.Model):
# If it's a manual progression state don't even try
# We shouldn't really be here in this case, but it could be a race condition
if current_state.externally_progressed:
print(
logging.warning(
f"Warning: trying to progress externally progressed state {self.state}!"
)
return None
@ -204,8 +203,7 @@ class StatorModel(models.Model):
except TryAgainLater:
pass
except BaseException as e:
exceptions.capture_exception(e)
traceback.print_exc()
logging.exception(e)
else:
if next_state:
# Ensure it's a State object

View file

@ -1,8 +1,8 @@
import datetime
import logging
import os
import signal
import time
import traceback
import uuid
from concurrent.futures import Future, ThreadPoolExecutor
@ -10,7 +10,7 @@ from django.conf import settings
from django.db import close_old_connections
from django.utils import timezone
from core import exceptions, sentry
from core import sentry
from core.models import Config
from stator.models import StatorModel, Stats
@ -84,7 +84,7 @@ class StatorRunner:
self.scheduling_timer = LoopingTimer(self.schedule_interval)
self.deletion_timer = LoopingTimer(self.delete_interval)
# For the first time period, launch tasks
print("Running main task loop")
logging.info("Running main task loop")
try:
with sentry.configure_scope() as scope:
while True:
@ -137,18 +137,18 @@ class StatorRunner:
pass
# Wait for tasks to finish
print("Waiting for tasks to complete")
logging.info("Waiting for tasks to complete")
self.executor.shutdown()
# We're done
print("Complete")
logging.info("Complete")
def alarm_handler(self, signum, frame):
"""
Called when SIGALRM fires, which means we missed a schedule loop.
Just exit as we're likely deadlocked.
"""
print("Watchdog timeout exceeded")
logging.warning("Watchdog timeout exceeded")
os._exit(2)
def load_config(self):
@ -165,7 +165,9 @@ class StatorRunner:
for model in self.models:
num = self.handled.get(model._meta.label_lower, 0)
if num or settings.DEBUG:
print(f"{model._meta.label_lower}: Scheduling ({num} handled)")
logging.info(
f"{model._meta.label_lower}: Scheduling ({num} handled)"
)
self.submit_stats(model)
model.transition_clean_locks()
@ -237,8 +239,7 @@ class StatorRunner:
try:
task.result()
except BaseException as e:
exceptions.capture_exception(e)
traceback.print_exc()
logging.exception(e)
def run_single_cycle(self):
"""
@ -268,11 +269,11 @@ def task_transition(instance: StatorModel, in_thread: bool = True):
result = instance.transition_attempt()
duration = time.monotonic() - started
if result:
print(
logging.info(
f"{instance._meta.label_lower}: {instance.pk}: {instance.state} -> {result} ({duration:.2f}s)"
)
else:
print(
logging.info(
f"{instance._meta.label_lower}: {instance.pk}: {instance.state} unchanged ({duration:.2f}s)"
)
if in_thread:
@ -288,7 +289,7 @@ def task_deletion(model: type[StatorModel], in_thread: bool = True):
deleted = model.transition_delete_due()
if not deleted:
break
print(f"{model._meta.label_lower}: Deleted {deleted} stale items")
logging.info(f"{model._meta.label_lower}: Deleted {deleted} stale items")
time.sleep(1)
if in_thread:
close_old_connections()

View file

@ -11,7 +11,6 @@ import httpx
import sentry_sdk
from corsheaders.defaults import default_headers
from pydantic import AnyUrl, BaseSettings, EmailStr, Field, validator
from sentry_sdk.integrations.django import DjangoIntegration
from takahe import __version__
@ -368,7 +367,9 @@ if SETUP.USE_PROXY_HEADERS:
if SETUP.SENTRY_DSN:
from sentry_sdk.integrations.django import DjangoIntegration
from sentry_sdk.integrations.httpx import HttpxIntegration
from sentry_sdk.integrations.logging import LoggingIntegration
sentry_experiments = {}
@ -382,6 +383,7 @@ if SETUP.SENTRY_DSN:
integrations=[
DjangoIntegration(),
HttpxIntegration(),
LoggingIntegration(),
],
traces_sample_rate=SETUP.SENTRY_TRACES_SAMPLE_RATE,
sample_rate=SETUP.SENTRY_SAMPLE_RATE,

View file

@ -1,4 +1,5 @@
import json
import logging
import ssl
from functools import cached_property
from typing import Optional
@ -9,7 +10,6 @@ import urlman
from django.conf import settings
from django.db import models
from core.exceptions import capture_message
from core.models import Config
from stator.models import State, StateField, StateGraph, StatorModel
from users.schemas import NodeInfo
@ -209,9 +209,9 @@ class Domain(StatorModel):
and response.status_code < 500
and response.status_code not in [401, 403, 404, 406, 410]
):
capture_message(
logging.warning(
f"Client error fetching nodeinfo: {str(ex)}",
extras={
extra={
"code": response.status_code,
"content": response.content,
"domain": self.domain,
@ -223,9 +223,9 @@ class Domain(StatorModel):
try:
info = NodeInfo(**response.json())
except (json.JSONDecodeError, pydantic.ValidationError) as ex:
capture_message(
logging.warning(
f"Client error decoding nodeinfo: {str(ex)}",
extras={
extra={
"domain": self.domain,
"nodeinfo20_url": nodeinfo20_url,
},

View file

@ -1,9 +1,9 @@
import logging
from typing import Optional
import httpx
from django.db import models, transaction
from core.exceptions import capture_message
from core.ld import canonicalise, get_str_or_id
from core.snowflake import Snowflake
from stator.models import State, StateField, StateGraph, StatorModel
@ -350,8 +350,8 @@ class Follow(StatorModel):
try:
follow = cls.by_ap(data, create=True)
except Identity.DoesNotExist:
capture_message(
"Identity not found for incoming Follow", extras={"data": data}
logging.info(
"Identity not found for incoming Follow", extra={"data": data}
)
return
if follow.state == FollowStates.accepted:
@ -367,9 +367,9 @@ class Follow(StatorModel):
try:
follow = cls.by_ap(data["object"])
except (cls.DoesNotExist, Identity.DoesNotExist):
capture_message(
logging.info(
"Follow or Identity not found for incoming Accept",
extras={"data": data},
extra={"data": data},
)
return
@ -389,9 +389,9 @@ class Follow(StatorModel):
try:
follow = cls.by_ap(data["object"])
except (cls.DoesNotExist, Identity.DoesNotExist):
capture_message(
logging.info(
"Follow or Identity not found for incoming Reject",
extras={"data": data},
extra={"data": data},
)
return
@ -419,8 +419,8 @@ class Follow(StatorModel):
try:
follow = cls.by_ap(data["object"])
except (cls.DoesNotExist, Identity.DoesNotExist):
capture_message(
"Follow or Identity not found for incoming Undo", extras={"data": data}
logging.info(
"Follow or Identity not found for incoming Undo", extra={"data": data}
)
return

View file

@ -1,3 +1,4 @@
import logging
import ssl
from functools import cached_property, partial
from typing import Literal, Optional
@ -11,7 +12,7 @@ from django.utils import timezone
from django.utils.functional import lazy
from lxml import etree
from core.exceptions import ActorMismatchError, capture_message
from core.exceptions import ActorMismatchError
from core.html import ContentRenderer, FediverseHtmlParser
from core.ld import (
canonicalise,
@ -871,9 +872,9 @@ class Identity(StatorModel):
# Their account got deleted, so let's do the same.
Identity.objects.filter(pk=self.pk).delete()
if status_code < 500 and status_code not in [401, 403, 404, 406, 410]:
capture_message(
logging.info(
f"Client error fetching actor at {self.actor_uri}: {status_code}",
extras={
extra={
"identity": self.pk,
"domain": self.domain_id,
"content": response.content,
@ -884,9 +885,9 @@ class Identity(StatorModel):
document = canonicalise(response.json(), include_security=True)
except ValueError:
# servers with empty or invalid responses are inevitable
capture_message(
logging.info(
f"Invalid response fetching actor at {self.actor_uri}",
extras={
extra={
"identity": self.pk,
"domain": self.domain_id,
"content": response.content,

View file

@ -1,4 +1,5 @@
import json
import logging
from django.conf import settings
from django.http import Http404, HttpResponse, HttpResponseBadRequest, JsonResponse
@ -9,7 +10,6 @@ from django.views.generic import View
from activities.models import Post
from activities.services import TimelineService
from core import exceptions
from core.decorators import cache_page
from core.ld import canonicalise
from core.models import Config
@ -140,6 +140,10 @@ class Inbox(View):
# Find the Identity by the actor on the incoming item
# This ensures that the signature used for the headers matches the actor
# described in the payload.
if "actor" not in document:
logging.warning("Inbox error: unspecified actor")
return HttpResponseBadRequest("Unspecified actor")
identity = Identity.by_actor_uri(document["actor"], create=True, transient=True)
if (
document["type"] == "Delete"
@ -154,23 +158,19 @@ class Inbox(View):
try:
identity.fetch_actor()
except TryAgainLater:
exceptions.capture_message(
logging.warning(
f"Inbox error: timed out fetching actor {document['actor']}"
)
return HttpResponse(status=504)
if not identity.public_key:
exceptions.capture_message(
f"Inbox error: cannot fetch actor {document['actor']}"
)
logging.warning(f"Inbox error: cannot fetch actor {document['actor']}")
return HttpResponseBadRequest("Cannot retrieve actor")
# See if it's from a blocked user or domain
if identity.blocked or identity.domain.recursively_blocked():
# I love to lie! Throw it away!
exceptions.capture_message(
f"Inbox: Discarded message from {identity.actor_uri}"
)
logging.warning(f"Inbox: Discarded message from {identity.actor_uri}")
return HttpResponse(status=202)
# If there's a "signature" payload, verify against that
@ -178,12 +178,10 @@ class Inbox(View):
try:
LDSignature.verify_signature(document, identity.public_key)
except VerificationFormatError as e:
exceptions.capture_message(
f"Inbox error: Bad LD signature format: {e.args[0]}"
)
logging.warning(f"Inbox error: Bad LD signature format: {e.args[0]}")
return HttpResponseBadRequest(e.args[0])
except VerificationError:
exceptions.capture_message("Inbox error: Bad LD signature")
logging.warning("Inbox error: Bad LD signature")
return HttpResponseUnauthorized("Bad signature")
# Otherwise, verify against the header (assuming it's the same actor)
@ -194,12 +192,10 @@ class Inbox(View):
identity.public_key,
)
except VerificationFormatError as e:
exceptions.capture_message(
f"Inbox error: Bad HTTP signature format: {e.args[0]}"
)
logging.warning(f"Inbox error: Bad HTTP signature format: {e.args[0]}")
return HttpResponseBadRequest(e.args[0])
except VerificationError:
exceptions.capture_message("Inbox error: Bad HTTP signature")
logging.warning("Inbox error: Bad HTTP signature")
return HttpResponseUnauthorized("Bad signature")
# Don't allow injection of internal messages