MTP looping between start and stopping causing constant ~10% cpu load

[Andrew Hayzen]

When unplugged from USB, I notice when running $ top that init, dbus-daemon, mpdecision are constantly using in total ~10% CPU.

The steps I have performed to cause this:
1) Ensure the device is off
2) Plug a USB cable into the device and a computer with MTP support
3) Boot the device
4) Unlock the device, run the terminal and the command $ top
5) Wait until the CPU settles, then unplug the USB cable
6) Now notice that init, dbus-daemon, mpdecision start using ~10% CPU

This is the output from running dbus-monitor [0]

Note that when I plugged my device into a PC the CPU usage reduced back to normal, but then when I unplugged it again it increased back to ~10% again.

0 - http://pastebin.ubuntu.com/9734788/

$ system-image-cli -i
current build number: 161
device name: mako
channel: ubuntu-touch/ubuntu-rtm/devel-proposed
alias: ubuntu-touch/ubuntu-rtm/14.09-proposed
last update: 2015-01-13 18:37:40
version version: 161
version ubuntu: 20150113
version device: 20141119
version custom: mako-1.1

[Andrew Hayzen (ahayzen)]

Note my PC is running utopic with the following mtp version

$ lsb_release -rd
Description: Ubuntu 14.10
Release: 14.10

$ uname -a
Linux andy-Pangolin-Performance 3.19.0-031900rc4-generic #201501112135 SMP Sun Jan 11 21:36:48 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

$ apt-cache policy libmtp9
libmtp9:
  Installed: 1.1.6-20-g1b9f164-1ubuntu5
  Candidate: 1.1.6-20-g1b9f164-1ubuntu5
  Version table:
 *** 1.1.6-20-g1b9f164-1ubuntu5 0
        500 http://gb.archive.ubuntu.com/ubuntu/ utopic/main amd64 Packages
        100 /var/lib/dpkg/status

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Ricardo Salveti (rsalveti)]

Able to confirm the issue with latest vivid on mako:

phablet@ubuntu-phablet:~$ system-image-cli -i
current build number: 65
device name: mako
channel: ubuntu-touch/vivid-proposed
last update: 2015-01-14 20:03:32
version version: 65
version ubuntu: 20150114.1
version device: 20141213
version custom: 20150114.1

phablet@ubuntu-phablet:~$ dpkg -l | grep mtp-server
ii mtp-server 0.0.4+15.04.20141113-0ubuntu1 armhf Small server implementation of MTP.

[Ricardo Salveti (rsalveti)]

