[Bug] MMS doesn't send pictures when Patchmanager is installed

ric9k · 9 January 2022 17:45

Hope it’s the right place.
Thought all bugs together in the [Bugs in Patchmanager ≥ 3.1.0] was not the right place, hope I got it right.

SailfishOS VERSION (Settings→About product→Build): 4.3.0.12 French
HARDWARE (Settings→About product→Manufacturer & Product name): Sony Xperia XA2
PATCHMANAGER VERSION (Settings→Patchmanager→[Top pulley] About): 3.2.0-1

BUG DESCRIPTION

MMS Picture sending fails when PM isd installed

STEPS TO REPRODUCE

Flash a fresh 4.3 Sfos (on XA2)
Take a picture
Send the picture via MMS (wifi) to test if it works, it works.
Install Storeman, Chum, Patchmanager (via Storeman)
Reboot
Send a picture via MMS (wifi) to test if it works, it does not work, saying there is a problem in the message thread.
Uninstall Patchmanager via Storeman
(no reboot needed) Try to send the picture, it works again.

ADDITIONAL INFORMATION

EDIT:
Output of

journalctl -f

Gives:

janv. 08 23:57:47 HoneypotJR mce[2272]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: OPEN → UNDEF
janv. 08 23:57:47 HoneypotJR invoker[5532]: WARNING: An inactive plugin is misbehaving - tried to show a window!
janv. 08 23:57:47 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:57:49 HoneypotJR jolla-messages[1918]: [W] unknown:99 - file:///usr/lib/qt5/qml/Sailfish/Messages/ChatTextInput.qml:99:17: QML Label: Binding loop detected for property “width”
janv. 08 23:57:50 HoneypotJR invoker[5532]: WARNING: An inactive plugin is misbehaving - tried to show a window!
janv. 08 23:57:50 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:57:50 HoneypotJR invoker[5532]: WARNING: invalid inputhandler for Xt9InputHandler.qml, forcing paste input handler
janv. 08 23:57:50 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:57:52 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:57:58 HoneypotJR invoker[5532]: WARNING: invalid inputhandler for Xt9InputHandler.qml, forcing paste input handler
janv. 08 23:57:58 HoneypotJR jolla-messages[1918]: [W] unknown:163 - file:///usr/lib/qt5/qml/Sailfish/Messages/MessageUtils.qml:163: TypeError: Cannot read property ‘phoneDetails’ of undefined
janv. 08 23:57:58 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:58:00 HoneypotJR invoker[5532]: WARNING: requestActivate() called for QQuickView(0x7d8730) which has Qt::WindowDoesNotAcceptFocus set.
janv. 08 23:58:00 HoneypotJR [5552]: [C] unknown:0 - Cannot copy message part file “/tmp/sailfish-share_wEm6mq/20220107_172525.jpg” to "/home/defaultuser/.local/share/commhistory/data/1573/20220107_172525.jpg"
janv. 08 23:58:00 HoneypotJR [5552]: [C] unknown:0 - Failed copying message part to storage; message dropped: 1573 "/tmp/sailfish-share_wEm6mq/20220107_172525.jpg"
janv. 08 23:58:00 HoneypotJR lipstick[5116]: [W] unknown:72 - file:///usr/share/lipstick-jolla-home-qt5/notifications/NotificationActionRow.qml:72:19: QML Button: Binding loop detected for property “width”
janv. 08 23:58:00 HoneypotJR mce[2272]: tklock.c: tklock_dbus_notification_beg_cb(): notification begin from name=:1.56 owner=:1.56 pid=5116 uid=100000 gid=996 priv=1 cmd=/usr/bin/lipstick -plugin evdevtouch -plugin evdevkeyboard:keym
janv. 08 23:58:00 HoneypotJR mce[2272]: tklock.c: tklock_datapipe_uiexception_type_cb(): uiexception_type = none → notif
janv. 08 23:58:00 HoneypotJR lipstick[5116]: [D] onDestruction:268 - coverActionIndicators destroyed jolla-messages.desktop
janv. 08 23:58:00 HoneypotJR jolla-messages[1918]: [W] unknown:82 - file:///usr/share/jolla-messages/pages/conversation/ConversationTextInput.qml:82:37: Unable to assign QJSValue to QString
janv. 08 23:58:01 HoneypotJR mce[2272]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: UNDEF → OPEN
janv. 08 23:58:02 HoneypotJR kernel: swr-wcd msm_sdw_swr_ctrl: swrm_cleanup_disabled_data_ports: end of list

Does it look like a folder/file permission error?
Thanks for Patchmanager anyways!

nephros · 10 January 2022 14:42

Thank you for the report, and the log and error message.

I can’t immediately imagine why those two might be related, but we’ll look into that.

Just for kicks, would you also post the relevant snippet of /var/log/zypp/history where it shows installation and uninstallation of the packages? Sometimes pkcon installs more than is immediately obvious.

Thanks!

phklrz · 10 January 2022 14:50

