GNOME Bugzilla – Bug 770916
When Amazon Fire Tablet HDX 8.9 is plugged into the USB port the daemon is writing information to syslog every 15 minutes
Last modified: 2016-09-14 14:08:34 UTC
Created attachment 334858 [details] Output to syslog when Amazon Fire tablet is connected via USB to desktop Every 15 minutes when I have my Amazon Fire HDX 8.9 tablet plugged into the desktop via a USB port the information in the attachment is written to syslog. This is on a Ubuntu 16.04.1LTS system that was upgraded for 14.04.4LTS on 4 August. The same day as the upgrade was done is when this started happening. Some useful, I hope, information: chris@localhost:~$ apt-cache policy gvfs gvfs: Installed: 1.28.2-1ubuntu1~16.04.1 Candidate: 1.28.2-1ubuntu1~16.04.1 Version table: *** 1.28.2-1ubuntu1~16.04.1 500 500 http://us.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages 100 /var/lib/dpkg/status 1.28.1-1ubuntu1 500 500 http://us.archive.ubuntu.com/ubuntu xenial/main amd64 Packages chris@localhost:~$ apt-cache policy gnome gnome: Installed: (none) Candidate: 1:3.14+3ubuntu1 Version table: 1:3.14+3ubuntu1 500 500 http://us.archive.ubuntu.com/ubuntu xenial/universe amd64 Packages chris@localhost:~$ lsb_release -crid Distributor ID: Ubuntu Description: Ubuntu 16.04.1 LTS Release: 16.04 Codename: xenial chris@localhost:~$ uname -a Linux localhost 4.4.0-36-generic #55-Ubuntu SMP Thu Aug 11 18:01:55 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux I've been asked by the Ubuntu folks to report this as an 'upstream' bug. I've already reported it there as bug https://bugs.launchpad.net/ubuntu/+source/gvfs/+bug/1613802 Please advise if I can provide any additional information. Prior to the upgrade when running Ubuntu 14.04LTS this was not an issue. I believe my Gnome version at the time was 3.12*.
seems gvfs is quite verbose in debug informations and those end up in syslog since systemd is in use
Thanks for your bug report. This debug prints comes from MTP backend, however it should be silent by default (if GVFS_DEBUG, or --debug is not set). Or it might be printed by libmtp without our awareness. I will check... Sebastian, do you see more debug info from GVfs even if debugging is disabled?
Maybe it is worth to mention that patches porting GVfs to use g_debug have been already pushed (so nothing should be printed to stdout by default), see Bug 740660. But those patches are already part of 1.28.x...
Ah, yes, I can see it. It is probably caused by the mtp_heartbeat function, which is called each 15 minut to avoid unmounting the device... https://git.gnome.org/browse/gvfs/tree/daemon/gvfsbackendmtp.c#n813 We have to use something else instead...
Philip, what would be good alternative for it? LIBMTP_Get_Friendlyname? LIBMTP_Check_Capability?
(In reply to Ondrej Holy from comment #5) > Philip, what would be good alternative for it? > LIBMTP_Get_Friendlyname? > LIBMTP_Check_Capability? Or modify libmtp and make it quiet.
I'd like to add an additional note that this does not occur whenever I plug in my Samsung Galaxy S4 phone to the same USB port though I do see, in my opinion, a couple of odd gvfs notations to syslog: Sep 6 08:22:59 localhost kernel: [347327.592018] usb 2-1: new high-speed USB device number 15 using ehci-pci Sep 6 08:22:59 localhost kernel: [347327.725002] usb 2-1: New USB device found, idVendor=04e8, idProduct=6865 Sep 6 08:22:59 localhost kernel: [347327.725007] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Sep 6 08:22:59 localhost kernel: [347327.725010] usb 2-1: Product: SAMSUNG_Android Sep 6 08:22:59 localhost kernel: [347327.725013] usb 2-1: Manufacturer: SAMSUNG Sep 6 08:22:59 localhost mtp-probe: checking bus 2, device 15: "/sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1" Sep 6 08:22:59 localhost kernel: [347327.725015] usb 2-1: SerialNumber: 0b492907 Sep 6 08:22:59 localhost mtp-probe: bus: 2, device: 15 was not an MTP device Sep 6 08:23:00 localhost /usr/lib/snapd/snapd[2129]: daemon.go:160: DEBUG: uid=0;@ POST /v2/snaps 825.752288ms 202 Sep 6 08:23:00 localhost org.gtk.vfs.GPhoto2VolumeMonitor[5385]: (process:5678): GVFS-GPhoto2-WARNING **: device (null) has no BUSNUM property, ignoring Sep 6 08:23:00 localhost snap[14507]: #015#033[K Sep 6 08:23:00 localhost snap[14507]: All snaps up-to-date. Sep 6 08:23:00 localhost systemd[1]: Started Automatically refresh installed snaps. Sep 6 08:23:00 localhost systemd[1]: snapd.refresh.timer: Adding 4h 59min 52.343266s random time. Sep 6 08:23:00 localhost systemd[1]: snapd.refresh.timer: Adding 2h 54min 35.538332s random time. Sep 6 08:23:00 localhost org.gtk.vfs.Daemon[5385]: PTP: reading event an error 0x02ff occurred Sep 6 08:23:00 localhost org.gtk.vfs.Daemon[5385]: ** (gvfsd:5483): WARNING **: dbus_mount_reply: Error from org.gtk.vfs.Mountable.mount(): Error initializing camera: -53: Could not claim the USB device Sep 6 08:23:00 localhost org.gtk.vfs.Daemon[5385]: (process:6031): GLib-GObject-CRITICAL **: g_object_unref: assertion 'G_IS_OBJECT (object)' failed Sep 6 08:23:00 localhost org.gtk.vfs.Daemon[5385]: message repeated 2 times: [ (process:6031): GLib-GObject-CRITICAL **: g_object_unref: assertion 'G_IS_OBJECT (object)' failed]
So, I agree we need to change it if it's dumping the entire device info into syslog every time. The main trick here was the call needs to actually go out to the device and do stuff. Some simple calls end up returning info cached by libmtp - and I'm not sure what Get_Friendlyname or Check_Capability will do. Would need to investigate. It's also worth seeing what behaviour without the heartbeat is like these days. It was something I added very early on and Android's come a long way since then. I'll take a look.
Created attachment 335010 [details] [review] Use a less spammy function for the heartbeat Friendlyname seems a reasonable choice - it does a property-get so it should be talking to the device.
Review of attachment 335010 [details] [review]: Looks good to me, but it is not maybe no longer needed. My Nexus works correctly after one hour without any activity, but who knows...
Comment on attachment 335010 [details] [review] Use a less spammy function for the heartbeat I marked the patch as "commit_after_freeze" initially, but the hard code freeze begins today, so I've pushed it as commit 47b10c6...
Thanks. I'd have missed that.
Question, will this be an update to gvfs on the Gnome version I'm running or will it only be on the next Gnome version?
I've pushed the patch in master only, so it will be part only the next GNOME version (1.30.x). I don't think this is something crucial what needs to be fixed in stable branches...
Thank you, and I agree it's not critical just a nuisance.