mconnect icon indicating copy to clipboard operation
mconnect copied to clipboard

Published 20 hours ago • verified publisher icon bboozzoo

mconnect creates and renames files non-stop in `~/.cache/mconnect`

Open moviuro opened this issue 2 years ago • 8 comments

I noticed heavy usage of my drive, caused by mconnect

% { strace mconnect } 2>&1| grep --line-buffered .cache/mconnect/devices....... | pv >/dev/null
30,0KiB 0:00:01 [30,0KiB/s] [  <=>                                                                                                                 ]

Sample log:

...
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.UYPW61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.UYPW61", "/home/moviuro/.cache/mconnect/devices") = 0
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.JXTW61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.JXTW61", "/home/moviuro/.cache/mconnect/devices") = 0
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.X8LW61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.X8LW61", "/home/moviuro/.cache/mconnect/devices") = 0
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.6POW61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.6POW61", "/home/moviuro/.cache/mconnect/devices") = 0
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.9BRV61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.9BRV61", "/home/moviuro/.cache/mconnect/devices") = 0
openat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices.SHKV61", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 13
newfstatat(AT_FDCWD, "/home/moviuro/.cache/mconnect/devices", {st_mode=S_IFREG|0644, st_size=6534, ...}, AT_SYMLINK_NOFOLLOW) = 0
rename("/home/moviuro/.cache/mconnect/devices.SHKV61", "/home/moviuro/.cache/mconnect/devices") = 0
...

% mconnect -d
...
** INFO: 15:25:30.795: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.798: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.798: devicechannel.vala:270: received line: {"id":1687267531432,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.798: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.798: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.798: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.798: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530798,"body":{"pair":true}}

** INFO: 15:25:30.798: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.803: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.803: devicechannel.vala:270: received line: {"id":1687267531434,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.803: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.803: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.803: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.803: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530803,"body":{"pair":true}}

** INFO: 15:25:30.803: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.806: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.806: devicechannel.vala:270: received line: {"id":1687267531440,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.806: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.806: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.806: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.806: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530806,"body":{"pair":true}}

** INFO: 15:25:30.807: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.811: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.811: devicechannel.vala:270: received line: {"id":1687267531443,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.811: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.811: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.811: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.811: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530811,"body":{"pair":true}}

** INFO: 15:25:30.811: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.814: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.814: devicechannel.vala:270: received line: {"id":1687267531448,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.814: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.814: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.814: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.814: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530814,"body":{"pair":true}}

** INFO: 15:25:30.814: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.820: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.820: devicechannel.vala:270: received line: {"id":1687267531452,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.820: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.820: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.820: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.820: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530820,"body":{"pair":true}}

** INFO: 15:25:30.820: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
** (mconnect:378616): DEBUG: 15:25:30.825: devicechannel.vala:285: check for IO, conditions: 0x1
** (mconnect:378616): DEBUG: 15:25:30.825: devicechannel.vala:270: received line: {"id":1687267531459,"type":"kdeconnect.pair","body":{"pair":true}}
** (mconnect:378616): DEBUG: 15:25:30.825: device.vala:418: pair in progress: false is paired: true pair: true
** (mconnect:378616): DEBUG: 15:25:30.825: device.vala:433: unsolicited pair change from device, pair status: true
** (mconnect:378616): DEBUG: 15:25:30.825: device.vala:275: start pairing
** (mconnect:378616): DEBUG: 15:25:30.825: devicechannel.vala:229: send data: {"type":"kdeconnect.pair","id":1687267530825,"body":{"pair":true}}

** INFO: 15:25:30.825: devicemanager.vala:190: device cda1530b_39c8_4e7e_add9_c09c32518d31-Oneirophrenia-phone-7 pair status change: true
...

moviuro avatar Jun 20 '23 13:06 moviuro

Removing this line seems to fix the issue. I have no idea about the side effects though.

https://github.com/bboozzoo/mconnect/blob/51b81447acdfe3cde07e1fd1504e54fe24c11c59/src/mconnect/device.vala#L443

moviuro avatar Jun 20 '23 15:06 moviuro

i'm seeing this behaviour as well - I wonder if the mobile app changed behaviour to cause this?

from poking around the code last night, that seems like a reasonable solution. though the code also seems to love calling handle_pair(true) all over the place... not sure why.

hedgehog1029 avatar Jun 22 '23 19:06 hedgehog1029

I think this is because of a change I ended up reverting, here: https://invent.kde.org/network/kdeconnect-android/-/commit/e4743002be768261a4eab288326bcebf11a308aa

I just released 1.26.1 with this revert, let me know if it fixes the issue for you :)

albertvaka avatar Jun 24 '23 14:06 albertvaka

@albertvaka now I'm having to re-pair my machine upon mconnect (426.3991150-99) (re)start, sometimes multiple times in a row; as well as when the Android app (1.26.2) (re)starts.

But the present issue (infinite rewrites) is no longer present.

Edit: just noticed that bug report should probably have gone to https://github.com/grimpy/mconnect which is the upstream for https://aur.archlinux.org/packages/mconnect-git

moviuro avatar Jun 30 '23 21:06 moviuro

In the Play Store analytics I can see lots of crashes when the app is trying to restore a saved paired device. The errors seem to be because the certificate isn't properly stored. I wonder if the crashes are all coming from mconnect users for some reason specific to this implementation, or if they come from devices that have some particularity that I still don't know. If you could attach the Android logs after pairing and also after the error happens, hopefully we can find something interesting/useful there.

albertvaka avatar Jul 02 '23 20:07 albertvaka

I am also running into mconnect requesting pairing a lot of times when I unlock the Android phone. This happens in the few recent android app versions (1.26.x).

Is that an issue of the android app, or is mconnect simply not supporting some new changes of the android app?

xlucn avatar Jul 20 '23 04:07 xlucn

I'm the maintainer of the KDE Connect Android app. I'm not sure why this is happening to some users. It would be really useful if someone can send me the Android app logs to debug this, ideally from the latest version (1.27.x).

albertvaka avatar Jul 21 '23 15:07 albertvaka

I just released version 1.27.1, which might (maybe, hopefully) fix the issue with having to pair the devices again and again. Let me know if it works.

albertvaka avatar Jul 29 '23 10:07 albertvaka