diff --git a/core/kordophone/src/api/http_client.rs b/core/kordophone/src/api/http_client.rs index 558943d..5a2a90d 100644 --- a/core/kordophone/src/api/http_client.rs +++ b/core/kordophone/src/api/http_client.rs @@ -65,7 +65,15 @@ impl std::error::Error for Error { impl std::fmt::Display for Error { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - write!(f, "{:?}", self) + match self { + Error::ClientError(message) => write!(f, "{}", message), + Error::HTTPError(err) => write!(f, "HTTP transport error: {}", err), + Error::SerdeError(err) => write!(f, "JSON error: {}", err), + Error::DecodeError(message) => write!(f, "Decode error: {}", message), + Error::PongError(err) => write!(f, "WebSocket error: {}", err), + Error::URLError => write!(f, "Invalid URL"), + Error::Unauthorized => write!(f, "Unauthorized"), + } } } @@ -284,6 +292,17 @@ impl APIInterface for HTTPAPIClient { Ok(()) } + async fn delete_conversation( + &mut self, + conversation_id: &ConversationID, + ) -> Result<(), Self::Error> { + // SERVER JANK: This should be DELETE or POST, but it's GET for some reason. + let endpoint = format!("delete?guid={}", conversation_id); + self.response_with_body_retry(&endpoint, Method::GET, Body::empty, true) + .await?; + Ok(()) + } + async fn get_messages( &mut self, conversation_id: &ConversationID, @@ -313,6 +332,25 @@ impl APIInterface for HTTPAPIClient { &mut self, outgoing_message: &OutgoingMessage, ) -> Result { + match &outgoing_message.target { + OutgoingMessageTarget::Conversation(conversation_id) => { + log::debug!( + "Sending message to conversation {} (body_length={}, attachment_count={})", + conversation_id, + outgoing_message.text.len(), + outgoing_message.file_transfer_guids.len() + ); + } + OutgoingMessageTarget::Handles(handle_ids) => { + log::debug!( + "Sending message to resolved handles {:?} (body_length={}, attachment_count={})", + handle_ids, + outgoing_message.text.len(), + outgoing_message.file_transfer_guids.len() + ); + } + } + let message: SendMessageResponse = self .deserialized_response_with_body("sendMessage", Method::POST, || { Self::send_message_request_body(outgoing_message) @@ -326,6 +364,7 @@ impl APIInterface for HTTPAPIClient { &mut self, handle_id: &str, ) -> Result { + log::debug!("Resolving handle {}", handle_id); let endpoint = format!("resolveHandle?id={}", urlencoding::encode(handle_id)); let response: ResolveHandleResponse = self.deserialized_response(&endpoint, Method::GET).await?; @@ -542,6 +581,18 @@ impl HTTPAPIClient { } } + fn log_transport_error(method: &Method, target: &str, err: &hyper::Error) { + log::error!("HTTP transport error for {} {}: {}", method, target, err); + + if format!("{:?}", err).contains("IncompleteMessage") { + log::error!( + "The server closed the connection before a complete response was received for {} {}.", + method, + target + ); + } + } + async fn deserialized_response( &mut self, endpoint: &str, @@ -575,15 +626,26 @@ impl HTTPAPIClient { T: DeserializeOwned, { let response = self - .response_with_body_retry(endpoint, method, body_fn, retry_auth) + .response_with_body_retry(endpoint, method.clone(), body_fn, retry_auth) .await?; // Read and parse response body - let body = hyper::body::to_bytes(response.into_body()).await?; + let body = match hyper::body::to_bytes(response.into_body()).await { + Ok(body) => body, + Err(err) => { + Self::log_transport_error(&method, endpoint, &err); + return Err(Error::HTTPError(err)); + } + }; let parsed: T = match serde_json::from_slice(&body) { Ok(result) => Ok(result), Err(json_err) => { - log::error!("Error deserializing JSON: {:?}", json_err); + log::error!( + "Error deserializing JSON for {} {}: {:?}", + method, + endpoint, + json_err + ); log::error!("Body: {:?}", String::from_utf8_lossy(&body)); // If JSON deserialization fails, try to interpret it as plain text @@ -606,7 +668,8 @@ impl HTTPAPIClient { use hyper::StatusCode; let uri = self.uri_for_endpoint(endpoint, None)?; - log::debug!("Requesting {:?} {:?}", method, uri); + let uri_string = uri.to_string(); + log::debug!("Requesting {} {}", method, uri_string); let mut build_request = |auth: &Option| { let body = body_fn(); @@ -620,13 +683,24 @@ impl HTTPAPIClient { log::trace!("Obtaining token from auth store"); let token = self.auth_store.get_token().await; - log::trace!("Token: {:?}", token); + log::trace!("Token present: {}", token.is_some()); let request = build_request(&token); - log::trace!("Request: {:?}. Sending request...", request); + log::trace!( + "Sending request: method={} uri={} authenticated={}", + method, + uri_string, + token.is_some() + ); - let mut response = self.client.request(request).await?; - log::debug!("-> Response: {:}", response.status()); + let mut response = match self.client.request(request).await { + Ok(response) => response, + Err(err) => { + Self::log_transport_error(&method, &uri_string, &err); + return Err(Error::HTTPError(err)); + } + }; + log::debug!("-> Response: {}", response.status()); match response.status() { StatusCode::OK => { /* cool */ } @@ -645,7 +719,19 @@ impl HTTPAPIClient { let new_token = self.authenticate(credentials.clone()).await?; let request = build_request(&Some(new_token.to_string())); - response = self.client.request(request).await?; + log::trace!( + "Retrying request after authentication: method={} uri={} authenticated=true", + method, + uri_string + ); + response = match self.client.request(request).await { + Ok(response) => response, + Err(err) => { + Self::log_transport_error(&method, &uri_string, &err); + return Err(Error::HTTPError(err)); + } + }; + log::debug!("-> Retry response: {}", response.status()); } else { return Err(Error::ClientError( "Unauthorized, no credentials provided".into(), diff --git a/core/kordophone/src/api/mod.rs b/core/kordophone/src/api/mod.rs index b1eaba8..65290ab 100644 --- a/core/kordophone/src/api/mod.rs +++ b/core/kordophone/src/api/mod.rs @@ -79,6 +79,12 @@ pub trait APIInterface { conversation_id: &ConversationID, ) -> Result<(), Self::Error>; + // (GET) /delete + async fn delete_conversation( + &mut self, + conversation_id: &ConversationID, + ) -> Result<(), Self::Error>; + // (WS) /updates async fn open_event_socket( &mut self, diff --git a/core/kordophone/src/tests/mod.rs b/core/kordophone/src/tests/mod.rs index 1de7245..61fb496 100644 --- a/core/kordophone/src/tests/mod.rs +++ b/core/kordophone/src/tests/mod.rs @@ -52,4 +52,20 @@ pub mod api_interface { assert_eq!(sent.message.text, "hello"); assert_eq!(sent.conversation_id, None); } + + #[tokio::test] + async fn test_delete_conversation() { + let mut client = TestClient::new(); + + let test_convo = Conversation::builder() + .display_name("Delete Me") + .build(); + + client.conversations.push(test_convo.clone()); + + client.delete_conversation(&test_convo.guid).await.unwrap(); + + let conversations = client.get_conversations().await.unwrap(); + assert!(conversations.is_empty()); + } } diff --git a/core/kordophone/src/tests/test_client.rs b/core/kordophone/src/tests/test_client.rs index fc0fb86..4ddd5f4 100644 --- a/core/kordophone/src/tests/test_client.rs +++ b/core/kordophone/src/tests/test_client.rs @@ -187,4 +187,19 @@ impl APIInterface for TestClient { ) -> Result<(), Self::Error> { Ok(()) } + + async fn delete_conversation( + &mut self, + conversation_id: &ConversationID, + ) -> Result<(), Self::Error> { + let previous_len = self.conversations.len(); + self.conversations.retain(|c| &c.guid != conversation_id); + self.messages.remove(conversation_id); + + if self.conversations.len() == previous_len { + return Err(TestError::ConversationNotFound); + } + + Ok(()) + } } diff --git a/core/kpcli/src/client/mod.rs b/core/kpcli/src/client/mod.rs index ae1b0ba..e2d08a1 100644 --- a/core/kpcli/src/client/mod.rs +++ b/core/kpcli/src/client/mod.rs @@ -5,10 +5,10 @@ use kordophone::api::InMemoryAuthenticationStore; use kordophone::APIInterface; use crate::printers::{ConversationPrinter, MessagePrinter}; -use anyhow::Result; +use anyhow::{bail, Result}; use clap::Subcommand; use kordophone::model::event::EventData; -use kordophone::model::outgoing_message::OutgoingMessage; +use kordophone::model::{HandleResolutionStatus, OutgoingMessage, OutgoingMessageTarget}; use futures_util::StreamExt; @@ -47,14 +47,29 @@ pub enum Commands { /// Prints all raw updates from the server. RawUpdates, - /// Sends a message to the server. - SendMessage { + /// Resolves an address to a canonical handle. + #[command(alias = "resolve")] + ResolveHandle { address: String }, + + /// Replies to an existing conversation. + #[command(alias = "send-message")] + Reply { conversation_id: String, message: String, }, + /// Starts a new message to one or more resolved handles. + New { + #[arg(long = "handle", required = true)] + handle_ids: Vec, + message: String, + }, + /// Marks a conversation as read. Mark { conversation_id: String }, + + /// Deletes a conversation from the server. + Delete { conversation_id: String }, } impl Commands { @@ -66,13 +81,19 @@ impl Commands { Commands::Messages { conversation_id } => client.print_messages(conversation_id).await, Commands::RawUpdates => client.print_raw_updates().await, Commands::Events => client.print_events().await, - Commands::SendMessage { + Commands::ResolveHandle { address } => client.resolve_handle(address).await, + Commands::Reply { conversation_id, message, - } => client.send_message(conversation_id, message).await, + } => client.reply(conversation_id, message).await, + Commands::New { + handle_ids, + message, + } => client.new_message(handle_ids, message).await, Commands::Mark { conversation_id } => { client.mark_conversation_as_read(conversation_id).await } + Commands::Delete { conversation_id } => client.delete_conversation(conversation_id).await, } } } @@ -167,20 +188,92 @@ impl ClientCli { Ok(()) } - pub async fn send_message(&mut self, conversation_id: String, message: String) -> Result<()> { + pub async fn resolve_handle(&mut self, address: String) -> Result<()> { + let response = self.api.resolve_handle(&address).await?; + let status = match response.status { + HandleResolutionStatus::Valid => "valid", + HandleResolutionStatus::Invalid => "invalid", + HandleResolutionStatus::Unknown => "unknown", + }; + + println!("Resolved handle: {}", response.resolved_handle.id); + + if let Some(name) = response.resolved_handle.name { + println!("Name: {}", name); + } + + println!("Status: {}", status); + + if let Some(conversation_id) = response.existing_chat { + println!("Existing conversation: {}", conversation_id); + } + + Ok(()) + } + + async fn send_message( + &mut self, + target: OutgoingMessageTarget, + message: String, + ) -> Result<()> { let outgoing_message = OutgoingMessage::builder() - .conversation_id(conversation_id) + .target(target) .text(message) .build(); let response = self.api.send_message(&outgoing_message).await?; - println!("Message sent: {}", response.message.guid); + if let Some(conversation_id) = response.conversation_id { + println!( + "Message sent: {} conversation: {}", + response.message.guid, conversation_id + ); + } else { + println!("Message sent: {}", response.message.guid); + } Ok(()) } + async fn resolve_handle_ids(&mut self, handle_ids: Vec) -> Result> { + let mut resolved_handle_ids = Vec::with_capacity(handle_ids.len()); + + for handle_id in handle_ids { + let response = self.api.resolve_handle(&handle_id).await?; + match response.status { + HandleResolutionStatus::Valid => { + resolved_handle_ids.push(response.resolved_handle.id); + } + HandleResolutionStatus::Invalid => { + bail!("Handle '{}' is not iMessage-capable.", handle_id); + } + HandleResolutionStatus::Unknown => { + bail!("Handle '{}' could not be resolved.", handle_id); + } + } + } + + Ok(resolved_handle_ids) + } + + pub async fn reply(&mut self, conversation_id: String, message: String) -> Result<()> { + self.send_message(OutgoingMessageTarget::Conversation(conversation_id), message) + .await + } + + pub async fn new_message(&mut self, handle_ids: Vec, message: String) -> Result<()> { + let resolved_handle_ids = self.resolve_handle_ids(handle_ids).await?; + self.send_message(OutgoingMessageTarget::Handles(resolved_handle_ids), message) + .await + } + pub async fn mark_conversation_as_read(&mut self, conversation_id: String) -> Result<()> { self.api.mark_conversation_as_read(&conversation_id).await?; println!("Conversation marked as read: {}", conversation_id); Ok(()) } + + pub async fn delete_conversation(&mut self, conversation_id: String) -> Result<()> { + self.api.delete_conversation(&conversation_id).await?; + println!("Conversation deleted: {}", conversation_id); + Ok(()) + } } diff --git a/server/kordophone/Bridge/MBIMHTTPConnection.m b/server/kordophone/Bridge/MBIMHTTPConnection.m index 86ed2a0..04499d5 100644 --- a/server/kordophone/Bridge/MBIMHTTPConnection.m +++ b/server/kordophone/Bridge/MBIMHTTPConnection.m @@ -14,6 +14,7 @@ #import "MBIMAuthToken.h" #import "MBIMUpdateQueue.h" #import "MBIMURLUtilities.h" +#import "MBIMLogging.h" #import #import "HTTPMessage.h" @@ -98,6 +99,10 @@ __block NSObject *response = nil; dispatch_semaphore_t sema = dispatch_semaphore_create(0); MBIMBridgeOperationCompletionBlock completion = ^(NSObject *incomingResponse) { + if (incomingResponse == nil) { + MBIMLogError(@"Operation for %@ %@ completed with a nil response.", method, path); + } + response = incomingResponse; dispatch_semaphore_signal(sema); }; @@ -124,6 +129,11 @@ if (requestTimedOut) { response = [_currentOperation cancelAndReturnTimeoutResponse]; } + + if (response == nil) { + MBIMLogError(@"Returning fallback 500 for %@ %@ because the operation produced no response.", method, path); + response = [[HTTPErrorResponse alloc] initWithErrorCode:500]; + } return response; } diff --git a/server/kordophone/Bridge/Operations/MBIMSendMessageOperation.m b/server/kordophone/Bridge/Operations/MBIMSendMessageOperation.m index 4e44864..10db1d4 100644 --- a/server/kordophone/Bridge/Operations/MBIMSendMessageOperation.m +++ b/server/kordophone/Bridge/Operations/MBIMSendMessageOperation.m @@ -23,6 +23,8 @@ - (nullable IMChat *)_chatForHandleIDs:(NSArray *)handleIDs registry:(IMChatRegistry *)registry { + MBIMLogInfo(@"Resolving send target for handles: %@", handleIDs); + IMAccount *iMessageAccount = [[IMAccountController sharedInstance] bestAccountForService:[IMServiceImpl iMessageService]]; if (!iMessageAccount) { MBIMLogError(@"Unable to find an iMessage account for message send."); @@ -47,6 +49,12 @@ chat = [registry chatWithHandle:handle]; } + if (chat) { + MBIMLogInfo(@"Resolved send target %@ to chat %@", [handle ID], [chat guid] ?: @""); + } else { + MBIMLogError(@"Unable to locate or create chat for handle %@", [handle ID]); + } + return chat; } @@ -60,6 +68,12 @@ chat = [registry chatWithHandles:handles displayName:nil joinedChatsOnly:YES]; } + if (chat) { + MBIMLogInfo(@"Resolved handles %@ to chat %@", handleIDs, [chat guid] ?: @""); + } else { + MBIMLogError(@"Unable to locate or create chat for handles %@", handleIDs); + } + return chat; } @@ -69,6 +83,13 @@ return nil; } + NSString *chatGUID = [chat guid]; + if (!chatGUID) { + chatGUID = [[[IMChatRegistry sharedInstance] allGUIDsForChat:chat] firstObject]; + } + + MBIMLogInfo(@"Preparing sendMessage for chat %@ (bodyLength=%lu attachmentCount=%lu)", chatGUID ?: @"", (unsigned long)[messageBody length], (unsigned long)[guids count]); + IMAccount *sendingAccount = [chat account]; if (!sendingAccount) { sendingAccount = [[IMAccountController sharedInstance] bestAccountForService:[IMServiceImpl iMessageService]]; @@ -92,9 +113,15 @@ [[IMFileTransferCenter sharedInstance] assignTransfer:guid toMessage:reply account:sendingAccount]; } - NSMutableDictionary *result = [[reply mbim_dictionaryRepresentation] mutableCopy]; + NSDictionary *replyRepresentation = [reply mbim_dictionaryRepresentation]; + if (![replyRepresentation isKindOfClass:[NSDictionary class]]) { + MBIMLogError(@"Unable to encode sent message for chat %@", chatGUID ?: @""); + return nil; + } + + NSMutableDictionary *result = [replyRepresentation mutableCopy]; if (includeConversationGUID) { - NSString *conversationGUID = [chat guid]; + NSString *conversationGUID = chatGUID; if (!conversationGUID) { conversationGUID = [[[IMChatRegistry sharedInstance] allGUIDsForChat:chat] firstObject]; } @@ -104,6 +131,7 @@ } } + MBIMLogInfo(@"Dispatching IMCore send for chat %@", chatGUID ?: @""); dispatch_async(dispatch_get_main_queue(), ^{ [chat sendMessage:reply]; }); @@ -138,6 +166,7 @@ NSError *error = nil; NSDictionary *args = [NSJSONSerialization JSONObjectWithData:self.requestBodyData options:0 error:&error]; if (error || args.count == 0) { + MBIMLogError(@"Unable to parse sendMessage request body: %@", error); self.serverCompletionBlock(response); return; } @@ -180,34 +209,65 @@ } } - dispatch_sync([[self class] sharedIMAccessQueue], ^{ - IMChatRegistry *registry = [IMChatRegistry sharedInstance]; - IMChat *chat = nil; - BOOL includeConversationGUID = NO; + MBIMLogInfo(@"sendMessage request received. guid=%@ handleIDs=%@ bodyLength=%lu attachmentGUIDs=%@", hasGUID ? guid : @"", handleIDs, (unsigned long)[messageBody length], transferGUIDs); - if (hasGUID) { - chat = [registry existingChatWithGUID:guid]; - if (!chat) { - response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Chat does not exist for the provided guid."]; + @try { + dispatch_sync([[self class] sharedIMAccessQueue], ^{ + IMChatRegistry *registry = [IMChatRegistry sharedInstance]; + IMChat *chat = nil; + BOOL includeConversationGUID = NO; + + if (hasGUID) { + MBIMLogInfo(@"sendMessage targeting existing conversation %@", guid); + chat = [registry existingChatWithGUID:guid]; + if (!chat) { + MBIMLogError(@"Chat does not exist for guid %@", guid); + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Chat does not exist for the provided guid."]; + return; + } + } else { + MBIMLogInfo(@"sendMessage targeting handles %@", handleIDs); + chat = [self _chatForHandleIDs:handleIDs registry:registry]; + includeConversationGUID = YES; + if (!chat) { + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Unable to create or locate a chat for the provided handles."]; + return; + } + } + + NSString *resolvedChatGUID = [chat guid]; + if (!resolvedChatGUID) { + resolvedChatGUID = [[[IMChatRegistry sharedInstance] allGUIDsForChat:chat] firstObject]; + } + MBIMLogInfo(@"sendMessage resolved target chat %@", resolvedChatGUID ?: @""); + + NSDictionary *result = [self _sendMessage:messageBody + toChat:chat + attachmentGUIDs:transferGUIDs + includeConversationGUID:includeConversationGUID]; + if (!result) { + MBIMLogError(@"sendMessage failed before a response payload could be encoded for chat %@", resolvedChatGUID ?: @""); + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Unable to construct sent message response."]; return; } - } else { - chat = [self _chatForHandleIDs:handleIDs registry:registry]; - includeConversationGUID = YES; - if (!chat) { - response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Unable to create or locate a chat for the provided handles."]; - return; - } - } - NSDictionary *result = [self _sendMessage:messageBody - toChat:chat - attachmentGUIDs:transferGUIDs - includeConversationGUID:includeConversationGUID]; - if (result) { - response = [MBIMJSONDataResponse responseWithJSONObject:result]; - } - }); + NSObject *jsonResponse = [MBIMJSONDataResponse responseWithJSONObject:result]; + if (jsonResponse) { + response = jsonResponse; + } else { + MBIMLogError(@"Unable to encode sendMessage JSON response for chat %@", resolvedChatGUID ?: @""); + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Unable to encode sendMessage response."]; + } + }); + } @catch (NSException *exception) { + MBIMLogError(@"Unhandled exception during sendMessage. name=%@ reason=%@ userInfo=%@", exception.name, exception.reason, exception.userInfo); + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"Unhandled exception while sending message. Check server logs."]; + } + + if (response == nil) { + MBIMLogError(@"sendMessage completed without producing a response. guid=%@ handleIDs=%@", hasGUID ? guid : @"", handleIDs); + response = [[MBIMErrorResponse alloc] initWithErrorCode:500 message:@"sendMessage did not produce a response. Check server logs."]; + } self.serverCompletionBlock(response); }