After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
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
When Amazon Fire Tablet HDX 8.9 is plugged into the USB port the daemon is wr...
Status: RESOLVED FIXED
Product: gvfs
Classification: Core
Component: mtp backend
1.28.x
Other Linux
: Normal normal
: ---
Assigned To: Philip Langdale
gvfs-maint
Depends on:
Blocks:
 
 
Reported: 2016-09-05 21:46 UTC by Chris
Modified: 2016-09-14 14:08 UTC
See Also:
GNOME target: ---
GNOME version: 3.13/3.14


Attachments
Output to syslog when Amazon Fire tablet is connected via USB to desktop (148.33 KB, text/plain)
2016-09-05 21:46 UTC, Chris
  Details
Use a less spammy function for the heartbeat (1.01 KB, patch)
2016-09-07 16:30 UTC, Philip Langdale
committed Details | Review

Description Chris 2016-09-05 21:46:01 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*.
Comment 1 Sebastien Bacher 2016-09-06 07:57:34 UTC
seems gvfs is quite verbose in debug informations and those end up in syslog since systemd is in use
Comment 2 Ondrej Holy 2016-09-06 08:18:48 UTC
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?
Comment 3 Ondrej Holy 2016-09-06 08:36:48 UTC
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...
Comment 4 Ondrej Holy 2016-09-06 08:49:44 UTC
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...
Comment 5 Ondrej Holy 2016-09-06 09:03:59 UTC
Philip, what would be good alternative for it?
LIBMTP_Get_Friendlyname?
LIBMTP_Check_Capability?
Comment 6 Bastien Nocera 2016-09-06 09:18:14 UTC
(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.
Comment 7 Chris 2016-09-06 13:52:52 UTC
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]
Comment 8 Philip Langdale 2016-09-06 14:38:10 UTC
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.
Comment 9 Philip Langdale 2016-09-07 16:30:35 UTC
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.
Comment 10 Ondrej Holy 2016-09-08 12:31:27 UTC
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 11 Ondrej Holy 2016-09-12 12:33:36 UTC
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...
Comment 12 Philip Langdale 2016-09-13 04:39:19 UTC
Thanks. I'd have missed that.
Comment 13 Chris 2016-09-13 13:11:37 UTC
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?
Comment 14 Ondrej Holy 2016-09-14 08:12:14 UTC
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...
Comment 15 Chris 2016-09-14 14:08:34 UTC
Thank you, and I agree it's not critical just a nuisance.