NetworkManager is polling every 4 seconds on the Desktop looking for /var/lib/ofono

Bug #1289532 reported by Colin Ian King
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
network-manager (Ubuntu)
Fix Released
Critical
Mathieu Trudel-Lapierre

Bug Description

I was looking at what's sucking power on the Trusty desktop and found that NetworkManager is polling every 4 seconds adding an inotify watch on /var/lib/ofono (which does not exist on the desktop - isn't that a phone related component?).

Anyhow, strace on one of the threads of NetworkManager shows:

sudo strace -p 710
Process 710 attached
restart_syscall(<... resuming interrupted call ...>) = 0
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3996) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3995) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3995) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)

So:

1. The polling is rather heavy - every 4 seconds? Is that really necessary?
2. Surely we can avoid repeatedly adding a watch on a directory that does not exist. Are there better ways than doing this so frequently, especially because it does not seem relevant on my desktop install.

Anyhow, can this be investigated, it's one of the final big causes of wakeups on an idle desktop image.

Changed in network-manager-applet (Ubuntu):
importance: Undecided → High
Revision history for this message
Colin Ian King (colin-king) wrote :

I've got some stats to show how this is now one of the top wake-up offending processes on the desktop now:

http://ci.ubuntu.com/power/eventstat/image/3105/machine/1/task/NetworkManager/details/

Revision history for this message
Colin Ian King (colin-king) wrote :

So, I think this could be classed as a regression in Trusty.

Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

Confirmed; I will try to fix this with an upload today.

affects: network-manager-applet (Ubuntu) → network-manager (Ubuntu)
Changed in network-manager (Ubuntu):
assignee: nobody → Mathieu Trudel-Lapierre (mathieu-tl)
importance: High → Critical
status: New → Triaged
Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

I can't seem to reproduce this. I've tried with NetworkManager 0.9.8.8-0ubuntu5 with the /var/lib/ofono directory inexistent, with it created, with it created and with subdirectories...

I've also tried another version I was working on; can't see it there either...

And before testing all that I built NM with a patch to not try to bring up a g_file_monitor for that path if it doesn't exist; and that obviously also doesn't show the problem.

Is there any more you can add to this bug report, such as what version of NM is running at the time, and whether ofono is also installed and running (though I expect it's not, since you don't appear to have /var/lib/ofono).

Revision history for this message
Colin Ian King (colin-king) wrote :
Download full text (3.2 KiB)

With version of 0.9.8.8-0ubuntu5 I still see one of the threads doing:

inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3997) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3998) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3995) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3996) = 0 (Timeout)
inotify_add_watch(8, "/var/lib/ofono", IN_MODIFY|IN_ATTRIB|IN_CLOSE_WRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_ONLYDIR) = -1 ENOENT (No such file or directory)
poll([{fd=9, events=POLLIN}, {fd=8, events=POLLIN}], 2, 3996) = 0 (Timeout)

So a 0.25 Hz timeout and an inotify watch being added each time which seems redundant on the desktop.

This is on a cleanly installed machine as of last week so I'm confident that my laptop is relatively sane when it comes to installed packages.

To track this down I did:

sudo health-check -p NetworkManager

this showed up as:

System calls traced:
  PID Process Syscall Count Rate/Sec Total μSecs % Call Time
   949 NetworkManager recvmsg 211 3.5167 2520 0.0021
   949 NetworkManager sendmsg 108 1.8000 2044 0.0017
   949 NetworkManager poll 97 1.6167 53977531 45.3342
   949 NetworkManager write 77 1.2833 873 0.0007
   949 NetworkManager read 52 0.8667 606 0.0005
   949 NetworkManager restart_syscall 1 0.0167 5542655 4.6551
   952 NetworkManager rt_sigtimedwait 1 0.0167 0 0.0000
   959 NetworkManager inotify_add_watch 15 0.2500 301 0.0003
   959 NetworkManager poll 15 0.2500 56001456 47.0340
   959 NetworkManager restart_syscall 1 0.0167 3537933 2.9714
   963 NetworkManager restart_syscall 1 0.0167 0 0.0000
 Total 579 9.6500 119065919

and also:

Inotify watches added:
  PID Process Rate/Sec File
   959 NetworkManager 0.250 /...

Read more...

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package network-manager - 0.9.8.8-0ubuntu10

---------------
network-manager (0.9.8.8-0ubuntu10) utopic; urgency=medium

  * debian/patches/add_ofono_settings_support.patch:
    - don't create a monitor for /var/lib/ofono if the path doesn't exist.
      We'll get another chance to do it if oFono appears on the DBus bus.
      (LP: #1289532)
    - Sort the list of ofono connections before returning them.
  * debian/patches/add_ofono_support.patch:
    - Don't Online the modem, urfkill or telepathy-ofono will take care of it.
    - Further refine how we pick the "best" for mobile data for oFono: we only
      want to consider GSM-type connections, and should try to pick the last
      connection to get successfully activated, defaulting to the first context
      privisioned by oFono (if no connections were ever established).
  * debian/patches/ofono_mms_support.patch: deal with MMS by setting up a host
    route for the mobile data connection if the MessageProxy property is set in
    oFono. (LP: #1302037)
  * debian/patches/dont-check-secrets-for-ofono.patch: refreshed.
  * debian/patches/git_default_route_active_device_9820258.patch: keep the
    default gateway on the currently active device.
 -- Mathieu Trudel-Lapierre <email address hidden> Wed, 07 May 2014 09:41:26 -0400

Changed in network-manager (Ubuntu):
status: Triaged → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.