Use a consistent logging string for the xms message id

Test: Manually tested sending/receiving SMSs and MMSs
Change-Id: I4260ef5ab6f0be19a41ab1c650acb7519e87c53e
diff --git a/src/com/android/mms/service/DownloadRequest.java b/src/com/android/mms/service/DownloadRequest.java
index b17a35a..5df1f95 100644
--- a/src/com/android/mms/service/DownloadRequest.java
+++ b/src/com/android/mms/service/DownloadRequest.java
@@ -72,9 +72,10 @@
         final String requestId = getRequestId();
         final MmsHttpClient mmsHttpClient = netMgr.getOrCreateHttpClient();
         if (mmsHttpClient == null) {
-            LogUtil.e(requestId, "MMS network is not ready! messageId: " + mMessageId);
-            throw new MmsHttpException(0/*statusCode*/, "MMS network is not ready. messageId: "
-                    + mMessageId);
+            LogUtil.e(requestId, "MMS network is not ready! "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
+            throw new MmsHttpException(0/*statusCode*/, "MMS network is not ready. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
         }
         return mmsHttpClient.execute(
                 mLocationUrl,
@@ -107,9 +108,11 @@
         if (!mRequestManager.getAutoPersistingPref()) {
             return null;
         }
-        LogUtil.d(requestId, "persistIfRequired. messageId: " + mMessageId);
+        LogUtil.d(requestId, "persistIfRequired. "
+                + MmsService.formatCrossStackMessageId(mMessageId));
         if (response == null || response.length < 1) {
-            LogUtil.e(requestId, "persistIfRequired: empty response. messageId: " + mMessageId);
+            LogUtil.e(requestId, "persistIfRequired: empty response. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
             return null;
         }
         final long identity = Binder.clearCallingIdentity();
@@ -118,15 +121,15 @@
                     mMmsConfig.getBoolean(SmsManager.MMS_CONFIG_SUPPORT_MMS_CONTENT_DISPOSITION);
             final GenericPdu pdu = (new PduParser(response, supportMmsContentDisposition)).parse();
             if (pdu == null || !(pdu instanceof RetrieveConf)) {
-                LogUtil.e(requestId, "persistIfRequired: invalid parsed PDU. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: invalid parsed PDU. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             final RetrieveConf retrieveConf = (RetrieveConf) pdu;
             final int status = retrieveConf.getRetrieveStatus();
             if (status != PduHeaders.RETRIEVE_STATUS_OK) {
                 LogUtil.e(requestId, "persistIfRequired: retrieve failed " + status
-                        + ", messageId: " + mMessageId);
+                        + ", " + MmsService.formatCrossStackMessageId(mMessageId));
                 // Update the retrieve status of the NotificationInd
                 final ContentValues values = new ContentValues(1);
                 values.put(Telephony.Mms.RETRIEVE_STATUS, status);
@@ -151,8 +154,8 @@
                     true/*groupMmsEnabled*/,
                     null/*preOpenedFiles*/);
             if (messageUri == null) {
-                LogUtil.e(requestId, "persistIfRequired: can not persist message. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: can not persist message. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             // Update some of the properties of the message
@@ -171,8 +174,8 @@
                     values,
                     null/*where*/,
                     null/*selectionArg*/) != 1) {
-                LogUtil.e(requestId, "persistIfRequired: can not update message. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: can not update message. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
             }
             // Delete the corresponding NotificationInd
             SqliteWrapper.delete(context,
@@ -186,14 +189,14 @@
 
             return messageUri;
         } catch (MmsException e) {
-            LogUtil.e(requestId, "persistIfRequired: can not persist message. messageId: "
-                    + mMessageId, e);
+            LogUtil.e(requestId, "persistIfRequired: can not persist message. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         } catch (SQLiteException e) {
-            LogUtil.e(requestId, "persistIfRequired: can not update message. messageId: "
-                    + mMessageId, e);
+            LogUtil.e(requestId, "persistIfRequired: can not update message. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         } catch (RuntimeException e) {
-            LogUtil.e(requestId, "persistIfRequired: can not parse response. messageId: "
-                    + mMessageId, e);
+            LogUtil.e(requestId, "persistIfRequired: can not parse response. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         } finally {
             Binder.restoreCallingIdentity(identity);
         }
@@ -293,11 +296,11 @@
             if (mCarrierMessagingServiceWrapper.bindToCarrierMessagingService(
                     context, carrierMessagingServicePackage, Runnable::run,
                     ()->onServiceReady())) {
-                LogUtil.v("bindService() for carrier messaging service succeeded. messageId: "
-                        + mMessageId);
+                LogUtil.v("bindService() for carrier messaging service succeeded. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
             } else {
-                LogUtil.e("bindService() for carrier messaging service failed. messageId: "
-                        + mMessageId);
+                LogUtil.e("bindService() for carrier messaging service failed. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 carrierDownloadCallback.onDownloadMmsComplete(
                         CarrierMessagingService.DOWNLOAD_STATUS_RETRY_ON_CARRIER_NETWORK);
             }
@@ -309,7 +312,8 @@
                         mContentUri, mSubId, Uri.parse(mLocationUrl), Runnable::run,
                         mCarrierDownloadCallback);
             } catch (RuntimeException e) {
-                LogUtil.e("Exception downloading MMS for messageId " + mMessageId
+                LogUtil.e("Exception downloading MMS for "
+                        + MmsService.formatCrossStackMessageId(mMessageId)
                         + " using the carrier messaging service: " + e, e);
                 mCarrierDownloadCallback.onDownloadMmsComplete(
                         CarrierMessagingService.DOWNLOAD_STATUS_RETRY_ON_CARRIER_NETWORK);
@@ -335,13 +339,13 @@
         @Override
         public void onSendMmsComplete(int result, byte[] sendConfPdu) {
             LogUtil.e("Unexpected onSendMmsComplete call with result: " + result
-                    + ", messageId: " + mMessageId);
+                    + ", " + MmsService.formatCrossStackMessageId(mMessageId));
         }
 
         @Override
         public void onDownloadMmsComplete(int result) {
             LogUtil.d("Carrier app result for download: " + result
-                    + ", messageId: " + mMessageId);
+                    + ", " + MmsService.formatCrossStackMessageId(mMessageId));
             mCarrierDownloadManager.disposeConnection(mContext);
 
             if (!maybeFallbackToRegularDelivery(result)) {
diff --git a/src/com/android/mms/service/MmsRequest.java b/src/com/android/mms/service/MmsRequest.java
index b6a8bd4..89b8620 100644
--- a/src/com/android/mms/service/MmsRequest.java
+++ b/src/com/android/mms/service/MmsRequest.java
@@ -351,8 +351,8 @@
                 == CarrierMessagingService.SEND_STATUS_RETRY_ON_CARRIER_NETWORK
                 || carrierMessagingAppResult
                         == CarrierMessagingService.DOWNLOAD_STATUS_RETRY_ON_CARRIER_NETWORK) {
-            LogUtil.d(this.toString(), "Sending/downloading MMS by IP failed. messageId: "
-                    + mMessageId);
+            LogUtil.d(this.toString(), "Sending/downloading MMS by IP failed. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
             mRequestManager.addSimRequest(MmsRequest.this);
             return true;
         } else {
@@ -377,10 +377,9 @@
     @Override
     public String toString() {
         return getClass().getSimpleName() + '@' + Integer.toHexString(hashCode())
-                + " messageId: " + mMessageId;
+                + " " + MmsService.formatCrossStackMessageId(mMessageId);
     }
 
-
     protected String getRequestId() {
         return this.toString();
     }
@@ -446,19 +445,22 @@
     protected abstract class CarrierMmsActionCallback implements CarrierMessagingCallback {
         @Override
         public void onSendSmsComplete(int result, int messageRef) {
-            LogUtil.e("Unexpected onSendSmsComplete call for messageId " + mMessageId
+            LogUtil.e("Unexpected onSendSmsComplete call for "
+                    + MmsService.formatCrossStackMessageId(mMessageId)
                     + " with result: " + result);
         }
 
         @Override
         public void onSendMultipartSmsComplete(int result, int[] messageRefs) {
-            LogUtil.e("Unexpected onSendMultipartSmsComplete call for messageId " + mMessageId
+            LogUtil.e("Unexpected onSendMultipartSmsComplete call for "
+                    + MmsService.formatCrossStackMessageId(mMessageId)
                     + " with result: " + result);
         }
 
         @Override
         public void onReceiveSmsComplete(int result) {
-            LogUtil.e("Unexpected onFilterComplete call for messageId " + mMessageId
+            LogUtil.e("Unexpected onFilterComplete call for "
+                    + MmsService.formatCrossStackMessageId(mMessageId)
                     + " with result: " + result);
         }
     }
diff --git a/src/com/android/mms/service/MmsService.java b/src/com/android/mms/service/MmsService.java
index eb0fd88..8ec30d6 100644
--- a/src/com/android/mms/service/MmsService.java
+++ b/src/com/android/mms/service/MmsService.java
@@ -189,7 +189,7 @@
         public void sendMessage(int subId, String callingPkg, Uri contentUri,
                 String locationUrl, Bundle configOverrides, PendingIntent sentIntent,
                 long messageId) {
-            LogUtil.d("sendMessage messageId: " + messageId);
+            LogUtil.d("sendMessage " + formatCrossStackMessageId(messageId));
             enforceSystemUid();
 
             // Make sure the subId is correct
@@ -216,7 +216,8 @@
                     getCarrierMessagingServicePackageIfExists(subId);
 
             if (carrierMessagingServicePackage != null) {
-                LogUtil.d(request.toString(), "sending message by carrier app");
+                LogUtil.d(request.toString(), "sending message by carrier app "
+                        + formatCrossStackMessageId(messageId));
                 request.trySendingByCarrierApp(MmsService.this, carrierMessagingServicePackage);
                 return;
             }
@@ -245,7 +246,7 @@
             // subIds, so we should try to download anyway.
             // TODO: Fail fast when downloading will fail (i.e. SIM swapped)
             LogUtil.d("downloadMessage: " + MmsHttpClient.redactUrlForNonVerbose(locationUrl) +
-                    ", messageId: " + messageId);
+                    ", " + formatCrossStackMessageId(messageId));
 
             enforceSystemUid();
 
@@ -285,7 +286,8 @@
                     getCarrierMessagingServicePackageIfExists(subId);
 
             if (carrierMessagingServicePackage != null) {
-                LogUtil.d(request.toString(), "downloading message by carrier app");
+                LogUtil.d(request.toString(), "downloading message by carrier app "
+                        + formatCrossStackMessageId(messageId));
                 request.tryDownloadingByCarrierApp(MmsService.this, carrierMessagingServicePackage);
                 return;
             }
@@ -1050,4 +1052,8 @@
         }
         return false;
     }
+
+    static String formatCrossStackMessageId(long id) {
+        return "{x-message-id:" + id + "}";
+    }
 }
diff --git a/src/com/android/mms/service/SendRequest.java b/src/com/android/mms/service/SendRequest.java
index 6691bac..c03b8bc 100644
--- a/src/com/android/mms/service/SendRequest.java
+++ b/src/com/android/mms/service/SendRequest.java
@@ -72,7 +72,8 @@
         final String requestId = getRequestId();
         final MmsHttpClient mmsHttpClient = netMgr.getOrCreateHttpClient();
         if (mmsHttpClient == null) {
-            String notReady = "MMS network is not ready! messageId: " + mMessageId;
+            String notReady = "MMS network is not ready! "
+                    + MmsService.formatCrossStackMessageId(mMessageId);
             LogUtil.e(requestId, notReady);
             throw new MmsHttpException(0/*statusCode*/, notReady);
         }
@@ -95,14 +96,16 @@
         final String requestId = getRequestId();
         try {
             if (mPduData == null) {
-                LogUtil.w(requestId, "Empty PDU raw data. messageId: " + mMessageId);
+                LogUtil.w(requestId, "Empty PDU raw data. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             final boolean supportContentDisposition =
                     mMmsConfig.getBoolean(SmsManager.MMS_CONFIG_SUPPORT_MMS_CONTENT_DISPOSITION);
             return new PduParser(mPduData, supportContentDisposition).parse();
         } catch (final Exception e) {
-            LogUtil.w(requestId, "Failed to parse PDU raw data. messageId: " + mMessageId);
+            LogUtil.w(requestId, "Failed to parse PDU raw data. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
         }
         return null;
     }
@@ -115,7 +118,8 @@
         try {
             notifyIfEmergencyContact(parsedPdu);
         } catch (Exception e) {
-            LogUtil.w(getRequestId(), "Error in notifyIfEmergencyContact. messageId: " + mMessageId, e);
+            LogUtil.w(getRequestId(), "Error in notifyIfEmergencyContact. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         }
     }
 
@@ -124,8 +128,8 @@
             SendReq sendReq = (SendReq) parsedPdu;
             for (EncodedStringValue encodedStringValue : sendReq.getTo()) {
                 if (isEmergencyNumber(encodedStringValue.getString())) {
-                    LogUtil.i(getRequestId(), "Notifying emergency contact. messageId: "
-                            + mMessageId);
+                    LogUtil.i(getRequestId(), "Notifying emergency contact. "
+                            + MmsService.formatCrossStackMessageId(mMessageId));
                     new AsyncTask<Void, Void, Void>() {
                         @Override
                         protected Void doInBackground(Void... voids) {
@@ -134,8 +138,8 @@
                                         .notifyEmergencyContact(mContext);
                             } catch (Exception e) {
                                 LogUtil.e(getRequestId(),
-                                    "Exception notifying emergency contact. messageId: "
-                                            + mMessageId + e);
+                                    "Exception notifying emergency contact. "
+                                            + MmsService.formatCrossStackMessageId(mMessageId) + e);
                             }
                             return null;
                         }
@@ -172,9 +176,11 @@
             // Not required to persist
             return null;
         }
-        LogUtil.d(requestId, "persistIfRequired. messageId: " + mMessageId);
+        LogUtil.d(requestId, "persistIfRequired. "
+                + MmsService.formatCrossStackMessageId(mMessageId));
         if (mPduData == null) {
-            LogUtil.e(requestId, "persistIfRequired: empty PDU. messageId: " + mMessageId);
+            LogUtil.e(requestId, "persistIfRequired: empty PDU. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
             return null;
         }
         final long identity = Binder.clearCallingIdentity();
@@ -184,12 +190,13 @@
             // Persist the request PDU first
             GenericPdu pdu = (new PduParser(mPduData, supportContentDisposition)).parse();
             if (pdu == null) {
-                LogUtil.e(requestId, "persistIfRequired: can't parse input PDU. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: can't parse input PDU. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             if (!(pdu instanceof SendReq)) {
-                LogUtil.d(requestId, "persistIfRequired: not SendReq. messageId: " + mMessageId);
+                LogUtil.d(requestId, "persistIfRequired: not SendReq. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             final PduPersister persister = PduPersister.getPduPersister(context);
@@ -200,8 +207,8 @@
                     true/*groupMmsEnabled*/,
                     null/*preOpenedFiles*/);
             if (messageUri == null) {
-                LogUtil.e(requestId, "persistIfRequired: can not persist message. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: can not persist message. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 return null;
             }
             // Update the additional columns based on the send result
@@ -239,16 +246,16 @@
             values.put(Telephony.Mms.SUBSCRIPTION_ID, mSubId);
             if (SqliteWrapper.update(context, context.getContentResolver(), messageUri, values,
                     null/*where*/, null/*selectionArg*/) != 1) {
-                LogUtil.e(requestId, "persistIfRequired: failed to update message. messageId: "
-                        + mMessageId);
+                LogUtil.e(requestId, "persistIfRequired: failed to update message. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
             }
             return messageUri;
         } catch (MmsException e) {
-            LogUtil.e(requestId, "persistIfRequired: can not persist message. messageId: "
-                    + mMessageId, e);
+            LogUtil.e(requestId, "persistIfRequired: can not persist message. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         } catch (RuntimeException e) {
-            LogUtil.e(requestId, "persistIfRequired: unexpected parsing failure. messageId: "
-                    + mMessageId, e);
+            LogUtil.e(requestId, "persistIfRequired: unexpected parsing failure. "
+                    + MmsService.formatCrossStackMessageId(mMessageId), e);
         } finally {
             Binder.restoreCallingIdentity(identity);
         }
@@ -263,12 +270,13 @@
     private void updateDestinationAddress(final GenericPdu pdu) {
         final String requestId = getRequestId();
         if (pdu == null) {
-            LogUtil.e(requestId, "updateDestinationAddress: can't parse input PDU. messageId: "
-                    + mMessageId);
+            LogUtil.e(requestId, "updateDestinationAddress: can't parse input PDU. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
             return ;
         }
         if (!(pdu instanceof SendReq)) {
-            LogUtil.i(requestId, "updateDestinationAddress: not SendReq. messageId: " + mMessageId);
+            LogUtil.i(requestId, "updateDestinationAddress: not SendReq. "
+                    + MmsService.formatCrossStackMessageId(mMessageId));
             return;
         }
 
@@ -409,11 +417,11 @@
             if (mCarrierMessagingServiceWrapper.bindToCarrierMessagingService(
                     context, carrierMessagingServicePackage, Runnable::run,
                     () -> onServiceReady())) {
-                LogUtil.v("bindService() for carrier messaging service succeeded. messageId: "
-                        + mMessageId);
+                LogUtil.v("bindService() for carrier messaging service succeeded. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
             } else {
-                LogUtil.e("bindService() for carrier messaging service failed. messageId: "
-                        + mMessageId);
+                LogUtil.e("bindService() for carrier messaging service failed. "
+                        + MmsService.formatCrossStackMessageId(mMessageId));
                 carrierSendCompleteCallback.onSendMmsComplete(
                         CarrierMessagingService.SEND_STATUS_RETRY_ON_CARRIER_NETWORK,
                         null /* no sendConfPdu */);
@@ -430,8 +438,8 @@
                         mPduUri, mSubId, locationUri, Runnable::run,
                         mCarrierSendCompleteCallback);
             } catch (RuntimeException e) {
-                LogUtil.e("Exception sending MMS using the carrier messaging service. messageId: "
-                        + mMessageId + e, e);
+                LogUtil.e("Exception sending MMS using the carrier messaging service. "
+                        + MmsService.formatCrossStackMessageId(mMessageId) + e, e);
                 mCarrierSendCompleteCallback.onSendMmsComplete(
                         CarrierMessagingService.SEND_STATUS_RETRY_ON_CARRIER_NETWORK,
                         null /* no sendConfPdu */);
@@ -455,7 +463,9 @@
 
         @Override
         public void onSendMmsComplete(int result, byte[] sendConfPdu) {
-            LogUtil.d("Carrier app result for sending messageId " + mMessageId + ": " + result);
+            LogUtil.d("Carrier app result for sending "
+                    + MmsService.formatCrossStackMessageId(mMessageId)
+                    + ": " + result);
             mCarrierSendManager.disposeConnection(mContext);
 
             if (!maybeFallbackToRegularDelivery(result)) {
@@ -466,7 +476,8 @@
 
         @Override
         public void onDownloadMmsComplete(int result) {
-            LogUtil.e("Unexpected onDownloadMmsComplete call for messageId " + mMessageId
+            LogUtil.e("Unexpected onDownloadMmsComplete call for "
+                    + MmsService.formatCrossStackMessageId(mMessageId)
                     + " with result: " + result);
         }
     }