snarfed / bridgy-fed

🌉 A bridge between decentralized social network protocols
https://fed.brid.gy
Creative Commons Zero v1.0 Universal
644 stars 31 forks source link

Protocol.receive: HTTP fetch errors stop processing #885

Closed snarfed closed 1 month ago

snarfed commented 8 months ago

We got an incoming AP reply recently that hit a timeout on an HTTP fetch during processing. The inbox delivery request short circuited out and didn't finish processing, and when the remote instance retried, we didn't finish it because we saw that we'd already processed it. Argh.

Log:

2024-02-15 16:29:57.509 PT, trace_id=30961271cf16f537cab8eb2ed19f81c0
Got Create from https://hachyderm.io/users/thisismissem: ...
Verifying HTTP Signature
Loading Object https://hachyderm.io/users/thisismissem local=True remote=None
  got from datastore
Verifying signature for /www.jvt.me/inbox with key ...
HTTP Signature verified!
From activitypub: Key('Object', 'https://hachyderm.io/users/thisismissem/statuses/111938332047014307/activity') AS1: ...
Loading Object https://hachyderm.io/users/thisismissem/statuses/111938332047014307/activity local=True remote=False
 not in datastore
Wrote Key('Object', 'https://hachyderm.io/users/thisismissem/statuses/111938332047014307/activity') {'as2': '...', 'labels': ['activity'], 'object_ids': ['https://hachyderm.io/users/thisismissem/statuses/111938332047014307'], 'our_as1': '...', 'type': 'post', 'new': True}
Wrote Key('Object', 'https://hachyderm.io/users/thisismissem/statuses/111938332047014307/activity') {'as2': '...', 'labels': ['activity'], 'object_ids': ['https://hachyderm.io/users/thisismissem/statuses/111938332047014307'], 'our_as1': '...', 'source_protocol': 'activitypub', 'type': 'post', 'users': [Key('ActivityPub', 'https://hachyderm.io/users/thisismissem')], 'new': True}
Wrote Key('Object', 'https://hachyderm.io/users/thisismissem/statuses/111938332047014307') {'our_as1': '...', 'source_protocol': 'activitypub', 'type': 'comment', 'new': True}
Fetching actor so we have name, profile photo, etc
Loading Object https://hachyderm.io/users/thisismissem local=True remote=None
  got from cache
Finding recipients and their targets
Raw targets: ['https://tantek.com/', 'https://tantek.com/2024/046/t1/the-ephemeral-web']
Loading Object https://tantek.com/2024/046/t1/the-ephemeral-web local=True remote=None
  got from cache
Loading Object https://tantek.com/ local=True remote=None
  got from datastore
  last updated 2024-01-02 16:54:18.884276, refreshing
requests.get https://tantek.com/ {'gateway': False}
<class 'requests.exceptions.ReadTimeout'>: HTTPSConnectionPool(host='tantek.com', port=443): Read timed out. (read timeout=15)
Connection failure: HTTPSConnectionPool(host='tantek.com', port=443): Read timed out. (read timeout=15)
Converting code None to 504
snarfed commented 8 months ago

cc @tantek

snarfed commented 5 months ago

1114 is another instance of this; logs below.

During protocol inference for https://fruef.social/about, we fetched it as AS2, and it returned 403 because that instance blocks brid.gy: https://fruef.social/users/FRUEFpodcast . That exception propagated up too far and stopped the rest of Protocol.receive processing.

Running receive task 1253782312667723502
Params: [('authed_as', 'https://det.social/users/HerrGuenni'), ('obj', 'ahBicmlkZ3ktZmVkZXJhdGVkclQLEgZPYmplY3QiSGh0dHBzOi8vZGV0LnNvY2lhbC91c2Vycy9IZXJyR3Vlbm5pL3N0YXR1c2VzLzExMjU2Mzc4MDgzODA3NTk5MS9hY3Rpdml0eQw')]
From activitypub: Key('Object', 'https://det.social/users/HerrGuenni/statuses/112563780838075991/activity') AS1: ...
Normalizing ids
Determining protocol for id https://mstdn.social/users/MillernTon
  Key('Object', 'https://mstdn.social/users/MillernTon') owned by source_protocol activitypub
...
Resolving activitypub ids; originals: {}
Wrote Key('Object', 'https://det.social/users/HerrGuenni/statuses/112563780838075991/activity')
Wrote Key('Object', 'https://det.social/users/HerrGuenni/statuses/112563780838075991')
Fetching actor so we have name, profile photo, etc
Finding recipients and their targets
Raw targets: ['https://a.gup.pe/u/fcsp', 'https://a.gup.pe/u/fussball', 'https://anonsys.net/profile/fussball', 'https://fruef.social/users/FRUEFpodcast', 'https://fruef.social/users/legendeverloren', 'https://machteburch.social/users/FCMPodcast', 'https://mastodon.social/users/hoerfehler', 'https://mstdn.social/users/MillernTon', 'https://podcasts.social/users/DerFussballPod', 'https://podcasts.social/users/brennpunkt', 'https://podcasts.social/users/rasenfunk', 'https://podcasts.social/users/weserfunk', 'https://social.anoxinon.de/users/SVMeppenPodcast', 'https://troet.cafe/users/fussballliebe']
...
Determining protocol for id https://fruef.social/users/FRUEFpodcast
  Key('Object', 'https://fruef.social/users/FRUEFpodcast') owned by source_protocol activitypub
Signing with Key('MagicKey', 'fed.brid.gy')'s key
requests.get https://fruef.social/users/FRUEFpodcast {'data': None, 'auth': <httpsig.requests_auth.HTTPSignatureAuth object at 0x7da0a08d80d0>, 'headers': {'Accept': '...', 'Date': '...', 'Host': '...', 'Content-Type': '...', 'Digest': '...'}, 'gateway': True}
Received 403: {"error":"Public key not found for key https://fed.brid.gy/fed.brid.gy#key"}
403 Client Error: Forbidden for url: https://fruef.social/users/FRUEFpodcast ; {"error":"Public key not found for key https://fed.brid.gy/fed.brid.gy#key"}
  File "/layers/google.python.pip/pip/lib/python3.11/site-packages/oauth_dropins/webutil/util.py", line 1694, in call
     resp.raise_for_status()
    File "/layers/google.python.pip/pip/lib/python3.11/site-packages/requests/models.py", line 1024, in raise_for_status
     raise HTTPError(http_error_msg, response=self)
snarfed commented 1 month ago

^ Hopefully fixed. @jamietanna @tantek feel free to reopen if you see this again!