pm: Cannot create new chats with noSIP/Barcelona

Open rothn opened this issue 1 year ago • 0 comments

https://github.com/mautrix/imessage/issues/126 was closed because it was suggested I needed to run a noSIP configuration of mautrix-imessage to initiate PMs. I now run this configuration with Barcelona, but am still unable to send PMs on the latest build (From mau.dev Pipelines -> Update dependencies -> #15721 ).

Since it was suggested in the earlier issue by @trek-boldly-go and @tulir that this was just an AppleScript limitation, I'm filing a new issue regarding this not working with Barcelona.

Error:

Logs:

2024-11-30T21:19:28-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851075 ws_command=
2024-11-30T21:19:28-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851075 ws_command=
2024-11-30T21:19:28-08:00 DBG Sent response to transaction req_id=0 transaction_id=851075 ws_command=
2024-11-30T21:19:28-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$rOQoyAIVzbLIGSFk-vGapCHZJCPs_VxZKyGlAe63bh8","event_type":"m.room.message","message_type":"m.text","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"BRIDGE","timestamp":1733030368597}
2024-11-30T21:19:28-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$rOQoyAIVzbLIGSFk-vGapCHZJCPs_VxZKyGlAe63bh8","event_type":"m.room.message","message_type":"m.text","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"COMMAND","timestamp":1733030368597}
2024-11-30T21:19:28-08:00 DBG Received command event_id=$rOQoyAIVzbLIGSFk-vGapCHZJCPs_VxZKyGlAe63bh8 mx_command=pm room_id=!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/) user_id=@nicholasroth:[nicholasroth.net](http://nicholasroth.net/)
2024-11-30T21:19:28-08:00 DBG Sending IPC command: resolve_identifier/65 module=iMessage/Mac-noSIP/IPC
2024-11-30T21:19:28-08:00 INF 2024-11-30T21:19:28-0800 error ChatLocator : [Barcelona] Failed to resolve IDS status for +REDACTED_PHONENUMBER
: unknownHandleStyle module=iMessage/Barcelona/Stdout
2024-11-30T21:19:28-08:00 INF 2024-11-30T21:19:28-0800 warning ResolveIdentifierCommand : [ResolveIdentifier] Resolving identifier for +REDACTED_PHONENUMBER
 failed with message: This address is not registered with iMessage, nor can you SMS it. module=iMessage/Barcelona/Stdout
2024-11-30T21:19:28-08:00 INF 2024-11-30T21:19:28-0800 info ResolveIdentifierCommand : [ResolveIdentifier] Responding that +REDACTED_PHONENUMBER
 is unavailable module=iMessage/Barcelona/Stdout
2024-11-30T21:19:28-08:00 DBG Received IPC command: error/65 module=iMessage/Mac-noSIP/IPC
2024-11-30T21:19:28-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851077 ws_command=
2024-11-30T21:19:28-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851077 ws_command=
2024-11-30T21:19:28-08:00 DBG Sent response to transaction req_id=0 transaction_id=851077 ws_command=
2024-11-30T21:19:28-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851080 ws_command=
2024-11-30T21:19:28-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851080 ws_command=
2024-11-30T21:19:28-08:00 DBG Sent response to transaction req_id=0 transaction_id=851080 ws_command=
2024-11-30T21:19:28-08:00 DBG Request completed as_user_id=@imessagebot:[nicholasroth.net](http://nicholasroth.net/) duration=310.285287 method=PUT req_body={"body":"Failed to start PM: failed to resolve identifier: err_destination_unreachable: Identifier resolution failed and SMS service is unavailable","msgtype":"m.notice"} req_id=48 response_length=59 response_mime=application/json status_code=200 url=https://matrix.nicholasroth.net/_matrix/client/v3/rooms/%21ThXBYPvFbLqEYGVGRn:nicholasroth.net/send/m.room.message/mautrix-go_1733030368608613000_4?user_id=%40imessagebot%3Anicholasroth.net
2024-11-30T21:19:28-08:00 DBG Request completed as_user_id=@imessagebot:[nicholasroth.net](http://nicholasroth.net/) duration=355.00726 method=PUT req_body={"m.relates_to":{"event_id":"$rOQoyAIVzbLIGSFk-vGapCHZJCPs_VxZKyGlAe63bh8","rel_type":"m.reference"},"network":"","status":"SUCCESS"} req_id=47 response_length=59 response_mime=application/json status_code=200 url=https://matrix.nicholasroth.net/_matrix/client/v3/rooms/%21ThXBYPvFbLqEYGVGRn:nicholasroth.net/send/com.beeper.message_send_status/mautrix-go_1733030368603794000_3?user_id=%40imessagebot%3Anicholasroth.net
2024-11-30T21:19:28-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$5eH9fX2TSsQP5tY2h0UHrvAw2XcsIiHNrzRClK1E5is","event_type":"m.room.message","message_type":"m.notice","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"BRIDGE","timestamp":1733030368959}

Tried with a different format, still not working:

2024-11-30T21:48:09-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851192 ws_command=
2024-11-30T21:48:09-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851192 ws_command=
2024-11-30T21:48:09-08:00 DBG Sent response to transaction req_id=0 transaction_id=851192 ws_command=
2024-11-30T21:48:09-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$GWuilke0G799mt8bAjhlD_zEV38PFtW7rQlBQiZiS_c","event_type":"m.room.message","message_type":"m.text","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"BRIDGE","timestamp":1733032089858}
2024-11-30T21:48:09-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$GWuilke0G799mt8bAjhlD_zEV38PFtW7rQlBQiZiS_c","event_type":"m.room.message","message_type":"m.text","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"COMMAND","timestamp":1733032089860}
2024-11-30T21:48:09-08:00 DBG Received command event_id=$GWuilke0G799mt8bAjhlD_zEV38PFtW7rQlBQiZiS_c mx_command=pm room_id=!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/) user_id=@nicholasroth:[nicholasroth.net](http://nicholasroth.net/)
2024-11-30T21:48:09-08:00 DBG Sending IPC command: resolve_identifier/73 module=iMessage/Mac-noSIP/IPC
2024-11-30T21:48:09-08:00 INF 2024-11-30T21:48:09-0800 error ChatLocator : [Barcelona] Failed to resolve IDS status for +1 (REDACTED) REDACTED-REDACTED
: unknownHandleStyle module=iMessage/Barcelona/Stdout

2024-11-30T21:48:09-08:00 INF 2024-11-30T21:48:09-0800 warning ResolveIdentifierCommand : [ResolveIdentifier] Resolving identifier for +1 (REDACTED) REDACTED-REDACTED

 failed with message: This address is not registered with iMessage, nor can you SMS it.

2024-11-30T21:48:09-0800 info ResolveIdentifierCommand : [ResolveIdentifier] Responding that +1 (REDACTED) REDACTED-REDACTED

 is unavailable module=iMessage/Barcelona/Stdout

2024-11-30T21:48:09-08:00 DBG Received IPC command: error/73 module=iMessage/Mac-noSIP/IPC

2024-11-30T21:48:09-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851193 ws_command=

2024-11-30T21:48:09-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851193 ws_command=

2024-11-30T21:48:09-08:00 DBG Sent response to transaction req_id=0 transaction_id=851193 ws_command=

2024-11-30T21:48:09-08:00 DBG Starting handling of transaction content={"pdu":1} req_id=0 transaction_id=851196 ws_command=

2024-11-30T21:48:09-08:00 DBG Finished dispatching events from transaction req_id=0 transaction_id=851196 ws_command=

2024-11-30T21:48:09-08:00 DBG Sent response to transaction req_id=0 transaction_id=851196 ws_command=

2024-11-30T21:48:10-08:00 DBG Request completed as_user_id=@imessagebot:[nicholasroth.net](http://nicholasroth.net/) duration=228.257671 method=PUT req_body={"m.relates_to":{"event_id":"$GWuilke0G799mt8bAjhlD_zEV38PFtW7rQlBQiZiS_c","rel_type":"m.reference"},"network":"","status":"SUCCESS"} req_id=58 response_length=59 response_mime=application/json status_code=200 url=https://matrix.nicholasroth.net/_matrix/client/v3/rooms/%21ThXBYPvFbLqEYGVGRn:nicholasroth.net/send/com.beeper.message_send_status/mautrix-go_1733032089863872000_13?user_id=%40imessagebot%3Anicholasroth.net

2024-11-30T21:48:10-08:00 DBG Sent message checkpoint message_checkpoint={"event_id":"$yioXDPhTQM9oPSIIhm3rcdDuNJ3PfIb1SGn9r4f-hDg","event_type":"m.room.message","message_type":"m.notice","reported_by":"BRIDGE","retry_num":0,"room_id":"!ThXBYPvFbLqEYGVGRn:[nicholasroth.net](http://nicholasroth.net/)","status":"SUCCESS","step":"BRIDGE","timestamp":1733032090092}

2024-11-30T21:48:10-08:00 DBG Request completed as_user_id=@imessagebot:[nicholasroth.net](http://nicholasroth.net/) duration=259.755463 method=PUT req_body={"body":"Failed to start PM: failed to resolve identifier: err_destination_unreachable: Identifier resolution failed and SMS service is unavailable","msgtype":"m.notice"} req_id=59 response_length=59 response_mime=application/json status_code=200 url=https://matrix.nicholasroth.net/_matrix/client/v3/rooms/%21ThXBYPvFbLqEYGVGRn:nicholasroth.net/send/m.room.message/mautrix-go_1733032089868244000_14?user_id=%40imessagebot%3Anicholasroth.net

Note also that on the latest version of the Mautrix server, I first get an error 403 with the pm command, and then I get the error pictured above upon subsequent requests to the same phone number.

Dec 01 '24 05:12 rothn