tmo1 / sms-ie

SMS Import / Export is a simple Android app that imports and exports SMS and MMS messages, call logs, and contacts from and to JSON / NDJSON files.
GNU General Public License v3.0
353 stars 39 forks source link

Unable to find or allocate a thread ID when importing MMS messages #150

Closed mrjnet closed 8 months ago

mrjnet commented 8 months ago

When importing MMS messages, 8 of 797 fail with popup error, "java.lang.IllegalArgumentException: Unable to find or allocate a thread ID." (all SMS messages import with no errors)

The Complete message is:

01-15 21:17:43.528 9094 9591 W System.err: java.lang.IllegalArgumentException: Unable to find or allocate a thread ID. 01-15 21:17:43.531 9094 9591 W System.err: at android.provider.Telephony$Threads.getOrCreateThreadId(Telephony.java:2214) 01-15 21:17:43.531 9094 9591 W System.err: at com.github.tmo1.sms_ie.ImportExportMessagesKt$importMessages$2$$ExternalSyntheticApiModelOutline2.m(R8$$SyntheticClass:0) 01-15 21:17:43.531 9094 9591 W System.err: at com.github.tmo1.sms_ie.ImportExportMessagesKt$importMessages$2.invokeSuspend(ImportExportMessages.kt:534) 01-15 21:17:43.531 9094 9591 W System.err: at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.internal.LimitedDispatcher$Worker.run(LimitedDispatcher.kt:115) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:100) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:584) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:793) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:697) 01-15 21:17:43.531 9094 9591 W System.err: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:684)

I would like to know how to identify these 8 MMS messages that could not be imported, to see if they are of any importance to me.

I have attached the log file created when importing: sms-import-log.out.zip

Thx.

tmo1 commented 8 months ago

I see that you included the logcat from a debug build - good. For privacy reasons, the logs, even from debug builds, do not include the actual data and metadata of messages, but it is relatively straightforward to locate the messages that are causing the problem:

  1. Search through the log for all instances of the message java.lang.IllegalArgumentException: Unable to find or allocate a thread ID.
  2. For each one, about a dozen lines earlier there's a message of the form Processing line #nnnn. The number nnnn is the line number of the message causing the error (within the file messages.ndjson).
  3. Use a text editor to view that line in the file, or extract it (via the Linux command line) using a command such as sed -n 'nnnn{q;d}' messages.ndjson.

The log does seem to show the source of the problem:

getThreadId: NO receipients specified -- NOT creating thread

SMS I/E message import code calls the Android method getOrCreateThreadId to assign thread identifiers to the messages it's importing. Your exporting system seems to have provided SMS I/E some messages that contain no recipients, which apparently causes the version of the method called by the MMS import code to throw an exception. (The problem does not seem to affect the version of the method called by the SMS import code - see here, here, here, and here.

I'll have to add code to check for MMS messages with no recipients and handle them somehow without crashing.

mrjnet commented 8 months ago

Thx for providing an explanation on how to determine which messages are failing to import. I have spend a couple of hours analyzing the log and message file. At first, I could not find the messages that did not have recipients, based upon the line numbers specified in the log file and then I noticed messages (exactly 8) which had the following format & text:

{"_id":"97","thread_id":"0","date":"1638360224","date_sent":"1638360225","msg_box":"1","read":"0","ct_t":"text\/plain","m_type":"132","v":"18","m_size":"22","st_ext":"0","retr_st":"226","retr_txt":"4504:Message not found","retr_txt_cs":"106","locked":"0","sub_id":"3","seen":"1","creator":"com.android.mms","text_only":"1","__parts":[{"_id":"127","mid":"97","seq":"0","ct":"text\/plain","cid":"","cl":"27656570211541","text":"4504:Message not found"}]}

Based upon this, I realized that there seems to be a +2-line offset between the line number cited in the log and the actual line number in the .ndjson file. Also, I noted that the log seems to indicate that the first MMS message is on line 4968, yet it is actually on line 4969 (only a 1-line offset). (Something to look into to aid in future debugging efforts? :-) )

I have attached a file contain the 8 messages that could not be imported, to aid in your future efforts in processing them.

Out of curiosity, have you seen this before?...is it a form of message corruption or Android just not cleaning up?

Thx again. msgs-not-imported.txt

tmo1 commented 8 months ago

Based upon this, I realized that there seems to be a +2-line offset between the line number cited in the log and the actual line number in the .ndjson file. Also, I noted that the log seems to indicate that the first MMS message is on line 4968, yet it is actually on line 4969 (only a 1-line offset). (Something to look into to aid in future debugging efforts? :-) )