I confirm that with patchmanager installed I can’t send pictures and I can send pictures once patchmanager is uninstalled.

nephros · 10 January 2022 19:02

I can not reproduce this on SFOS 4.2 / arm32 / Xperia 10.

Did you guys reboot after installing PM?

nephros · 10 January 2022 19:05

Sorry, yes reboot was done according to the OP.

ric9k · 10 January 2022 19:11

Hi,
Yes, here it is right after a fresh OS flash + Storeman + Chum install. Strangely, I could see more errors on uninstallation than on install of Patchmanager…

> 2022-01-09 17:12:57|install|libsailfishcryptopluginapi|0.2.21-1.5.1.jolla|armv7hl||jolla|5aa60f1f87704da44dc45db4f044125d5628b63ccb43e04f25aa3021e24e8296|
> 2022-01-09 17:12:57|install|sailfishsecretsdaemon|0.2.21-1.5.1.jolla|armv7hl||jolla|64415cd79b168eae570190617c6645d295884f4a2de2c02e644da6bdb572b7e9|
> 2022-01-09 17:12:58|install|sailfishsecretsdaemon-secretsplugin-common|0.2.21-1.5.1.jolla|armv7hl||jolla|e6c36b12b579234d35c726b20ccab2f6d3bf0e5bab709e003638ce8ee594956f|
> 2022-01-09 17:12:58|install|sailfishsecretsdaemon-secretsplugins-default|0.2.21-1.5.1.jolla|armv7hl||jolla|a9bffcc38402955786289718a9ca25db0f7863bc938cfb87567b5eea512ecd43|
> 2022-01-09 17:12:59|install|harbour-storeman|0.2.11+sfos4.2.20210918134855.2.g1945da7-1.34.1.jolla|armv7hl|root@XperiaXA2-DualSIM|mentaljam-obs|bd21432253dbde8399f6a0686040002aef1f53367f7eb8d026305ed8489a3960|
> 2022-01-09 17:22:24|radd   |PK_TMP_DIR|dir:/var/tmp/TmpDir.36TlQN|
> 2022-01-09 17:22:24|command|root@XperiaXA2-DualSIM|'/usr/libexec/packagekitd'|
> 2022-01-09 17:22:24|install|sailfishos-chum|0.3.0-1.5.1.jolla|noarch|root@XperiaXA2-DualSIM|PK_TMP_DIR||
> 2022-01-09 17:22:25|rremove|PK_TMP_DIR|
> 2022-01-09 17:22:25|rremove|PK_TMP_DIR|
> 2022-01-09 17:22:51|radd   |PK_TMP_DIR|dir:/var/tmp/TmpDir.A7VnFM|
> 2022-01-09 17:22:51|command|root@XperiaXA2-DualSIM|'/usr/libexec/packagekitd'|
> 2022-01-09 17:22:51|install|sailfishos-chum-gui|0.3.1-1.3.1.jolla|armv7hl|root@XperiaXA2-DualSIM|PK_TMP_DIR||
> 2022-01-09 17:22:52|rremove|PK_TMP_DIR|
> 2022-01-09 17:29:35|command|root@XperiaXA2-DualSIM|'/usr/libexec/packagekitd'|
> 2022-01-09 17:29:35|install|patch|2.7.6+git1-1.5.1.jolla|armv7hl||jolla|eeff6558c1d6765cd95a04914f6368165d001351a985b2e7d17442a2a210213d|
> 2022-01-09 17:29:35|install|unzip|6.0-1.5.3.jolla|armv7hl||jolla|43af45a207c04e85f1798ff8d5cb71bfd41b20eb9c07b1cf7d08bb4dedb1d4fa|
> # 2022-01-09 17:29:38 patchmanager-3.2.0-1.armv7hl.rpm installed ok
> # Additional rpm output:
> # Installing patchmanager: pre section
> # Installing patchmanager: post section
> # sed: /etc/ld.so.preload: No such file or directory
> # 
> 2022-01-09 17:29:38|install|patchmanager|3.2.0-1|armv7hl|root@XperiaXA2-DualSIM|openrepos-Patchmanager|f720033fdf7001b58b8b894cecd248001ff77bac|
> 2022-01-09 17:57:22|command|root@XperiaXA2-DualSIM|'/usr/libexec/packagekitd'|
> # 2022-01-09 17:57:23 patchmanager-3.2.0-1.armv7hl removed ok
> # Additional rpm output:
> # Uninstalling patchmanager: preun section
> # ERROR: ld.so: object '/usr/lib/libpreloadpatchmanager.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
> # Uninstalling patchmanager: postun section
> # ERROR: ld.so: object '/usr/lib/libpreloadpatchmanager.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
> # ERROR: ld.so: object '/usr/lib/libpreloadpatchmanager.so' from /etc/ld.so.preload cannot be preloaded (cannot open shared object file): ignored.
> # 
> 2022-01-09 17:57:23|remove |patchmanager|3.2.0-1|armv7hl|root@XperiaXA2-DualSIM|

