ATProto send: `assert did` crash

snarfed commented 3 months ago

We've been seeing a steady trickle of this one for a while. Why?!

https://console.cloud.google.com/errors/detail/CMHloZaRmPXQZQ;time=P1D;locations=global?project=bridgy-federated

https://github.com/snarfed/bridgy-fed/blob/3acde571ad8c4be57c5a66e89b1671bc5baee54c/atproto.py#L505-L508

Params: [
  ('obj', 'ahBicmlkZ3ktZmVkZXJhdGVkcmoLEgZPYmplY3QiXmh0dHBzOi8vd3d3LmhibC5maS9hcnRpa2VsL2xhc3Qtb2NoLWhvcnQtZnJhbi1vc3MtYWxsYS10aWxsLWVyLWFsbGEtZW4tcmlrdGlndC1sZXNiaXNrLXNvbW1hci8M'),
  ('orig_obj', ''),
  ('protocol', 'atproto'),
  ('url', 'https://atproto.brid.gy'),
  ('user', 'ahBicmlkZ3ktZmVkZXJhdGVkchQLEghNYWdpY0tleSIGaGJsLmZpDA')
]
Sending atproto post https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/ to https://atproto.brid.gy
Using server at https://api.bsky.app
Can't translate object id https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/ to atproto , haven't copied it there yet!
Can't translate user id www.hbl.fi to atproto , haven't copied it there yet!
Using server at https://bsky.social/
Defaulting username to key id www.hbl.fi

Traceback (most recent call last):
  File "/workspace/protocol.py", line 1674, in send_task
    sent = PROTOCOLS[protocol].send(obj, url, from_user=user, orig_obj=orig_obj)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/workspace/atproto.py", line 508, in send
    assert did
           ^^^
AssertionError"

snarfed commented 3 months ago

This example is from https://bsky.app/profile/hbl.fi.web.brid.gy . The object AS1 (below) has actor: www.hbl.fi, but the Web user is hbl.fi, no www, and interestingly the stored Web user for www.hbl.fi doesn't have use_instead. Why not?

This in ATProto.send before the assert ends up with www.hbl.fi's key, not hbl.fi's.

https://github.com/snarfed/bridgy-fed/blob/5f1a99d6cda36e9d4504e6db3d03c146fcb4a0ea/atproto.py#L500

{
  "objectType": "activity",
  "verb": "post",
  "id": "https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/",
  "url": "https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/",
  "actor": {
    "displayName": "Elliot Lundeg\u00e5rd",
    "id": "https://www.hbl.fi/"
  },
  "object": {
    "objectType": "article",
    "id": "https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/",
    "url": "https://www.hbl.fi/artikel/last-och-hort-fran-oss-alla-till-er-alla-en-riktigt-lesbisk-sommar/",
    "displayName": "L\u00e4st & h\u00f6rt: Fr\u00e5n oss alla till er alla \u2013 en riktigt lesbisk sommar",
    "content": "Den har kallats f\u00f6r \u201den lesbisk ren\u00e4ssans\u201d \u2013 sommaren 2024 domineras topplistorna av queera kvinnor. Elliot Lundeg\u00e5rd reflekterar kring synlighet, trendighet och f\u00f6r\u00e4ndring.",
    "published": "2024-08-03T12:00:00+00:00",
    "updated": "2024-08-03T12:00:00.106000+00:00",
    "author": {
      "displayName": "Elliot Lundeg\u00e5rd",
      "id": "https://www.hbl.fi/"
    },
    "image": [
      {
        "url": "https://static.bonniernews.se/bildix/api/images/69db87c3-4bc8-5930-aa0f-9a22c07e63c0.jpeg",
        "mimeType": "image/jpeg",
        "displayName": "Billie Eilish \u00e4r en av de popstj\u00e4rnor som sl\u00e4ppt explicit lesbiska l\u00e5tar under \u00e5ret."
      },
      {
        "url": "https://static.bonniernews.se/bildix/api/images/63915c0d-e2e4-537a-91e4-1f85284207e6.jpeg",
        "mimeType": "image/jpeg"
      },
      {
        "url": "https://static.bonniernews.se/bildix/api/images/dde61024-ebb4-492b-a77e-1e69fdf7bf37.jpeg",
        "mimeType": "image/jpeg"
      }
    ]
  },
  "title": "L\u00e4st & h\u00f6rt: Fr\u00e5n oss alla till er alla \u2013 en riktigt lesbisk sommar",
  "feed_index": 8
}