There was a crash and then mtp-server restarting in loop, which caused it to show on top:
phablet@ubuntu-phablet:~$ cat ./.cache/upstart/mtp-server.log
I0114 20:04:11.081110 2914 server.cpp:419] MTP server starting...
E0114 20:04:11.103268 2914 server.cpp:440] Could not start the MTP server:org.freedesktop.DBus.Error.ServiceUnknown: The name com.canonical.UnityGreeter was not provided by any .service files
I0114 20:04:21.545111 3012 server.cpp:419] MTP server starting...
E0114 20:04:21.571146 3012 server.cpp:440] Could not start the MTP server:org.freedesktop.DBus.Error.ServiceUnknown: The name com.canonical.UnityGreeter was not provided by any .service files
I0114 20:04:32.033162 3334 server.cpp:419] MTP server starting...
E0114 20:55:23.626266 3334 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 20:55:27.263805 5108 server.cpp:419] MTP server starting...
I0114 20:56:21.600800 3143 server.cpp:419] MTP server starting...
E0114 21:02:16.476572 3143 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:16.623710 4157 server.cpp:419] MTP server starting...
E0114 21:02:16.651300 4157 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:17.229143 4175 server.cpp:419] MTP server starting...
E0114 21:02:17.250813 4175 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:17.651392 4196 server.cpp:419] MTP server starting...
E0114 21:02:17.668025 4196 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:17.769384 4212 server.cpp:419] MTP server starting...
E0114 21:02:17.790657 4212 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:18.251240 4226 server.cpp:419] MTP server starting...
E0114 21:02:18.267659 4226 MtpServer.cpp:174] request read returned -1: Input/output error [5]
*** Error in `/usr/bin/mtp-server': double free or corruption (!prev): 0x01d78008 ***
I0114 21:02:21.462715 4249 server.cpp:419] MTP server starting...
E0114 21:02:21.476754 4249 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:21.872237 4259 server.cpp:419] MTP server starting...
E0114 21:02:21.888077 4259 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:22.478128 4276 server.cpp:419] MTP server starting...
E0114 21:02:22.494457 4276 MtpServer.cpp:174] request read returned -1: Input/output error [5]
I0114 21:02:22.977716 4292 server.cpp:419] MTP server starting...

[Ricardo Salveti (rsalveti)]

Backtrace I got:
(gdb) bt full
#0 __libc_do_syscall () at ../ports/sysdeps/unix/sysv/linux/arm/libc-do-syscall.S:44
No locals.
#1 0xb6c77e5e in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
        _a1 = 0
        _a3tmp = 6
        _a1tmp = 0
        _a3 = 6
        _nametmp = 268
        _a2tmp = 4227
        _a2 = 4227
        _name = 268
        _sys_result = <optimized out>
        pd = 0xb6731450
        pid = 0
        selftid = 4227
#2 0xb6c78b4e in __GI_abort () at abort.c:89
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0 <repeats 32 times>}}, sa_flags = 0, sa_restorer = 0xb6730c98}
        sigs = {__val = {32, 0 <repeats 31 times>}}
#3 0xb6ca13f8 in __libc_message (do_abort=<optimized out>, fmt=0xb6d1f638 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
        ap = {__ap = 0xb6730ce4}
        fd = 2
        on_2 = <optimized out>
        list = <optimized out>
        nlist = <optimized out>
        cp = <optimized out>
        written = <optimized out>
#4 0xb6ca5296 in malloc_printerr (action=1, str=0xb6d1f76c "double free or corruption (!prev)", ptr=<optimized out>) at malloc.c:4996
        buf = "01d78008"
        cp = <optimized out>
#5 0xb6ca5d76 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3840
        size = <optimized out>
        fb = <optimized out>
        nextchunk = <optimized out>
        nextsize = <optimized out>
        nextinuse = <optimized out>
        prevsize = <optimized out>
        bck = <optimized out>
        fwd = <optimized out>
        errstr = <optimized out>
        locked = <optimized out>
        __func__ = "_int_free"
#6 0x0003a652 in deallocate (this=0x1d7f6a8, __p=<optimized out>) at /usr/include/c++/4.9/ext/new_allocator.h:110
No locals.
#7 deallocate (__a=..., __n=<optimized out>, __p=<optimized out>) at /usr/include/c++/4.9/bits/alloc_traits.h:383
No locals.
#8 _M_deallocate (this=0x1d7f6a8, __n=<optimized out>, __p=<optimized out>) at /usr/include/c++/4.9/bits/stl_vector.h:178
No locals.
#9 std::vector<char, std::allocator<char> >::_M_default_append (this=this@entry=0x1d7f6a8, __n=__n@entry=896) at /usr/include/c++/4.9/bits/vector.tcc:578
        __new_start = 0xb3c00468 "\350\235\327\001 \233\327\001"
        __new_finish = 0xb3c00868 ""
#10 0x0004657e in _M_default_append (__n=896, this=0x1d7f6a8) at /usr/include/c++/4.9/bits/vector.tcc:545
No locals.
#11 resize (__new_size=<optimized out>, this=0x1d7f6a8) at /usr/include/c++/4.9/bits/stl_vector.h:676
No locals.
#12 boost::asio::basic_streambuf<std::allocator<char> >::reserve (this=this@entry=0x1d7f684, n=n@entry=1024) at /usr/include/boost/asio/basic_streambuf.hpp:325
        gnext = <optimized out>
        pnext = 0
        pend = 1024
#13 0x00049570 in prepare (n=1024, this=0x1d7f684) at /usr/include/boost/asio/basic_streambuf.hpp:207
No locals.
#14 MtpDaemon::read_more_notify (this=0x1d7f628) at /build/buildd/mtp-0.0.4+15.04.20141113/server/server.cpp:191
        __PRETTY_FUNCTION__ = "void MtpDaemon::read_more_notify()"
#15 0xb6f035de in ?? () from /usr/lib/arm-linu...

[Ricardo Salveti (rsalveti)]

This is killing my battery on mako, as there is no respawn limit, it keeps opening and closing mtp (as it always gets Input/output error).

[Mathieu Trudel-Lapierre (cyphermox)]

The fix for this is now in RTM:

mtp (0.0.4+15.04.20150120~rtm-0ubuntu1) 14.09; urgency=low

  [ Mathieu Trudel-Lapierre ]
  * Adjust start and stop conditions to properly handle USB connection
    *and* disconnection, and to do the right thing at boot-time if USB
    is connected already.

Closing as Fix Released.