veskuy · 10 January 2022 19:32

I couldn’t send MMS messages for a long time with Xperia 10 ii. After uninstalling Patchmanager sending them works again. Thanks for the report!

ric9k · 10 January 2022 19:43

By chance, testing to get MMS back was successful on the 3rd installed app.
I wouldn’t have liked to have to reinstall/reboot all of them to find the problem

vlagged · 10 January 2022 23:43

Nice find, @ric9k - I can also reproduce this.

I’ve tried stracing jolla-messages, sailfish-share and commhistoryd and I’ve yet to find an explanation (the second one is a new process at each share popover).

sailfish-share seems to be passing a descriptor to jolla-messages and the messages app makes a 0x20000-byte buffered copy into /tmp/sailfish-share_XYZ then something goes wrong, by the time it passes it to commhistoryd the file is already unlinked (looks like jolla-messages does this, not sure about the timing).

Looks like you do get a preview of the file in the message, but when you hit send the file is already gone (hence the error you found).

There may be some open() bugs in the preloading library of patchmanager, I have yet to see its role here, will need to dig further.

Since the separate sailifsh-share process was introduced in SFOS 4.3.0, I’d also be curios if anyone has a previous version to check if the bug was there too.

wetab73 · 11 January 2022 03:34

I’m on freshly flashed licenced 4.3.0.12 on Xperia XA2 Ultra, with Patchmanager installed, and I do NOT have problems with sending MMS. On the contrary, I have problems with receiving MMS, if the message only contains a multimedia file (image, audio, etc.) but no text - as reported here.

vlagged · 11 January 2022 14:11

Hmm maybe it’s a 64-bit thing …

dcaliste · 11 January 2022 15:10

I’ve seen this PR from @pvuorela recently in libcommhistory :

github.com/sailfishos/libcommhistory

[libcommhistory] Fix race when sending a temporary file with MMS. JB#56314

sailfishos:master ← sailfishos:jb56314-fix_mms_race

opened 11:22AM - 03 Jan 22 UTC

pvuorela

+21 -1

If the file to be sent is a temporary file, the owner might assume it can be re…moved after sendMessage() finishes. Avoid that by creating a temporary file owned by the helper, hard link as first option and file copy if that fails. The copy case might not be the most efficient, but the files should be small enough here and it's simple on api. @Tomin1 @monich

It looks like a race condition, but I cannot figure out why Patchmanager is consistently putting in on the wrong path…

vlagged · 11 January 2022 18:02

In this case patchmanager should introduce a infinitesimal delay of checking that the path starts with tmp and bailing querying the patchmanager service for a patched file.

Thanks for your find @dcaliste! I’ve built that branch and the results seem better (i.e image loads, MMS says sending…).
If you are blocked by this and want to use patchmanager, upgrade to this libcommhistory-qt5-1.11.12+jb56314.fix_mms_race package (aarch64 only) package: Show nemo:devel:hw:xiaomi:tucana / libcommhistory - SailfishOS Open Build Service

If anything goes wrong, for 4.3.0.12 you need to downgrade libcommhistory to 1.11.11-1.11.1.jolla

ric9k · 11 January 2022 19:01

Great you guys found something!
I could test it too on armv7 but have no sdk neither would know how.
But no hurry.

vlagged · 11 January 2022 21:56

I did try building armv7hl on OBS, but did not test it. Use with caution: State of Repository sailfish_latest_armv7hl for home:b100dian:commhistoryd / libcommhistory - SailfishOS Open Build Service

ric9k · 12 January 2022 05:50

Thanks,
For a normal usage, du I only need to rmp install libcommhistory-qt5-1.11.12?

vlagged · 12 January 2022 13:07

I think -declarative and -tools too. Since I actually installed them from the repo it was easier for me. Maybe you should use zypper ar to add that repository, zypper ref and the zypper up libcommhistory-qt5

ric9k · 12 January 2022 14:20

@vlagged Brilliant!
Thank you for that and for de-noobing me.

For other new users, if useful, I did:

$ devel-su
$ pkcon install zypper
$ zypper ar https://repo.sailfishos.org/obs/home:/b100dian:/commhistoryd/sailfish_latest_armv7hl/home:b100dian:commhistoryd.repo
$ zypper ref
$ zypper up libcommhistory-qt5

Installed Patchmanager, rebooted.
SMS in and out work, MMS in and out work (wifi).

It complained about repomd.xml and packages being unsigned.
That’s expected, isn’t it?

vlagged · 12 January 2022 15:44

Yes, public OBS does not sign…
Thanks for confirming that it works - and welcome to the world of watching github PRs to see when the fix will be merged then watching the text changelog to see when the fix will be delivered in a sailfish update:) If you get this package listed as conflicting at the next update, you need to downgrade it first to the version above with something like zypper install --oldpackage package-name-x.x.x

ric9k · 13 January 2022 05:49

Ok. Now, the bug is in my head: How will I remember to downgrade before upgrading? :–)
Thanks again.
Cheers