search

mautrix / imessage

A Matrix-iMessage puppeting bridge
https://go.mau.fi/mautrix-imessage/
GNU Affero General Public License v3.0
334 stars 37 forks source link

incoming attachments not working #106

Closed ekallevig closed 1 year ago

ekallevig commented 1 year ago

Finally got these things all working:

But for some reason incoming attachments are not being handled. I see the attachment file transfer being logged in the bridge, but then it just sits for about a minute before finally reporting this:

DBG Starting handling of iMessage ED6C6695-AC18-44ED-8537-9DF83DE99F9E (type: 0, attachments: 0, text: 0) portal_guid=iMessage;-;incoming@sender.com
WRN iMessage ED6C6695-AC18-44ED-8537-9DF83DE99F9E doesn't contain any attachments nor text

Not sure if it could be some kind of permissions issue or what.

Here's the full sequence:

2023-05-03T10:02:05-04:00 INF 2023-05-03T10:02:05-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D was created! module=iMessage/Barcelona/Stdout
2023-05-03T10:02:06-04:00 INF 2023-05-03T10:02:06-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished false state accepted error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished false state transferring error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished false state finalizing error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished true state finished error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has finished! module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug IMFileTransfer : [Barcelona] checking inSandboxedLocation for localPath: Optional("/var/folders/6s/j5t63ckj1m9dw6b6k_xq7ldm0000gn/T/com.apple.imagent/2D04F63D-6BEB-4D4F-B862-9D3228D02A43/0/uxmsmp5zooirj9cpiqlg.jpeg") module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished true state finished error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has finished! module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug IMFileTransfer : [Barcelona] checking inSandboxedLocation for localPath: Optional("/Users/myuser/Library/Messages/Attachments/83/03/7A4ECAC5-665E-498C-8B33-AE76EBD09A4D/uxmsmp5zooirj9cpiqlg.jpeg") module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has updated! isFinished true state finished error nil module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug FileTransfers : [Barcelona] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D has finished! module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug IMFileTransfer : [Barcelona] checking inSandboxedLocation for localPath: Optional("/Users/myuser/Library/Messages/Attachments/83/03/7A4ECAC5-665E-498C-8B33-AE76EBD09A4D/uxmsmp5zooirj9cpiqlg.jpeg") module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug ERDaemonListener : [Barcelona] chat:iMessage;-;incoming@sender.com updated:[AnyHashable("lastAddressedLocalHandle"): +19173199095, AnyHashable("properties"): { LSMD = "2023-05-03 14:01:36 +0000"; hasBeenAutoSpamReported = 1; hasViewedPotentialSpamChat = 1; messageHandshakeState = 2; numberOfTimesRespondedtoThread = 3; pv = 0; shouldForceToSMS = 0; }, AnyHashable("state"): 3, AnyHashable("autoDonationBehavior"): 0, AnyHashable("chatIdentifier"): incoming@sender.com, AnyHashable("participants"): <__NSSingleObjectArrayI 0x600002e2c010>( { FZPersonID = "incoming@sender.com"; } ) , AnyHashable("style"): 45, AnyHashable("unreadCount"): 2, AnyHashable("originalGroupID"): 1706A1BB-17E3-405E-AFE0-3BD4958E74C7, AnyHashable("isRecovered"): 0, AnyHashable("rowID"): 1, AnyHashable("groupID"): 367D03E4-1FAD-42DE-897A-15AB317AA1EF, AnyHashable("accountID"): BBA0BBB3-5E80-400A-83BD-AFA124B40BEE, AnyHashable("pcmid"): incoming@sender.com, AnyHashable("lastReadMessageTimeStamp"): 704814905270678016, AnyHashable("isFiltered"): 0, AnyHashable("isBlackholed"): 0, AnyHashable("guid"): iMessage;-;incoming@sender.com, AnyHashable("lastMessageTimeStampOnLoad"): 704813575281999872, AnyHashable("serviceName"): iMessage, AnyHashable("hasHadSuccessfulQuery"): 1] module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug CBChatRegistry : [Barcelona] chat nil pcID nil persistentIdentifier iMessage;-;incoming@sender.com updated Optional([AnyHashable("unreadCount"): 2, AnyHashable("accountID"): BBA0BBB3-5E80-400A-83BD-AFA124B40BEE, AnyHashable("pcmid"): incoming@sender.com, AnyHashable("lastReadMessageTimeStamp"): 704814905270678016, AnyHashable("rowID"): 1, AnyHashable("guid"): iMessage;-;incoming@sender.com, AnyHashable("lastAddressedLocalHandle"): +19173199095, AnyHashable("serviceName"): iMessage, AnyHashable("groupID"): 367D03E4-1FAD-42DE-897A-15AB317AA1EF, AnyHashable("chatIdentifier"): incoming@sender.com, AnyHashable("style"): 45, AnyHashable("hasHadSuccessfulQuery"): 1, AnyHashable("properties"): { LSMD = "2023-05-03 14:01:36 +0000"; hasBeenAutoSpamReported = 1; hasViewedPotentialSpamChat = 1; messageHandshakeState = 2; numberOfTimesRespondedtoThread = 3; pv = 0; shouldForceToSMS = 0; }, AnyHashable("participants"): <__NSSingleObjectArrayI 0x600002e2c010>( { FZPersonID = "incoming@sender.com"; } ) , AnyHashable("state"): 3, AnyHashable("isBlackholed"): 0, AnyHashable("isFiltered"): 0, AnyHashable("autoDonationBehavior"): 0, AnyHashable("originalGroupID"): 1706A1BB-17E3-405E-AFE0-3BD4958E74C7, AnyHashable("isRecovered"): 0, AnyHashable("lastMessageTimeStampOnLoad"): 704813575281999872]): chat(_:updated:) module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug ERDaemonListener : [Barcelona] messagesReceived: [IMMessageItem[outgoing: NO sender=incoming@sender.com; service=iMessage; handle=incoming@sender.com; destinationCallerID= +19173199095, unformatted=(null); country=US; roomName='(null)'; flags=101001; subject='(null)' text='(null)' messageID: 65 GUID:'ED6C6695-AC18-44ED-8537-9DF83DE99F9E' sortID: 0 date:'704815325.849180' date-delivered:'0.000000' date-read:'0.000000' date-played:'0.000000' transfer guids: '( "7A4ECAC5-665E-498C-8B33-AE76EBD09A4D" )' empty: NO finished: YES sent: NO read: NO delivered: YES audio: NO played: NO from-me: NO DD results: NO DD Scanned: YES Downgraded: NO emote: NO expirable: NO expire-state: 0 balloon-bundle-id: (null) expressive-send-style-id: (null) time-expressive-send-played: (null) bizIntent: (null) locale: (null) error: 0 sync-state 0 corrupt: NO shouldSendMeCard: NO isSpam: NO hasUnseenMention: NO threadIdentifier: (null), threadOriginator: (null), replyCountsByPart: (null), syndicationRanges: (null), syncedSyndicationRanges: (null), dateEdited: '0.000000', hasGroupActivity: NO, wasDetonated: NO]] comingFromStorage: false module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug ERDaemonListener : [Barcelona] sending message Optional("ED6C6695-AC18-44ED-8537-9DF83DE99F9E") Optional("iMessage") incoming@sender.com down the pipeline module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 DBG Received IPC command: typing/0 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:07-04:00 DBG Sending request as_user_id=@imessage_incoming=40sender.com:mymatrix.domain body={"timeout":60000,"typing":false} method=PUT req_id=15 url=https://matrix.mymatrix.domain/matrix/client/v3/rooms/%21QgIaoSIMSECfHAVN:mymatrix.domain/typing/@imessage_incoming=40sender.com:mymatrix.domain?user_id=%40imessage_incoming%3D40sender.com%3Amymatrix.domain
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 debug CBChatRegistry : [Barcelona] chat incoming@sender.com pcID incoming@sender.com received [IMMessageItem[outgoing: NO sender=incoming@sender.com; service=iMessage; handle=incoming@sender.com; destinationCallerID= +19173199095, unformatted=(null); country=US; roomName='(null)'; flags=101001; subject='(null)' text='(null)' messageID: 65 GUID:'ED6C6695-AC18-44ED-8537-9DF83DE99F9E' sortID: 4 date:'704815325.849180' date-delivered:'0.000000' date-read:'0.000000' date-played:'0.000000' transfer guids: '(
"7A4ECAC5-665E-498C-8B33-AE76EBD09A4D"
)' empty: NO finished: YES sent: NO read: NO delivered: YES audio: NO played: NO from-me: NO DD results: NO DD Scanned: YES Downgraded: NO emote: NO expirable: NO expire-state: 0 balloon-bundle-id: (null) expressive-send-style-id: (null) time-expressive-send-played: (null) bizIntent: (null) locale: (null) error: 0 sync-state 0 corrupt: NO shouldSendMeCard: NO isSpam: NO hasUnseenMention: NO threadIdentifier: (null), threadOriginator: (null), replyCountsByPart: (null), syndicationRanges: (null), syncedSyndicationRanges: (null), dateEdited: '0.000000', hasGroupActivity: NO, wasDetonated: NO]] from storage false: account(:chat:style:chatProperties:groupID:chatPersonCentricID:messagesReceived:messagesComingFromStorage:) module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 INF 2023-05-03T10:02:07-0400 info CBChat : [Barcelona] handled message ED6C6695-AC18-44ED-8537-9DF83DE99F9E, <CBMessage retryCount=0 rawFlags=66 error=noError time=2023-05-03 14:02:05 +0000 timeDelivered=nil timeRead=nil sender=<Handle name=mailto value=incoming@sender.com/> sent=false delivered=true typing=false read=false fromMe=false downgraded=false beingRetried=false finished=true prepared=false sos=false alert=false spam=false emote=false played=false corrupt=false expirable=false audioMessage=false locationMessage=false empty=false/>"
2023-05-03T10:02:07-0400 debug IMFileTransfer : [Barcelona] checking inSandboxedLocation for localPath: Optional("/Users/myuser/Library/Messages/Attachments/83/03/7A4ECAC5-665E-498C-8B33-AE76EBD09A4D/uxmsmp5zooirj9cpiqlg.jpeg")
2023-05-03T10:02:07-0400 info FileTransfers : [CBFileTransferCenter] Transfer 7A4ECAC5-665E-498C-8B33-AE76EBD09A4D is truly finished!
2023-05-03T10:02:07-0400 debug IMFileTransfer : [Barcelona] checking inSandboxedLocation for localPath: Optional("/Users/myuser/Library/Messages/Attachments/83/03/7A4ECAC5-665E-498C-8B33-AE76EBD09A4D/uxmsmp5zooirj9cpiqlg.jpeg") module=iMessage/Barcelona/Stdout
2023-05-03T10:02:07-04:00 DBG Request completed as_user_id=@imessage_incoming=40sender.com:mymatrix.domain duration=14.083064 method=PUT path=/v3/rooms/!QgIaoSIMSECfHAVN:mymatrix.domain/typing/@imessage_incoming=40sender.com:mymatrix.domain req_id=15 response_length=2 response_mime=application/json status_code=200
2023-05-03T10:02:07-04:00 DBG Handled typing notification in 17.143934ms (queued: 0m/0r/0t/0ch/0ct/0s/0b) module=iMessage
2023-05-03T10:02:20-04:00 DBG Sending IPC command: ping/17 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:20-04:00 DBG Received IPC command: response/17 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:35-04:00 DBG Sending IPC command: ping/18 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:35-04:00 DBG Received IPC command: response/18 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:50-04:00 DBG Sending IPC command: ping/19 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:02:50-04:00 DBG Received IPC command: response/19 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:03:02-04:00 INF 2023-05-03T10:03:02-0400 info MautrixIPCChannel : [BarcelonaMautrixIPC] Outgoing! message -1 module=iMessage/Barcelona/Stdout
2023-05-03T10:03:02-04:00 DBG Received IPC command: message/0 module=iMessage/Mac-noSIP/IPC
2023-05-03T10:03:02-04:00 DBG Handled message in 12.076µs (queued: 0m/0r/0t/0ch/0ct/0s/0b) module=iMessage
2023-05-03T10:03:02-04:00 DBG Starting handling of iMessage ED6C6695-AC18-44ED-8537-9DF83DE99F9E (type: 0, attachments: 0, text: 0) portal_guid=iMessage;-;incoming@sender.com
2023-05-03T10:03:02-04:00 WRN iMessage ED6C6695-AC18-44ED-8537-9DF83DE99F9E doesn't contain any attachments nor text portal_guid=iMessage;-;incoming@sender.com
2023-05-03T10:03:02-04:00 DBG Unhandled message ED6C6695-AC18-44ED-8537-9DF83DE99F9E portal_guid=iMessage;-;incoming@sender.com
2023-05-03T10:03:02-04:00 DBG Handled iMessage in 103.917579ms (queued: 0i/0r/0m/0s) portal_guid=iMessage;-;incoming@sender.com
ekallevig commented 1 year ago

Not sure how it started working. I reapplied the OCLP settings and restarted and it worked.

james-choncholas commented 1 year ago

I had the same issue but for me, the fix was correcting the file permissions on /Library/Preferences/com.apple.security.xpc.plist

dmr138 commented 9 months ago

I had the same issue but for me, the fix was correcting the file permissions on /Library/Preferences/com.apple.security.xpc.plist

I need to try this