The one line offset is due to the fact that text editors (typically?) start counting from 1, like human beings, whereas SMS I/E starts counting from 0, like computers :). I should have realized this, and I apologize for wasting your time. I don't have an explanation for the two line offset.

I have attached a file contain the 8 messages that could not be imported, to aid in your future efforts in processing them.

Thanks!

Out of curiosity, have you seen this before?

I have not.

is it a form of message corruption or Android just not cleaning up?

I don't know, but I've seen enough weirdness in message metadata to not be particularly surprised at the existence of such things.

In any event, I've confirmed that trying to insert MMS messages with no associated recipients will cause the errors that you saw, and I've implemented a workaround that just adds an empty recipient to such messages, which causes them to import without error. Would you please test the latest code and confirm that it solves the problem?

mrjnet commented 8 months ago

I have installed the latest debug code and can confirm that those 8 MMS messages (and all the others) now import successfully (with no errors) with a recipient of "null"; perhaps the recipient for these orphaned messages could be called "_sms_ie-lost+found_", similar to UNIX file systems...lol.

As an aside, I checked the messaging app on the "source" phone from which I exported the messages and while it does not show these 8 problem messages in the message listing (presumably, because there isn't a recipient), if I search the messages with "4504", the auto-fill displays the entire text but when I click on the message, nothing shows up. So, the messaging app does appear to know that they are there, it just filters them out.

With respect to debugging and the line offsets, perhaps (as a suggestion) in addition to the line number in the log, you could also display the date number associated with the message (nothing private in that); the line number can allow one to get to the vicinity of the desired message and the date code can allow confirmation that the desired message has been referenced.

eg. 01-15 21:17:43.524 9094 9591 D SMSIE : Processing line #5733, "date":"1638360224"

Thx for the fix!

mrjnet commented 8 months ago

Also BTW, I found that the app seems to obey the debug options settings ("Process SMS messages", "Process MMS messages") even if the "Enable debugging options" is turned OFF.

tmo1 commented 8 months ago

I have installed the latest debug code and can confirm that those 8 MMS messages (and all the others) now import successfully (with no errors) with a recipient of "null"; perhaps the recipient for these orphaned messages could be called "sms_ie-lost+found", similar to UNIX file systems...lol.

I considered something like that, but ultimately followed the SMS I/E general design principle of making the least intrusive modifications / additions possible to Android record data / metadata.

As an aside, I checked the messaging app on the "source" phone from which I exported the messages and while it does not show these 8 problem messages in the message listing (presumably, because there isn't a recipient), if I search the messages with "4504", the auto-fill displays the entire text but when I click on the message, nothing shows up. So, the messaging app does appear to know that they are there, it just filters them out.

Very interesting. As I said, there's quite a lot of weirdness in Android message metada.

With respect to debugging and the line offsets, perhaps (as a suggestion) in addition to the line number in the log, you could also display the date number associated with the message (nothing private in that); the line number can allow one to get to the vicinity of the desired message and the date code can allow confirmation that the desired message has been referenced.

Worth considering, although note that there is no absolute guarantee of timestamp uniqueness.

Thx for the fix!

You're welcome! Thanks for the report, good logcat, and detective work.

Also BTW, I found that the app seems to obey the debug options settings ("Process SMS messages", "Process MMS messages") even if the "Enable debugging options" is turned OFF.

Yes - the debugging options simply have a "dependency" on the "Enable debugging options" option, which merely means that:

When the corresponding switch is turned off, this Preference is disabled and is unable to be modified.

Perhaps "Unlock debugging options" would be a more accurate title. Alternatively, we could add code to set all the debug preferences back to their default values when "Enable debugging options" is turned off, or sprinkle checks throughout the application to only pay attention to the debug options when "Enable debugging options" is turned on, but these modifications would both require more code and work :|

mrjnet commented 8 months ago

WRT timestamp uniqueness, while I grant you that anything is possible, I think that the likelihood of multiple messages in the same vicinity of the data file, having a same received date (to the EXACT second) is unlikely. If that is of concern, then the addition of the "_id" field (also not private) as well would make it nearly impossible. :-)

WRT the debugging options, if that is the intended functionality, then I think the change to the option title you mentioned would be more intuitive for the end user. From my perspective, when I see options greyed out, I view them as disabled (and not applicable); this is why I thought that when the debugging options were disabled (and greyed out) that they would not affect the import.

Just my opinion. :-)