I set up the Meta Bridge for Facebook Messenger using double puppeting, running both the bridge and my Synapse Matrix home server in Docker containers. However, I'm facing an issue when trying to send messages to users who turned on the new end-to-end encryption in Messenger. On the flip side, I can still chat with users who haven't enabled this encryption feature. Since I couldn't find anything about this in the documentation, I'm reporting it as a bug.
2024-01-29T11:37:50Z DBG decode.go:129:Decode() > Facebook server log: Write error response from server global_log=true
2024-01-29T11:37:50Z WRN decode.go:210:handleStoredProcedure() > Failed to set int64 field_index=2 field_name=TaskValue global_log=true struct_name=LSIssueNewTask val="{\"force_upsert\":false,\"use_open_messenger_transport\":false,\"metadata_only\":false,\"preview_only\":false,\"thread_fbid\":6...8,\"sync_group\":95}" val_type=string
2024-01-29T11:37:50Z TRC Meta send response action="handle matrix event" event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message response={"LSIssueNewTask":[{"Context":209,"QueueName":"invalid_send_task_queue","Unrecognized":{"10":0,"2":"{\"force_upsert\":false,\"use_open_messenger_transport\":false,\"metadata_only\":false,\"preview_only\":false,\"thread_fbid\":6...8,\"sync_group\":95}"}}],"LSMailboxTaskCompletionApiOnTaskCompletion":[{"TaskId":73}],"LSMarkOptimisticMessageFailed":[{"Message":"Couldn't send.","OTID":"7157698346855956522"}],"LSRemoveTask":[{"TaskId":74}],"LSTaskExists":[{"TaskId":73},{"TaskId":73},{"TaskId":73},{"TaskId":73},{"TaskId":73},{"TaskId":73},{"TaskId":73},{"TaskId":74},{"TaskId":74}],"LSUpdateMessagesOptimisticContext":[{"Unrecognized":{"0":73}}],"LSUpdateSubscriptErrorMessage":[{"Message":"Couldn't send.","OTID":"7157698346855956522","ThreadKey":100009247374828}],"LSUpdateThreadSnippet":[{"IsAdminSnippet":true,"Snippet":"Message failed to send","ThreadKey":100009247374828,"Unrecognized":{"7":false}}],"LSWriteCTAIdToThreadsTable":[{"ThreadKey":100009247374828}]} thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:50Z WRN Sending message failed action="handle matrix event" event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:50Z ERR Sending message metrics for event error="server rejected message: Couldn't send." event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message handling_step="Error sending" sender=@username:matrix.server.name thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:50Z DBG Sent message checkpoint message_checkpoint={"event_id":"$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY","event_type":"m.room.message","info":"server rejected message: Couldn't send.","message_type":"m.text","reported_by":"BRIDGE","retry_num":0,"room_id":"!vUTGHXtXdWONcrTDFL:matrix.server.name","status":"UNSUPPORTED","step":"REMOTE","timestamp":1706528270047}
2024-01-29T11:37:50Z DBG Request completed duration=65.162364 event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message handling_step="Error sending" method=PUT req_body={"typing":false} req_id=2785 response_length=2 response_mime=application/json sender=@username:matrix.server.name status_code=200 thread_id=100009247374828 thread_receiver=1...1 url=http://matrixserver:8008/_matrix/client/v3/rooms/%21vUTGHXtXdWONcrTDFL:matrix.server.name/typing/@facebook_1...8:matrix.server.name?user_id=%40facebook_1...8%3Amatrix.server.name
2024-01-29T11:37:50Z DBG Request completed action="handle meta read receipt" duration=63.017916 method=POST read_at_ms=1706528270047 read_up_to_ms=1706528269495 req_body={"com.beeper.fully_read.extra":{"fi.mau.double_puppet_source":"mautrix-meta"},"com.beeper.read.extra":{"fi.mau.double_puppet_source":"mautrix-meta"},"m.fully_read":"$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk","m.read":"$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk"} req_id=2786 response_length=2 response_mime=application/json sender_id=1...1 status_code=200 thread_id=100009247374828 thread_receiver=1...1 url=http://matrixserver:8008/_matrix/client/v3/rooms/%21vUTGHXtXdWONcrTDFL:matrix.server.name/read_markers?user_id=%40username%3Amatrix.server.name
2024-01-29T11:37:50Z DBG Sent read receipt to Matrix action="handle meta read receipt" event_id=$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk read_at_ms=1706528270047 read_up_to_ms=1706528269495 sender_id=1...1 thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:50Z DBG Starting handling of transaction content={"pdu":0,"unstable_edu":3,"unstable_to_device":0} transaction_id=1701
2024-01-29T11:37:50Z DBG Finished dispatching events from transaction transaction_id=1701
2024-01-29T11:37:50Z DBG Request completed duration=185.698493 event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message handling_step="Error sending" method=PUT req_body={"body":"\u003e \u003c@username:matrix.server.name\u003e Test 123 Test\n\n⚠ Your message was not bridged: server rejected message: Couldn't send.","format":"org.matrix.custom.html","formatted_body":"\u003cmx-reply\u003e\u003cblockquote\u003e\u003ca href=\"https://matrix.to/#/!vUTGHXtXdWONcrTDFL:matrix.server.name/$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY\"\u003eIn reply to\u003c/a\u003e \u003ca href=\"https://matrix.to/#/@username:matrix.server.name\"\u003e@username:matrix.server.name\u003c/a\u003e\u003cbr\u003eTest 123 Test\u003c/blockquote\u003e\u003c/mx-reply\u003e⚠ Your message was not bridged: server rejected message: Couldn\u0026#39;t send.","m.relates_to":{"m.in_reply_to":{"event_id":"$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY"}},"msgtype":"m.notice"} req_id=2787 response_length=59 response_mime=application/json sender=@username:matrix.server.name status_code=200 thread_id=100009247374828 thread_receiver=1...1 url=http://matrixserver:8008/_matrix/client/v3/rooms/%21vUTGHXtXdWONcrTDFL:matrix.server.name/send/m.room.message/mautrix-go_1706528270115250745_18?user_id=%40facebook_1...8%3Amatrix.server.name
2024-01-29T11:37:50Z DBG Timings for event event_id=$K9wbrRtuloOAI39TPCThcy2jAJbVf7bbmGuE6wTzFkY event_type=m.room.message handling_step="Error sending" sender=@username:matrix.server.name thread_id=100009247374828 thread_receiver=1...1 timings={"bridge":{"decrypt":"0s","init_receive":"197.8ms","queue":"0s","total_hs_to_portal":"198.8ms"},"portal":{"convert":"9.222µs","implicit_rr":"93ns","preproc":"182.443µs","total_send":"0s"}}
2024-01-29T11:37:50Z DBG Starting handling of transaction content={"pdu":1,"unstable_edu":0,"unstable_to_device":0} transaction_id=1703
2024-01-29T11:37:50Z DBG Finished dispatching events from transaction transaction_id=1703
2024-01-29T11:37:50Z DBG Sent message checkpoint message_checkpoint={"event_id":"$MnfCtuY2-ZblUfaiywgMxRUliYMlkjYIPLSnMUkDe_4","event_type":"m.room.message","message_type":"m.notice","reported_by":"BRIDGE","retry_num":0,"room_id":"!vUTGHXtXdWONcrTDFL:matrix.server.name","status":"SUCCESS","step":"BRIDGE","timestamp":1706528270347}
2024-01-29T11:37:51Z DBG Starting handling of transaction content={"pdu":0,"unstable_edu":1,"unstable_to_device":0} transaction_id=1704
2024-01-29T11:37:51Z DBG Finished dispatching events from transaction transaction_id=1704
2024-01-29T11:37:51Z DBG Creating task component=messagix label=21 payload={"last_read_watermark_ts":1706528271296,"sync_group":1,"thread_id":100009247374828} queueName=100009247374828 taskId=75 user_id=@username:matrix.server.name
2024-01-29T11:37:51Z DBG Updating sync groups LSExecuteFirstBlockForSyncTransaction=[{"CurrentCursor":"HCwAABbUmK4BFrKk7asGEwUWiuiVvuu8LQA","DatabaseId":1,"EpochId":7157693973903966250,"NextCursor":"HCwAABbWmK4BFrKk7asGEwUWiuiVvuu8LQA","SyncChannel":1,"SyncStatus":2}] LSUpsertSyncGroupThreadsRange=null component=messagix user_id=@username:matrix.server.name
2024-01-29T11:37:51Z INF Updated database by transaction... component=messagix database_id=1 new_cursor=HCwAABbWmK4BFrKk7asGEwUWiuiVvuu8LQA sendSyncParams=false syncChannel=1 user_id=@username:matrix.server.name
2024-01-29T11:37:51Z TRC Got new event table={"LSExecuteFinallyBlockForSyncTransaction":[{"EpochId":7157693973903966250,"SyncDatabaseId":1}],"LSExecuteFirstBlockForSyncTransaction":[{"CurrentCursor":"HCwAABbUmK4BFrKk7asGEwUWiuiVvuu8LQA","DatabaseId":1,"EpochId":7157693973903966250,"NextCursor":"HCwAABbWmK4BFrKk7asGEwUWiuiVvuu8LQA","SyncChannel":1,"SyncStatus":2}],"LSMarkThreadRead":[{"LastReadWatermarkTimestampMs":1706528271296,"ThreadKey":100009247374828}],"LSUpdateParentFolderReadWatermark":[{"ThreadKey":100009247374828,"Unrecognized":{"1":{"all_read":"","unread_plural":" nieuwe chatberichten","unread_singular":" nieuw chatbericht"}}}],"LSUpsertSequenceId":[{"LastAppliedMailboxSequenceId":1426987}],"LSWriteCTAIdToThreadsTable":[{"ThreadKey":100009247374828}]} user_id=@username:matrix.server.name
2024-01-29T11:37:51Z DBG Request completed action="handle meta read receipt" duration=25.939217 method=POST read_at_ms=1706528271797 read_up_to_ms=1706528271296 req_body={"com.beeper.fully_read.extra":{"fi.mau.double_puppet_source":"mautrix-meta"},"com.beeper.read.extra":{"fi.mau.double_puppet_source":"mautrix-meta"},"m.fully_read":"$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk","m.read":"$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk"} req_id=2788 response_length=2 response_mime=application/json sender_id=1...1 status_code=200 thread_id=100009247374828 thread_receiver=1...1 url=http://matrixserver:8008/_matrix/client/v3/rooms/%21vUTGHXtXdWONcrTDFL:matrix.server.name/read_markers?user_id=%40username%3Amatrix.server.name
2024-01-29T11:37:51Z DBG Sent read receipt to Matrix action="handle meta read receipt" event_id=$1EAN-dN4q2dzjPRK4Sg8OZU8slI_4EutEADpG9vp3bk read_at_ms=1706528271797 read_up_to_ms=1706528271296 sender_id=1...1 thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:52Z TRC Read receipt send response action="handle matrix receipt" event_id=$MnfCtuY2-ZblUfaiywgMxRUliYMlkjYIPLSnMUkDe_4 response={"LSRemoveTask":[{"TaskId":75}],"LSTaskExists":[{"TaskId":75},{"TaskId":75}],"LSWriteCTAIdToThreadsTable":[{"ThreadKey":100009247374828}]} thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:52Z DBG Read receipt sent action="handle matrix receipt" event_id=$MnfCtuY2-ZblUfaiywgMxRUliYMlkjYIPLSnMUkDe_4 read_watermark=2024-01-29T11:37:51.296Z thread_id=100009247374828 thread_receiver=1...1
2024-01-29T11:37:56Z TRC Got ping response component=messagix user_id=@username:matrix.server.name
Thank you for your attention to this matter. I am happy to provide any further information or clarification needed to resolve this issue.
I appreciate the efforts put into developing and maintaining this integration.