ErrorFrameHeader.__init__() got an unexpected keyword argument 't'

[adonoho]

This has been happening every few days, 10/25-11/12. Now happening every several hours.

Traceback (most recent call last):
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 266, in start
    _handle_frame_decoding_error(e)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 66, in _handle_frame_decoding_error
    raise exception
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 263, in start
    frame = _get_message_frame_from_bytes_or_raise(raw_frame)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 83, in _get_message_frame_from_bytes_or_raise
    frame = Frame.from_bytes(data)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/models.py", line 126, in from_bytes
    header = parse_frame_header(raw_header)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/models.py", line 59, in parse_frame_header
    return get_or_create(raw_header, ErrorFrameHeader)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 69, in get_or_create
    raise e
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 62, in get_or_create
    model_instance = _get_or_create(model_data, model, strict=strict)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 101, in _get_or_create
    return model(**model_data)
TypeError: ErrorFrameHeader.__init__() got an unexpected keyword argument 't'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 341, in <module>
    IOLoop().run_sync(run_it)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/tornado/ioloop.py", line 539, in run_sync
    return future_cell[0].result()
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 338, in run_it
    await async_monitor_bsky_firehose (lambda item: is_post (item),
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 307, in async_monitor_bsky_firehose
    await firehose.start(lambda message: async_on_message(message, test_function, handler))
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 271, in start
    should_stop = _handle_websocket_error_or_stop(e)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 79, in _handle_websocket_error_or_stop
    raise FirehoseError from exception
atproto_firehose.exceptions.FirehoseError

The code that calls the atproto library is straightforward:

async def async_monitor_bsky_firehose(test_function, handler):
    firehose = hose.AsyncFirehoseSubscribeReposClient()
    await firehose.start(lambda message: async_on_message(message, test_function, handler))

Happy to dig deeper.

Anon,
Andrew

[MarshalX]

Interesting. That's a super rare case when firehose returns error frames. Maybe started happened because of some server changes or new load challenges. Probably just a simple deserialization bug around ErrorFrameHeader on SDK side.

[adonoho]

Not as rare an error as you might hope. Happening multiple times since the first issue raise. This is from a few minutes ago.

Traceback (most recent call last):
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 221, in _process_message_frame
    await self._on_message_callback(frame)
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 91, in async_on_message
    blocks = atproto.CAR.from_bytes(message.blocks).blocks
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_core/car/car.py", line 51, in from_bytes
    header, blocks = libipld.decode_car(data)
ValueError: Failed to read CAR header. Invalid uvarint
Traceback (most recent call last):
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 266, in start
    _handle_frame_decoding_error(e)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 66, in _handle_frame_decoding_error
    raise exception
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 263, in start
    frame = _get_message_frame_from_bytes_or_raise(raw_frame)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 83, in _get_message_frame_from_bytes_or_raise
    frame = Frame.from_bytes(data)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/models.py", line 126, in from_bytes
    header = parse_frame_header(raw_header)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/models.py", line 59, in parse_frame_header
    return get_or_create(raw_header, ErrorFrameHeader)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 69, in get_or_create
    raise e
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 62, in get_or_create
    model_instance = _get_or_create(model_data, model, strict=strict)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_client/models/utils.py", line 101, in _get_or_create
    return model(**model_data)
TypeError: ErrorFrameHeader.__init__() got an unexpected keyword argument 't'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 341, in <module>
    IOLoop().run_sync(run_it)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/tornado/ioloop.py", line 539, in run_sync
    return future_cell[0].result()
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 338, in run_it
    await async_monitor_bsky_firehose (lambda item: is_post (item),
  File "/Users/awd/Projects/PhenomML/BSky2GBQ/main.py", line 307, in async_monitor_bsky_firehose
    await firehose.start(lambda message: async_on_message(message, test_function, handler))
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 271, in start
    should_stop = _handle_websocket_error_or_stop(e)
  File "/Users/awd/miniforge3/envs/bsky/lib/python3.10/site-packages/atproto_firehose/client.py", line 79, in _handle_websocket_error_or_stop
    raise FirehoseError from exception
atproto_firehose.exceptions.FirehoseError

[MarshalX]

Today evening they have maintenance xDD

[MarshalX]

I will look at this closer since we need to fix it first before touching, for example, jet streams

[adonoho]

I am happy to help but I know nothing about this stack. IOW, if you need me to instrument my stack, I'm happy to do so. We capture the firehose as the beginning of a research project at the University with which I volunteer. No one is depending upon 24x7 operation.

[MarshalX]

I checked the code. It looks legit... Super strange that this happens. Maybe another server side bug... So from the docs:

t ("type", string, optional): required if op is 1, indicating the Lexicon sub-type for this message, in short form. Does not include the full Lexicon identifier, just a fragment. Eg: #commit. Should not be included in header if op is -1. (https://atproto.com/specs/event-stream#streaming-wire-protocol-v0)

And we are getting op = -1... because:

atproto/packages/atproto_firehose/models.py

Lines 52 to 59 in d030829

	header_op = int(raw_header.get('op', 0))
	if not FrameType.has_value(header_op):
	raise FirehoseDecodingError('Invalid frame type')
	frame_type = FrameType(header_op)
	if frame_type is FrameType.MESSAGE:
	return get_or_create(raw_header, MessageFrameHeader)
	return get_or_create(raw_header, ErrorFrameHeader)

• line 52 fallback to op 0 if missing
• line 53 checks that the op is 1 or -1
• and we are failing on line 59. which means that op is -1 for sure...

but somehow, header with -1 contains t field. which should not occur at all (according to the official docs)

upd. it will be awesome if you could log the value of "raw_header"!

[justin-pierce]

been experiencing this a lot

when I print raw_header right before the exception, it's simply:

raw_header: {'t': '', 'op': -1}

[MarshalX]

so backend started to send empty string with op=-1... but empty string is not true optional field?