MMS success and failure

jezek · 24 Feb 2022, 14:41

@fizz Oh sorry I forgot, in the <UUID>.db file, in which you modified the status to "downloaded", you have to set the TelepathyErrorNotified field to "false".

Then on the next nuntium restart, it loads the <UUID>.db file, finds out that the file is downloaded (in the <UUID>.mms file), but some error happened (cause the message was stuck in "downloaded" state) and telepathy was not notified of the error. So it will try to send the message to the messaging-app again.

I hope it works. I currently am working on some fixes which should prevent the endless rotating pending circle. It's basicaly done, I'm just cleaning the code and beautifying the commits. I'll write when the PR(s) is(are) ready.

Fizz · 25 Feb 2022, 00:02

@jezek said in MMS success and failure:

@fizz Oh sorry I forgot, in the <UUID>.db file, in which you modified the status to "downloaded", you have to set the TelepathyErrorNotified field to "false".

Then on the next nuntium restart, it loads the <UUID>.db file, finds out that the file is downloaded (in the <UUID>.mms file), but some error happened (cause the message was stuck in "downloaded" state) and telepathy was not notified of the error. So it will try to send the message to the messaging-app again.

I hope it works. I currently am working on some fixes which should prevent the endless rotating pending circle. It's basicaly done, I'm just cleaning the code and beautifying the commits. I'll write when the PR(s) is(are) ready.