snarfed commented 3 months ago

Log from when we created this user, 2024-07-30T09:13:31.892275Z :

Params: [('url', 'https://www.hbl.fi/')]
requests.get https://hbl.fi/ {'gateway': False}
Redirected to https://www.hbl.fi/
Received 200
https://hbl.fi/ is user's web url
Found representative h-card
Extracted microformats2 entry: {   "type": [     "h-card"   ],   "properties": {     "summary": [       "St\u00f6rst i Svenskfinland"     ],     "name": [       "Hufvudstadsbladet"     ],     "photo": [       "https://www.hbl.fi/assets/static/hbl/favicon.ico",       "https://www.hbl.fi/assets/static/hbl/favicon.svg"     ],     "url": [       "https://www.hbl.fi/"     ]   },   "rel-urls": {     "https://static.bonniernews.se": {       "text": "",       "rels": [         "preconnect"       ]     },     "https://www.hbl.fi/assets/static/hbl/favicon.ico": {       "text": "",       "rels": [         "icon"       ],       "type": "image/x-icon"     },     "https://www.hbl.fi/assets/static/hbl/favicon.svg": {       "text": "",       "rels": [         "icon"       ],       "type": "image/svg+xml"     },     "https://www.hbl.fi/assets/static/hbl/mask.svg": {       "text": "",       "rels": [         "mask-icon"       ]     },     "https://www.hbl.fi/assets/static/hbl/apple-icon-v2.png": {       "text": "",       "rels": [         "apple-touch-icon"       ]     },     "https://www.hbl.fi/assets/rev/css/main.24f4b37c5e6b38a5db55.css": {       "text": "",       "rels": [         "stylesheet"       ]     },     "https://www.hbl.fi/assets/rev/fonts/Inter.var.57b5363aaa460506e9ea.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-semibold.036b591334b60073f47f.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-fine-web-black.fb835351d631e9b40136.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-light.5e8f737cd94c9c5f1015.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-text-web-regular.7d580ec23fa19f606404.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/": {       "text": "",       "rels": [         "canonical"       ]     },     "https://www.hbl.fi/feeds/feed.xml": {       "text": "",       "rels": [         "alternate"       ],       "type": "application/rss+xml",       "title": "HBL RSS"     },     "https://www.hbl.fi/2024-06-14/far-och-son-westerlund-gilla… [message truncated due to size]
Creating new did:plc for Key('MagicKey', 'hbl.fi') hbl.fi.web.brid.gy https://atproto.brid.gy
Generating new k256 signing key
Generating new k256 rotation key
Generating and signing PLC directory genesis operation...
  did:plc:dla27ojnu3ilfo6k6q7ashbv
Publishing to https://plc.directory/did:plc:dla27ojnu3ilfo6k6q7ashbv  ...
requests.post https://plc.directory/did:plc:dla27ojnu3ilfo6k6q7ashbv ...
Received 200
<Response [200]> b'OK'
adding GCP DNS TXT record for _atproto.hbl.fi.web.brid.gy. "did=did:plc:dla27ojnu3ilfo6k6q7ashbv"
Checking for existing record
done!
Using server at https://bsky.social/
requests.get https://www.hbl.fi/assets/static/hbl/favicon.ico {}
Received 200
Creating new AtpRemoteBlob for https://www.hbl.fi/assets/static/hbl/favicon.ico CID bafkreidzvkap3aphksr4dnj44zvxstfoeqjk2gji6wkoiikjgerwxrrv5q
requests.get https://www.hbl.fi/assets/static/hbl/favicon.svg {}
Received 200
Creating new AtpRemoteBlob for https://www.hbl.fi/assets/static/hbl/favicon.svg CID bafkreign6vuxmlluvsyqzsuvewhkedkif2p7nnvz37onywlzkq3ufayvqq
Using server at https://api.bsky.app
Signing with Key('MagicKey', 'fed.brid.gy')'s key
requests.get https://www.hbl.fi/ {'data': None, 'auth': <httpsig.requests_auth.HTTPSignatureAuth object at 0x3ea2e7fb1650>, 'headers': {'Accept': '...', 'Date': '...', 'Host': '...', 'Content-Type': '...', 'Digest': '...'}, 'gateway': True}
Received 200: 
Received 200
no AS2 available
requests.get https://www.hbl.fi/ {'gateway': False}
Received 200
https://www.hbl.fi/ is user's web url
Found representative h-card
Extracted microformats2 entry: {   "type": [     "h-card"   ],   "properties": {     "summary": [       "St\u00f6rst i Svenskfinland"     ],     "name": [       "Hufvudstadsbladet"     ],     "photo": [       "https://www.hbl.fi/assets/static/hbl/favicon.ico",       "https://www.hbl.fi/assets/static/hbl/favicon.svg"     ],     "url": [       "https://www.hbl.fi/"     ]   },   "rel-urls": {     "https://static.bonniernews.se": {       "text": "",       "rels": [         "preconnect"       ]     },     "https://www.hbl.fi/assets/static/hbl/favicon.ico": {       "text": "",       "rels": [         "icon"       ],       "type": "image/x-icon"     },     "https://www.hbl.fi/assets/static/hbl/favicon.svg": {       "text": "",       "rels": [         "icon"       ],       "type": "image/svg+xml"     },     "https://www.hbl.fi/assets/static/hbl/mask.svg": {       "text": "",       "rels": [         "mask-icon"       ]     },     "https://www.hbl.fi/assets/static/hbl/apple-icon-v2.png": {       "text": "",       "rels": [         "apple-touch-icon"       ]     },     "https://www.hbl.fi/assets/rev/css/main.24f4b37c5e6b38a5db55.css": {       "text": "",       "rels": [         "stylesheet"       ]     },     "https://www.hbl.fi/assets/rev/fonts/Inter.var.57b5363aaa460506e9ea.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-semibold.036b591334b60073f47f.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-fine-web-black.fb835351d631e9b40136.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-light.5e8f737cd94c9c5f1015.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-text-web-regular.7d580ec23fa19f606404.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/": {       "text": "",       "rels": [         "canonical"       ]     },     "https://www.hbl.fi/feeds/feed.xml": {       "text": "",       "rels": [         "alternate"       ],       "type": "application/rss+xml",       "title": "HBL RSS"     },     "https://www.hbl.fi/2024-06-14/far-och-son-westerlund-gilla… [message truncated due to size]
Can't translate user id www.hbl.fi to atproto , haven't copied it there yet!
Storing ATProto app.bsky.actor.profile self
Storing ATProto chat declaration record
Stored repo AtpRepo(key=Key('AtpRepo', 'did:plc:dla27ojnu3ilfo6k6q7ashbv'), created=datetime.datetime(2024, 7, 30, 9, 13, 38, 44899), handles=['hbl.fi.web.brid.gy'], head='bafyreiapb4krhhwmwjplk57x4gqjtg3jts6m7sinabgddfmnnpq2b47eqe', ...
Added atproto-commit task projects/bridgy-federated/locations/us-central1/queues/atproto-commit/tasks/89965956743136732631 : {}
Defaulting username to key id hbl.fi
Defaulting username to key id hbl.fi
Created new Web(key=Key('MagicKey', 'hbl.fi'), ap_subdomain='web', copies=[Target(protocol='atproto', uri='did:plc:dla27ojnu3ilfo6k6q7ashbv')], created=datetime.datetime(2024, 7, 30, 9, 13, 38, 61035), direct=True, enabled_protocols=['atproto'], handle='hbl.fi', ..., obj_key=Key('Object', 'https://hbl.fi/'), ..., public_exponent='AQAB', readable_id=None, status=None, updated=datetime.datetime(2024, 7, 30, 9, 13, 40, 542866))
Added poll-feed task projects/bridgy-federated/locations/us-central1/queues/poll-feed/tasks/7915297727397230283 : {'domain': 'hbl.fi'}
Verifying hbl.fi
requests.get https://hbl.fi/.well-known/webfinger?resource=acct:hbl.fi@hbl.fi {'gateway': False}
Redirected to https://www.hbl.fi/.well-known/webfinger?resource=acct:hbl.fi@hbl.fi
Received 404
requests.get https://hbl.fi/ {'gateway': True}
Received 200: 
Redirected to https://www.hbl.fi/
Received 200
https://hbl.fi/ is user's web url
Found representative h-card
Extracted microformats2 entry: {   "type": [     "h-card"   ],   "properties": {     "summary": [       "St\u00f6rst i Svenskfinland"     ],     "name": [       "Hufvudstadsbladet"     ],     "photo": [       "https://www.hbl.fi/assets/static/hbl/favicon.ico",       "https://www.hbl.fi/assets/static/hbl/favicon.svg"     ],     "url": [       "https://www.hbl.fi/"     ]   },   "rel-urls": {     "https://static.bonniernews.se": {       "text": "",       "rels": [         "preconnect"       ]     },     "https://www.hbl.fi/assets/static/hbl/favicon.ico": {       "text": "",       "rels": [         "icon"       ],       "type": "image/x-icon"     },     "https://www.hbl.fi/assets/static/hbl/favicon.svg": {       "text": "",       "rels": [         "icon"       ],       "type": "image/svg+xml"     },     "https://www.hbl.fi/assets/static/hbl/mask.svg": {       "text": "",       "rels": [         "mask-icon"       ]     },     "https://www.hbl.fi/assets/static/hbl/apple-icon-v2.png": {       "text": "",       "rels": [         "apple-touch-icon"       ]     },     "https://www.hbl.fi/assets/rev/css/main.24f4b37c5e6b38a5db55.css": {       "text": "",       "rels": [         "stylesheet"       ]     },     "https://www.hbl.fi/assets/rev/fonts/Inter.var.57b5363aaa460506e9ea.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-semibold.036b591334b60073f47f.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-fine-web-black.fb835351d631e9b40136.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-headline-web-light.5e8f737cd94c9c5f1015.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/assets/rev/fonts/tiempos-text-web-regular.7d580ec23fa19f606404.woff2": {       "text": "",       "rels": [         "preload"       ],       "type": "font/woff2"     },     "https://www.hbl.fi/": {       "text": "",       "rels": [         "canonical"       ]     },     "https://www.hbl.fi/feeds/feed.xml": {       "text": "",       "rels": [         "alternate"       ],       "type": "application/rss+xml",       "title": "HBL RSS"     },     "https://www.hbl.fi/2024-06-14/far-och-son-westerlund-gilla… [message truncated due to size]
Defaulting username to key id hbl.fi

snarfed commented 3 months ago

Culprit HTTP request that created www.hbl.fi without use_instead was an AP actor request for /www.hbl.fi at 2024-07-30 18:08:38.915 UTC:

Defaulting username to key id www.hbl.fi
Created new Web(key=Key('MagicKey', 'www.hbl.fi'), ap_subdomain='web', copies=[], created=datetime.datetime(2024, 7, 30, 18, 8, 38, 914872), direct=False, enabled_protocols=[], handle='www.hbl.fi', ..., obj_key=Key('Object', 'https://www.hbl.fi/'), ..., public_exponent='AQAB', readable_id=None, status=None, updated=datetime.datetime(2024, 7, 30, 18, 8, 38, 919619))
Defaulting username to key id www.hbl.fi

snarfed commented 3 months ago

Currently running this to backfill all the use_insteads:

wwws = Web.query(
  Web.use_instead == None,
  Web.key > Web(id='www.').key,
  Web.key < Web(id='www/').key).fetch()
len(wwws)  # 551

roots = ndb.get_multi(Web(id=w.key.id().removeprefix('www.')).key for w in wwws)
len([r for r in roots if r])  # 382

for i, (www, root) in enumerate(zip(wwws, roots)):
  if not root or not www.obj_key:
    continue
  print(i)
  assert www.key.id() == 'www.' + root.key.id()
  www.use_instead = root.key
  www.put()

snarfed / bridgy-fed

ATProto send: `assert did` crash #1232