MMS success and failure

Fizz

@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

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

@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

@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

@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

@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
Screenshot - Message with notification

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.