OK, i gave this a try. I had a fresh message with an image attached sent to me. I got the usual MMS error warning as usual. I found the .db file and changed the State (note it doesn't have a field named "Status") to "downloaded" and TelepathyErroyNotified to false. I then restarted the entire phone.

And... same thing as before. When i go back to the message and hig Download, it just keeps spinning non-stop, and i never get the image.

Also, even after another reboot of the phone, the button is still spinning.

-Fizz

jezek · 25 Feb 2022, 16:09

@fizz said in MMS success and failure:

OK, i gave this a try. I had a fresh message with an image attached sent to me. I got the usual MMS error warning as usual. I found the .db file and changed the State (note it doesn't have a field named "Status") to "downloaded" and TelepathyErroyNotified to false. I then restarted the entire phone.

You forgot to copy the file downloaded with wget into the storage folder named as <UUID>.mms (replace the <UUID> with the actual UUID, as in the .db file name).

Fizz · 25 Feb 2022, 22:15

@jezek said in MMS success and failure:

You forgot to copy the file downloaded with wget into the storage folder named as <UUID>.mms (replace the <UUID> with the actual UUID, as in the .db file name).

Where is the <uuid>.mms folder located? I haven't found any folders named that way. Is it supposed to be in the same place as the <uuid>.db files? If so, should i create the folder manually?

And should the downloaded file be named in any particular way, name or extension or otherwise?

-Fizz

jezek · 26 Feb 2022, 17:14

@fizz said in MMS success and failure:

Where is the <uuid>.mms folder located? I haven't found any folders named that way. Is it supposed to be in the same place as the <uuid>.db files? If so, should i create the folder manually?

As i wrote before, the storage is in ~/.local/share/nuntium/store/. So yes, it is supposed to be in the same place as the <UUID>.db file.

And should the downloaded file be named in any particular way, name or extension or otherwise?

The downloaded file should have the same name as the .db file, but different extension (.mms).
Example: There is a file

~/.local/share/nuntium/store $ ls                                                                                                                                          
00947a75dd5c33ff406f296bd5330caa.db

So after copying and renaming you should have

~/.local/share/nuntium/store $ ls                                                                                                                                          
00947a75dd5c33ff406f296bd5330caa.db
00947a75dd5c33ff406f296bd5330caa.mms

Fizz · 27 Feb 2022, 00:11

@jezek said in MMS success and failure:

As i wrote before, the storage is in ~/.local/share/nuntium/store/. So yes, it is supposed to be in the same place as the <UUID>.db file.

Oh, when you said "... into the storage folder named as <uuid>.mms" i thought you meant <uuid>.mms was the name of the folder. OK, i see now.

So, i had a fresh test message sent to me, which created a file in nuntium/store of 873cbe.db (shortened for posting, it's not actually that short). I changed the .db file to have "State":"downloaded" and "TelepathyErrorNotified":false . I used wget to download the message, renamed it to match the .db file (so it's 873cbd.mms) and moved it into the nuntium/store directory.

All of this is quite the pain on a little phone... ugh. Anyways, the result... same as before... it's just spinning after i tell it to download.

-Fizz

Fizz · 27 Feb 2022, 01:40

@jezek
Oh, forgot to mention, i did do a phone reboot as the last part of the process... no change.
-Fizz

jezek · 1 Mar 2022, 00:20

@fizz Can you post, or PM me the ~/.cache/upstart/nuntium.log, please?

Fizz · 3 Jan 2022, 00:24

@jezek said in MMS success and failure:

@fizz Can you post, or PM me the ~/.cache/upstart/nuntium.log, please?

Hrmmm... i don't have a nuntium.log there. I do have a nuntium.log.1.gz however.

I presume this is a zipped file, so i ran gzip on it and was able to open. I'll post it in the next message.

FYI, i did re-run through the whole process with a new image sent to me. Same result as before- constant spinning.

-Fizz

Fizz · 3 Jan 2022, 00:27

Ok, here is the content of the file...

2022/02/28 18:58:32 Received ReceiveNotification() method call from 44600
2022/02/28 18:58:32 Push data
00000000  00 06 29 1f 22 61 70 70  6c 69 63 61 74 69 6f 6e  |..)."application|
00000010  2f 76 6e 64 2e 77 61 70  2e 6d 6d 73 2d 6d 65 73  |/vnd.wap.mms-mes|
00000020  73 61 67 65 00 81 84 af  84 8d 01 00 8c 82 98 39  |sage...........9|
00000030  30 64 65 34 30 62 66 61  63 36 36 30 39 63 62 63  |0de40bfac6609cbc|
00000040  66 38 66 35 38 36 32 2d  31 00 8d 92 89 1a 80 18  |f8f5862-1.......|
00000050  ea 2b 31 35 31 39 38 35  39 30 35 34 37 2f 54 59  |.+15198590547/TY|
00000060  50 45 3d 50 4c 4d 4e 00  96 00 8a 80 88 05 81 03  |PE=PLMN.........|
00000070  09 3a 7e 86 81 83 68 74  74 70 3a 2f 2f 6d 6d 73  |.:~...http://mms|
00000080  63 32 2e 67 65 74 2e 62  65 6c 6c 2e 63 61 2f 63  |c2.get.bell.ca/c|
00000090  6c 6f 75 64 6d 6d 73 63  3f 6c 3d 39 30 64 65 34  |loudmmsc?l=90de4|
000000a0  30 62 66 61 63 36 36 30  39 63 62 63 66 38 66 35  |0bfac6609cbcf8f5|
000000b0  38 36 32 2d 31 00 8e 03  04 72 0a                 |862-1....r.|
2022/02/28 18:58:32 Trying to set Active property to true for context on true /ril_0/context2
2022/02/28 18:58:33 Download issues: org.freedesktop.DBus.Error.InvalidArgs: Invalid URL: ''
2022/02/28 18:58:33 Trying to set Active property to false for context on false /ril_0/context2
2022/02/28 18:58:45 Received unknown method call on org.ofono.mms.Message MarkRead
2022/02/28 18:58:45 Message /org/ofono/mms/302610917674682/843fd46d18383e9984a830164d648aad is not responded and not expired, not deleting.
2022/02/28 18:58:45 Received unknown method call on org.ofono.mms.Message MarkRead
2022/02/28 18:58:45 Message /org/ofono/mms/302610917674682/843fd46d18383e9984a830164d648aad is not responded and not expired, not deleting.
2022/02/28 19:08:54 Using session bus on :1.5
2022/02/28 19:08:54 Registered :1.5 on bus as org.ofono.mms
2022/02/28 19:08:54 Using system bus on :1.37
2022/02/28 19:08:54 Initializing modem /ril_0
2022/02/28 19:08:54 Modem online: true
2022/02/28 19:08:56 Identity added 302610917674682
2022/02/28 19:08:56 Service added /org/ofono/mms/302610917674682
2022/02/28 19:08:56 Initializing 3 messages from storage
2022/02/28 19:08:56 Message af88a769e57deda43a2b1e7a4e2d56e7 is not an incoming message. State: draft
2022/02/28 19:08:56 Using deprecated Start header
2022/02/28 19:08:56 Using deprecated Name header
2022/02/28 19:08:56 Using deprecated Name header
2022/02/28 19:08:56 Using deprecated Name header
2022/02/28 19:08:56 Push interface state: true
2022/02/28 19:08:57 Using deprecated Start header
2022/02/28 19:08:57 Using deprecated Name header
2022/02/28 19:08:57 Using deprecated Name header
2022/02/28 19:08:57 Using deprecated Name header
2022/02/28 19:08:57 Received GetServices()
2022/02/28 19:09:38 Redownload of /org/ofono/mms/302610917674682/843fd46d18383e9984a830164d648aad is not allowed

jezek · 1 Mar 2022, 16:43

@fizz Hmm. I'm not smarter from the log. I'll have to test by myself. I'll come back to you.I hope it'll be soon.

Meanwhile, please, could you write me, what is the state of the message .db, you have modified? Is it still "downloaded" and is the telepathy notified field still false? Thanks.

Fizz · 3 Mar 2022, 04:29

@jezek said in MMS success and failure:

@fizz Hmm. I'm not smarter from the log. I'll have to test by myself. I'll come back to you.I hope it'll be soon.

Meanwhile, please, could you write me, what is the state of the message .db, you have modified? Is it still "downloaded" and is the telepathy notified field still false? Thanks.

Actually, the .db State is now "received" (not my doing). TelepathyErrorNotified is still "false".

Thanks for your continued efforts in this.

-Fizz

jezek · 3 Mar 2022, 21:22

@fizz said in MMS success and failure:

Actually, the .db State is now "received" (not my doing). TelepathyErrorNotified is still "false".

The "received" state means that the messege was forwarded to messaging-app, which is strange that it is not there. But more strange is, that I don't see any error in loggs, so the message should ended in "responded" state. As I said I have to test this approach on my phone.

Thank you for answering my questions. I'll write you, when I know more.

jezek · 3 Dec 2022, 17:41

@fizz Hello, I've been able to make a test using the approach described above. The test was done in stable channel (OTA-22) after reboot and the commands have been punched via ssh.

I sent myself a testing multimedia message via the nuntium-inject-push testing helper tool.

phablet@ubuntu-phablet:~$ sudo ./nuntium-inject-push -s +421908353517 --sender-notification +421908353517 --transaction-id test-wget --error-activate-context=1
[sudo] password for phablet: 
No end-point flag provided, trying to retrieve end-point from nuntium logs in: /home/phablet/.cache/upstart
Using endpoint: ":1.55"
Creating web server to serve mms
Denial count: 0

The notification was delivered to messaging-app

I looked at the ~/.cache/upstart/nuntium.log

phablet@ubuntu-phablet:~$ tail .cache/upstart/nuntium.log
00000060  39 30 38 33 35 33 35 31  37 2f 54 59 50 45 3d 50  |908353517/TYPE=P|
00000070  4c 4d 4e 00 8a 80 8e 02  74 00 88 05 81 03 02 a2  |LMN.....t.......|
00000080  ff 83 68 74 74 70 3a 2f  2f 6c 6f 63 61 6c 68 6f  |..http://localho|
00000090  73 74 3a 39 31 39 31 2f  6d 6d 73 3f 65 72 72 6f  |st:9191/mms?erro|
000000a0  72 2d 61 63 74 69 76 61  74 65 2d 63 6f 6e 74 65  |r-activate-conte|
000000b0  78 74 3d 31 00                                    |xt=1.|
2022/03/11 18:10:19 This is a local test, skipping context activation and proxy settings
2022/03/11 18:10:19 Forcing debug error: main.downloadError{standartizedError:main.standartizedError{error:"error-activate-context", code:"x-ubports-nuntium-mms-error-activate-context"}}
2022/03/11 18:10:31 Received unknown method call on org.ofono.mms.Message MarkRead
2022/03/11 18:10:31 Message /org/ofono/mms/231014453153205/cb2e5a6911b100a99a13927694308474 is not responded and not expired, not deleting.

and extracted the message UUID cb2e5a6911b100a99a13927694308474 and download link http://localhost:9191/mms.
(Note: in the log there is "?error-activate-context=1" in the url. This is a testing string specific for the nuntium-inject-push tool and I know it's safe to remove. In real world usage use the whole link)

I downloaded the message content with wget using the download link into the storage as <UUID>.mms

phablet@ubuntu-phablet:~$ wget -O - http://localhost:9191/mms > ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.mms
--2022-03-11 18:23:50--  http://localhost:9191/mms
Resolving localhost (localhost)... ::1, 127.0.0.1
Connecting to localhost (localhost)|::1|:9191... failed: Connection refused.
Connecting to localhost (localhost)|127.0.0.1|:9191... connected.
HTTP request sent, awaiting response... 200 OK
Length: 3405 (3,3K) [application/octet-stream]
Saving to: ‘STDOUT’

-                                      100%[=========================================================================>]   3,33K  --.-KB/s    in 0s      

2022-03-11 18:23:50 (79,2 MB/s) - written to stdout [3405/3405]

And checked, if there is the file in the storage folder. (Note: I've also appended, what the files look like.)

phablet@ubuntu-phablet:~$ ls -l ~/.local/share/nuntium/store/
total 8
-rw------- 1 phablet phablet  653 mar 11 18:10 cb2e5a6911b100a99a13927694308474.db
-rw-rw-r-- 1 phablet phablet 3405 mar 11 18:23 cb2e5a6911b100a99a13927694308474.mms

phablet@ubuntu-phablet:~$ head -c 200 ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.mms 
���test-wget���abcdefghipqrrst�TZ�7��+421908353517/TYPE=PLMN��application/smil�<smil>/�+pplication/smil�smil.xml�smil.xml�"<smil><smil>   <head>     <layout>         <region id="Image

phablet@ubuntu-phablet:~$ head ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.db
{"Id":"test-wget","State":"notification","ContentLocation":"http://localhost:9191/mms?error-activate-context=1","SendState":null,"ModemId":"231014453153205","MNotificationInd":{"MMSReader":null,"UUID":"cb2e5a6911b100a99a13927694308474","RedownloadOfUUID":"","Received":"2022-03-11T18:10:19.122527716+01:00","Type":130,"Version":144,"Class":128,"DeliveryReport":0,"ReplyCharging":0,"ReplyChargingDeadline":0,"Priority":0,"ReplyChargingId":"","TransactionId":"test-wget","ContentLocation":"http://localhost:9191/mms","From":"+421908353517/TYPE=PLMN","Subject":"","Expiry":"2022-03-13T18:10:18.122527716+01:00","Size":29696},"TelepathyErrorNotified":true}

I edited the ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.db file and changed the State to "downloaded" and TelepathyErrorNotified to "false".

phablet@ubuntu-phablet:~$ sed -i 's/"State":"notification"/"State":"downloaded"/' ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.db 
phablet@ubuntu-phablet:~$ sed -i 's/"TelepathyErrorNotified":true/"TelepathyErrorNotified":false/' ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.db 
phablet@ubuntu-phablet:~$ head ~/.local/share/nuntium/store/cb2e5a6911b100a99a13927694308474.db
{"Id":"test-wget","State":"downloaded","ContentLocation":"http://localhost:9191/mms?error-activate-context=1","SendState":null,"ModemId":"231014453153205","MNotificationInd":{"MMSReader":null,"UUID":"cb2e5a6911b100a99a13927694308474","RedownloadOfUUID":"","Received":"2022-03-11T18:10:19.122527716+01:00","Type":130,"Version":144,"Class":128,"DeliveryReport":0,"ReplyCharging":0,"ReplyChargingDeadline":0,"Priority":0,"ReplyChargingId":"","TransactionId":"test-wget","ContentLocation":"http://localhost:9191/mms","From":"+421908353517/TYPE=PLMN","Subject":"","Expiry":"2022-03-13T18:10:18.122527716+01:00","Size":29696},"TelepathyErrorNotified":false}

I restarted nuntium (should be the same as restarting the phone)

phablet@ubuntu-phablet:~$ initctl --user restart nuntium
nuntium start/running, process 10665

There is the message instead of notification in the messaging app.

Here you can see the relevant logs produced in this test for comparsion.

For the record, I've also encountered a case, where the message was not delivered to messaging-app after restart, but it was due to bad wget usage, which produced an empty .mms file. So maybe if the file is somehow faulty, the message is not shown. This needs more investigation.