GNOME Bugzilla – Bug 723040
UI frozen for about 20secs after connecting Nexus4 and switching it from PTP to MTP mode
Last modified: 2020-03-17 09:56:09 UTC
1. Launched banshee. 2. Connected nexus4 via USB. 3. Switched nexus from PTP to MTP. Expected results: Should show contents of device. If it takes a bit to load them, it should show a progress bar, and never block the UI. Current results: Frozen for 20 secs (banshee turned "grey color"), then suddenly this was written in the console: [1 Debug 19:07:34.434] Dap support extension loaded: Banshee.Dap.AppleDevice [1 Debug 19:07:34.435] Dap support extension loaded: Banshee.Dap.Mtp [1 Debug 19:07:34.447] Dap support extension loaded: Banshee.Dap.MassStorage [1 Warn 19:07:34.448] Failed to load media-player-info file for 1 [1 Debug 19:07:34.452] Delayed Initializating Banshee.Daap.DaapService [1 Debug 19:07:34.453] Delayed Initializating Banshee.Podcasting.PodcastService [9 Debug 19:07:34.605] Refreshing any podcasts that haven't been updated in over an hour Device 0 (VID=18d1 and PID=4ee1) is a Google Inc (for LG Electronics/Samsung) Nexus 4/10 (MTP). Unable to open ~/.mtpz-data for reading, MTPZ disabled.Android device detected, assigning default bug flags [1 Warn 19:07:34.721] Failed to load media-player-info file for 1 [1 Warn 19:07:34.725] Failed to load media-player-info file for 1 [13 Debug 19:07:35.940] DAAP Proxy listening for connections on port 8089 [7 Warn 19:07:56.325] Unable to get battery level from MTP device - Mtp.LibMtpException: Could not retrieve battery stats (in `Mtp') at Mtp.MtpDevice.GetBatteryLevel (Mtp.MtpDeviceHandle handle, System.UInt16& maxLevel, System.UInt16& currentLevel) [0x0001c] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/MtpDevice.cs:312 at Mtp.MtpDevice.get_BatteryLevel () [0x0000b] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/MtpDevice.cs:68 at Banshee.Dap.Mtp.MtpSource.DeviceInitialize (IDevice device) [0x00285] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Dap/Banshee.Dap.Mtp/Banshee.Dap.Mtp/MtpSource.cs:144 [7 Debug 19:07:56.325] Found DAP support (Banshee.Dap.Mtp.MtpSource) for device Nexus 4 and Uuid /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 [1 Debug 19:07:56.326] Unmapping DAP source (/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2) [7 Info 19:07:56.326] AppleDeviceSource is ignoring unmounted volume Lenovo_Recovery [7 Info 19:07:56.330] AppleDeviceSource is ignoring unmounted volume Windows8_OS [7 Info 19:07:56.333] AppleDeviceSource is ignoring unmounted volume Nexus 4 Device 0 (VID=18d1 and PID=4ee1) is a Google Inc (for LG Electronics/Samsung) Nexus 4/10 (MTP). ERROR: Could not close session! ignoring libusb_claim_interface() = -6PTP_ERROR_IO: failed to open session, trying again after resetting USB interface LIBMTP libusb: Attempt to reset device inep: usb_get_endpoint_status(): Resource temporarily unavailable outep: usb_get_endpoint_status(): Device or resource busy usb_clear_halt() on IN endpoint: Device or resource busy usb_clear_halt() on OUT endpoint: Device or resource busy usb_clear_halt() on INTERRUPT endpoint: Device or resource busy [15 Warn 19:07:56.504] Caught an exception - System.ObjectDisposedException: The object was used after being disposed. (in `mscorlib') at System.Runtime.InteropServices.SafeHandle.DangerousAddRef (System.Boolean& success) [0x00000] in <filename unknown>:0 at (wrapper managed-to-native) Mtp.Track:LIBMTP_Get_Tracklisting_With_Callback (Mtp.MtpDeviceHandle,Mtp.ProgressFunction,intptr) at Mtp.Track.GetTrackListing (Mtp.MtpDeviceHandle handle, Mtp.ProgressFunction function, IntPtr data) [0x00004] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/Track.cs:212 at Mtp.MtpDevice.GetAllTracks (Mtp.ProgressFunction callback) [0x00001] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/MtpDevice.cs:193 at Banshee.Dap.Mtp.MtpSource.LoadFromDevice () [0x00033] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Dap/Banshee.Dap.Mtp/Banshee.Dap.Mtp/MtpSource.cs:156 [1 Debug 19:07:56.512] Finished - Startup Job [1 Debug 19:07:56.518] Starting - Downloading Cover Art [16 Debug 19:07:56.520] Finished - Downloading Cover Art Android device detected, assigning default bug flags [1 Debug 19:07:56.649] Creating Pango.Layout, configuring Cairo.Context [1 Debug 19:07:56.689] Creating Pango.Layout, configuring Cairo.Context [1 Warn 19:07:56.690] Buggy CSS theme: same background-color for .cell:selected and .cell [1 Debug 19:07:56.695] Creating Pango.Layout, configuring Cairo.Context [7 Warn 19:07:56.724] Unable to get battery level from MTP device - Mtp.LibMtpException: Could not retrieve battery stats (in `Mtp') at Mtp.MtpDevice.GetBatteryLevel (Mtp.MtpDeviceHandle handle, System.UInt16& maxLevel, System.UInt16& currentLevel) [0x0001c] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/MtpDevice.cs:312 at Mtp.MtpDevice.get_BatteryLevel () [0x0000b] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Libraries/Mtp/Mtp/MtpDevice.cs:68 at Banshee.Dap.Mtp.MtpSource.DeviceInitialize (IDevice device) [0x00285] in /home/knocte/Documents/Code/OpenSource/bansheeCLEANMANAGED/src/Dap/Banshee.Dap.Mtp/Banshee.Dap.Mtp/MtpSource.cs:144 [7 Debug 19:07:56.724] Found DAP support (Banshee.Dap.Mtp.MtpSource) for device Nexus 4 and Uuid /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 [7 Info 19:07:56.724] AppleDeviceSource is ignoring unmounted volume WINRE_DRV
Hey, have you managed to do any troubleshooting with the nexus4? It looks from the trace that libmtp might be failing to communicate with the device. Without having banshee running, are you able to get useful information from mtp-detect, or mtp-filetree? With the i9100, even though nautilus showed nothing I think I had to unmount the volume in the nautilus window before those commands worked.
Created attachment 267599 [details] [review] Stops banshee from attempting to unmount mtp devices I tried to reproduce the issue you were experiencing and I think I got pretty close. I could get it to either freeze for a short period (less than two seconds) or forever (until I unplugged the device or switched its mode back to PTP) I managed to get the latter case to occur fairly readily in the end, so hopefully we were seeing the same issue-the console log looks similar. This patch sorts out the problem for me, it appears to be related to attempting to unmount the device. With this applied, I was able to switch the device between modes with little/no disruption to banshee's UI, and on selecting MTP the device is detected and displayed after a short period. Again, banshee is still responsive during that process. There's a major caveat though, when plugging the device in with MTP mode, I have to switch to PTP, then back again for the device to show up. Banshee is already very well threaded with respect to device loading so I still can't put my finger on exactly _why_ the UI freeze occurs. Hope this helps, at least in working out what's going wrong.
Mm, I think that removing that is kind of risky. I've read in a lot of places how fucked up is the fact that gphoto "holds" a connection to the device and it needs to be unmounted. Perhaps you can start reading this: http://banshee-media-player.2283330.n4.nabble.com/Bonus-Banshee-Bit-for-Nov-4th-2011-So-your-MTP-device-isn-t-showing-up-in-Banshee-td3991346.html (and go read especially the gphoto bug that is linked there... and that bug will lead you to another bug... etc etc all of them unresolved bugs...). So this is kind of a bumpy road... On top of that, I think that maybe we shouldn't try to fix bugs in older systems that may happen to be system bugs (or MTP bugs). For example, I read this today: https://mail.gnome.org/archives/rhythmbox-devel/2014-January/msg00001.html which links to a PPA which says "13.10 (Saucy) and newer versions of Ubuntu contain all of these changes, so you don't need to use this ppa any more". So this leads me to think that I should upgrade my Ubuntu first of all. What version are you using BTW?
(Forgot to say: I'm on Ubuntu 13.04)
libgphoto2 - 2.5.2-r1 libmtp - 1.1.6 I think I read some similar reports when I was using a creative zen xtra quite a while ago now. That said, I can switch readily between the two modes with the patch applied, it's just the initial connection that doesn't work in MTP mode for me now. I was hoping to see whether the patch has the same effect on your side. I'm not proposing this as a fix, but perhaps it'll get us some useful information about the issue.
Ok I'll test it. So what distro and version are you on?
I'm on gentoo, there's not really a version ;)
Managed to reproduce this again, and I was fast enough to use kill -s QUIT <pidofbanshee>, and I got this for the main thread: "Main Thread" tid=0x0x2ae90af93500 this=0x0x2ae90b084010 thread handle 0x403 state : waiting on 0x689 : Sem owns () at <unknown> <0xffffffff> at (wrapper managed-to-native) System.Threading.Monitor.try_enter_with_atomic_var (object,int,bool&) <IL 0x0000f, 0xffffffff> at System.Threading.Monitor.TryEnter (object,int,bool&) <IL 0x00044, 0x0005f> at System.Threading.Monitor.Enter (object,bool&) <IL 0x00003, 0x0003b> at (wrapper unknown) System.Threading.Monitor.FastMonitorEnterV4 (object,bool&) <IL 0x00059, 0xffffffff> at Banshee.Dap.DapService.UnmapDevice (string) [0x0000e] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Dap/Banshee.Dap/Banshee.Dap/DapService.cs:258 at Banshee.Dap.DapService.OnHardwareDeviceRemoved (object,Banshee.Hardware.DeviceRemovedArgs) [0x00008] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Dap/Banshee.Dap/Banshee.Dap/DapService.cs:293 at (wrapper delegate-invoke) <Module>.invoke_void__this___object_DeviceRemovedArgs (object,Banshee.Hardware.DeviceRemovedArgs) <IL 0x00059, 0xffffffff> at Banshee.Hardware.HardwareManager.OnDeviceRemoved (object,Banshee.Hardware.DeviceRemovedArgs) [0x0001f] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Core/Banshee.Services/Banshee.Hardware/HardwareManager.cs:194 at Banshee.Hardware.Gio.HardwareManager.HandleManagerDeviceRemoved (object,Banshee.Hardware.Gio.MountArgs) [0x00024] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Backends/Banshee.Gio/Banshee.Hardware.Gio/HardwareManager.cs:60 at Banshee.Hardware.Gio.Manager.VolumeRemoved (GLib.IVolume) [0x00069] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Backends/Banshee.Gio/Banshee.Hardware.Gio/LowLevel/Manager.cs:128 at Banshee.Hardware.Gio.Manager.HandleMonitorMountRemoved (object,GLib.MountRemovedArgs) [0x0002c] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Backends/Banshee.Gio/Banshee.Hardware.Gio/LowLevel/Manager.cs:100 at (wrapper runtime-invoke) <Module>.runtime_invoke_void__this___object_object (object,intptr,intptr,intptr) <IL 0x0005c, 0xffffffff> at <unknown> <0xffffffff> at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke (System.Reflection.MonoMethod,object,object[],System.Exception&) <IL 0x0001c, 0xffffffff> at System.Reflection.MonoMethod.Invoke (object,System.Reflection.BindingFlags,System.Reflection.Binder,object[],System.Globalization.CultureInfo) <IL 0x0005a, 0x000e3> at System.Reflection.MethodBase.Invoke (object,object[]) <IL 0x00006, 0x00043> at System.Delegate.DynamicInvokeImpl (object[]) <IL 0x000dc, 0x0020b> at System.MulticastDelegate.DynamicInvokeImpl (object[]) <IL 0x0001a, 0x00047> at System.Delegate.DynamicInvoke (object[]) <IL 0x00002, 0x00033> at GLib.Signal.ClosureInvokedCB (object,GLib.ClosureInvokedArgs) [0x00039] in /home/knocte/Documents/Code/OpenSource/gtk-sharp/glib/Signal.cs:200 at GLib.SignalClosure.Invoke (GLib.ClosureInvokedArgs) [0x00019] in /home/knocte/Documents/Code/OpenSource/gtk-sharp/glib/SignalClosure.cs:126 at GLib.SignalClosure.MarshalCallback (intptr,intptr,uint,intptr,intptr,intptr) [0x0014c] in /home/knocte/Documents/Code/OpenSource/gtk-sharp/glib/SignalClosure.cs:167 at (wrapper native-to-managed) GLib.SignalClosure.MarshalCallback (intptr,intptr,uint,intptr,intptr,intptr) <IL 0x00028, 0xffffffff> at <unknown> <0xffffffff> at (wrapper managed-to-native) Gtk.Application.gtk_main () <IL 0x0000e, 0xffffffff> at Gtk.Application.Run () [0x00001] in /home/knocte/Documents/Code/OpenSource/gtk-sharp/gtk/Application.cs:133 at Banshee.Gui.GtkBaseClient.Run () [0x00019] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Core/Banshee.ThickClient/Banshee.Gui/GtkBaseClient.cs:225 at Banshee.Gui.GtkBaseClient.Startup () [0x00010] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Core/Banshee.ThickClient/Banshee.Gui/GtkBaseClient.cs:79 at Hyena.Gui.CleanRoomStartup.Startup (Hyena.Gui.CleanRoomStartup/StartupInvocationHandler) [0x00050] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Hyena/Hyena.Gui/Hyena.Gui/CleanRoomStartup.cs:54 at Banshee.Gui.GtkBaseClient.Startup<T> () [0x00049] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Core/Banshee.ThickClient/Banshee.Gui/GtkBaseClient.cs:74 at Banshee.Gui.GtkBaseClient.Startup<T> (string[]) [0x00021] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Core/Banshee.ThickClient/Banshee.Gui/GtkBaseClient.cs:64 at Nereid.Client.Main (string[]) [0x00002] in /home/knocte/Documents/Code/OpenSource/banshee3NATIVE/src/Clients/Nereid/Nereid/Client.cs:54 at (wrapper runtime-invoke) <Module>.runtime_invoke_void_object (object,intptr,intptr,intptr) <IL 0x00050, 0xffffffff> So I guess the problem is that there is some MTP operation that is taking a long time and which is holding the lock that the main thread is trying to enter. We should probably launch a worker thread to unmap the device instead.
Created attachment 267855 [details] [review] Push the Unmap device call to the Scheduler as an IJob Threaded like so? Very astute, initial tests for me have my device and banshee playing together nicely even with automount enabled, banshee gracefully unmounts the device. I'm running with the patch I sent to you by email applied, but i'm pretty sure with nautilus' automount behaviour this should Just Work without even without that.
Isn't it simpler to just us ThreadAssist.SpawnFromMain()? What would a job class offer as an advantage?
Perhaps, but I thought mirroring the Map operation which uses a job class would be easier to maintain later, and passing that through the scheduler would ensure that "Happens Before/After" relationships are respected.
(In reply to comment #11) > Perhaps, but I thought mirroring the Map operation which uses a job class would What's the map operation? > be easier to maintain later, and passing that through the scheduler would > ensure that "Happens Before/After" relationships are respected. But we don't know why this call is so slow, the only thing we know is that it's kept waiting on the lock() statement, so wouldn't this fact mean that the scheduler would not matter here?
(In reply to comment #12) > (In reply to comment #11) > > Perhaps, but I thought mirroring the Map operation which uses a job class would > > What's the map operation? private void MapDevice (IDevice device) { Scheduler.Schedule (new MapDeviceJob (this, device)); } I figured that having the UnmapDevice method follow the same pattern would be easier for people following us. I'm not sure that ThreadAssist.SpawnFromMain(() => { }); can be called a pattern ;) > > be easier to maintain later, and passing that through the scheduler would > > ensure that "Happens Before/After" relationships are respected. > > But we don't know why this call is so slow, the only thing we know is that it's > kept waiting on the lock() statement, so wouldn't this fact mean that the > scheduler would not matter here? Ok, from the stack trace the semaphore we're waiting on is DapService.sync. A short analysis which I hope is about right: When we plug our devices in, we're running a MapDevice job, and during that job we cause an UnmapDevice to occur indirectly when we run the Unmount command to allow us to take control of the MTP volume. But since the MapDevice job is on a different thread, we can't acquire the lock in UnmapDevice so we have to wait for all 5 MtpDevice.Connect() attempts to fail before UnmapDevice can acquire the lock. You're probably right, in that the scheduler makes no difference with the current locking strategy. What I'm getting at here, is that if we use the scheduler then perhaps we can actually avoid the locks at a later date?
(In reply to comment #13) > (...) What I'm getting at here, is that if we use the > scheduler then perhaps we can actually avoid the locks at a later date? How? Can you elaborate on that?
(In reply to comment #14) > (In reply to comment #13) > > (...) What I'm getting at here, is that if we use the > > scheduler then perhaps we can actually avoid the locks at a later date? > > How? Can you elaborate on that? Looking at the Scheduler class, it's a priority queue of jobs which run consecutively, so if I do: IJob job1 = new IJob() { }, job2 = new IJob() { }; Scheduler.Schedule(job1); Scheduler.Schedule(job2); Then job1 will at least run before job2, which gives us the same relationship that the lock does and prevents both critical regions of code from running at the same time. I may be wrong, I haven't tried it.
Fedora 19 here: libmtp-1.1.6-0.fc19.i686 libgphoto2-2.5.2-1.fc19.i686 I just can't access to any content with Banshee in my N4 :-m
(In reply to comment #16) > I just can't access to any content with Banshee in my N4 :-m Ismael, please open a new bug for that, this one is about banshee getting frozen when connecting a Mtp device. (In reply to comment #15) > (In reply to comment #14) > > (In reply to comment #13) > > > (...) What I'm getting at here, is that if we use the > > > scheduler then perhaps we can actually avoid the locks at a later date? > > > > How? Can you elaborate on that? > > Looking at the Scheduler class, it's a priority queue of jobs which run > consecutively, so if I do... Fair enough. However, your fix is a bit more sophisticated than what I'm proposing, and with more sophistication comes more risk. So what I decided to do is fix this for now with ThreadAssist[1], then backport the fix to the stable branch (because a 2.6.2 release is imminent), and then some days later (without the rush of a release), I will get your patch merged into master. So I'll leave the bug open for now. [1] https://git.gnome.org/browse/banshee/commit/?id=b0e172f01374f807bf396b6a289e51f56f851e31
*** Bug 670915 has been marked as a duplicate of this bug. ***
Banshee is not under active development anymore and had its last code changes more than three years ago. Its codebase has been archived. Closing this report as WONTFIX as part of Bugzilla Housekeeping to reflect reality. Please feel free to reopen this ticket (or rather transfer the project to GNOME Gitlab, as GNOME Bugzilla is being shut down) if anyone takes the responsibility for active development again. See https://gitlab.gnome.org/Infrastructure/Infrastructure/issues/264 for more info.