ubuntu one client takes too long to start

[Scott James Remnant (Canonical)]

Binary package hint: ubuntuone-client

The UbuntuOne client takes an unbelievable amount of time to start, consuming all CPU and I/O resource.

Since this is installed and run by default, this directly conflicts with our attempts to improve boot performance.

[Scott James Remnant (Canonical) (canonical-scott)]

Attached an example boot chart, in this one the daemon is taking 15s

[Scott James Remnant (Canonical) (canonical-scott)]

Cc'ing Release Team.

I would like this considered Release Critical. Either ubuntu one's performance problems should be fixed, or it should be removed from the default set.

[Scott James Remnant (Canonical) (canonical-scott)]

Oops, wrong chart. That was jaunty - although this proper one neatly demonstrates that ubuntu one's client has undone *ALL* of our performance work so far in the karmic cycle!

[Martin Pitt (pitti)]

Since file sync isn't enabled by default, it shouldn't do anything by default (not start the python process with the panel icon, start the sync daemon, etc.).

Also, the autostart .desktop file should push out the sync daemon start by a minute or so, to not get in the way of session start.

[Elliot Murphy (statik)]

Hi Rodney, it would be great to get this into alpha3. If that's not possible, please bump to w15. The changes Martin described seem good.

[dobey (dobey)]

We can't simply create an autostart file and delay start-up of ubuntuone-syncdaemon. It will still be started before autorstart attempts to run it if we do, as the nautilus extension makes DBus calls to it, so that it can know which folder is the Ubuntu One folder, if there are any current transfers, and what the connection state is. The problem is that the syncdaemon is doing things it shouldn't be doing at this time, as well as doing some of them ineffeciently.

[Martin Pitt (pitti)]

How is the "u1 sync enabled" configuration switch stored? If it's
gconf, the autostart .desktop file could at least use an
AutostartCondition: to prevent startup in the default case?

That won't help the people who do have it enabled, but at least it
would give a better first impression.

[dobey (dobey)]

There is no stored configuration for 'is sync enabled' really. We don't really do anything until the user has authorized the computer to access their data, and then we store the OAuth token in the keyring, and the applet adds itself to autostart, and adds a bookmark for the Ubuntu One folder. I just tried to test this on Karmic, using the 0.90.4+r88 package from our PPA, which is a bit newer than what's currently in Karmic. With or without it installed, and not authorized, I couldn't perceive any real difference in start up time. Even with it authorized, and all the files already synced (it seemed to do so pretty quickly), I couldn't perceive any real start up time issues. But I don't have a lot of files stored in Ubuntu One, and nothing really large either.

I don't know if this is true for the version that's in Karmic right now though. There have been a lot of bug fixes since that release. i've filed bugs last week to get 0.90.4 packages in Karmic, and will be releasing 0.91.0 tomorrow, to be included in the Alpha this week. Of course, I'm not a core dev, and don't have upload rights, so I have to depend on someone else getting the packages built and uploaded. I will be updating the source package branch we use with the new version though.

[Guillermo Gonzalez (verterok)]

Hi,

Scott, it's possible to get the syncdaemon logs? (~/.cache/ubuntuone/log)
Is this on a clean system/fresh install?

As Rodney pointed out, the current startup time isn't much. In my mahcine (macbook Core 2 Duo 2.0GHz, 2GB RAM) is ~2s. I have a fix that improves things a bit, in the same machine it goes down to ~0.3s

Thanks a lot.

Regards,

[Scott James Remnant (Canonical) (canonical-scott)]

Absolutely, I'll attach the logs presently.

This is a clean system and fresh install, on the machine we use for boot performance testing. It's a Dell Mini 10v: Intel Atom N270, 1GB RAM (HDD model). As you can see from the bootchart I attached, the startup time is 13s not ~2s.

(Even if it were ~2s, that is unacceptable - our target for the entire boot is 10s, with only 4s allocated to desktop login).

[Scott James Remnant (Canonical) (canonical-scott)]

All of the logs attached above. I believe the log corresponding to that bootchart would be:

syncdaemon.log.2009-07-17_16-32-33 (3.5 KiB, text/plain)

but all of the charts show the same performance problems

[Scott James Remnant (Canonical) (canonical-scott)]

Actually, it might be syncdaemon.log.2009-07-17_16-35-13 (3.5 KiB, text/plain)

(assuming your times are stop time not start time <g>)

[Martin Pitt (pitti)]

Please note that in a default install, there should be no sync daemon
process and logs _at all_. This is already a bug.

[Guillermo Gonzalez (verterok)]

Scott, thanks for the logs :)

The actual startup of the syncdaemon is taking ~5s, see the inline comments:

>2009-07-17 16:29:08,672 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
>2009-07-17 16:29:08,849 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 1, idx_node_id: 0, shares: 1

Most of the startup time is in this step: (~4s):

>2009-07-17 16:29:08,862 - ubuntuone.SyncDaemon.HQ - INFO - HashQueue: _hasher started
>2009-07-17 16:29:12,873 - ubuntuone.SyncDaemon.DBus - DEBUG - using the real system bus

I have a branch, that's going to be proposed today, that fix this and now the step above takes ~0.2s (would be nice to test this in a similar netbook)

>2009-07-17 16:29:12,885 - ubuntuone.SyncDaemon.Main - INFO - Using /home/ubuntu/Ubuntu One/My Files as root dir
>2009-07-17 16:29:12,885 - ubuntuone.SyncDaemon.Main - INFO - Using /home/ubuntu/.cache/ubuntuone/syncdaemon
.....
> 2009-07-17 16:29:12,958 - ubuntuone.SyncDaemon.EQ - DEBUG - push_event: SYS_STATE_CHANGED, args:(), kw:{'state': <SyncDaemonState READY_FOR_NETWORK>}

At this point the syncdaemon is fully initialized

> 2009-07-17 16:29:26,867 - ubuntuone.SyncDaemon.EQ - DEBUG - push_event: SYS_NET_CONNECTED, args:(), kw:{}
> 2009-07-17 16:29:26,868 - ubuntuone.SyncDaemon.State - DEBUG - READY_FOR_NETWORK --[SYS_NET_CONNECTED]--> READY_WITH_NETWORK
> 2009-07-17 16:29:26,868 - ubuntuone.SyncDaemon.EQ - DEBUG - push_event: SYS_STATE_CHANGED, args:(), kw:{'state': <SyncDaemonState READY_WITH_NETWORK>}

The last 3 logs are related to a dbus call to NetworkManager.

I'll take a look why this NetworkManager dbus call is taking so long.

Regards,

[Guillermo Gonzalez (verterok)]

Hi Martin,

> Please note that in a default install, there should be no sync daemon
> process and logs _at all_. This is already a bug.

Interesting.

So, syncdaemon is started by a dbus call issued by the nautilus extension. what do you think it's the way this should work?

We could check if there is a OAuth token available before starting syncdaemon to avoid starting it and also avoid creating the ~/Ubuntu One and ~/.cache/ubuntuone folders.

I don't know how this impact the current nautilus extension, Rodney?

Regards,

[Scott James Remnant (Canonical) (canonical-scott)]

On Tue, 2009-07-21 at 15:57 +0000, Guillermo Gonzalez wrote:

> The actual startup of the syncdaemon is taking ~5s, see the inline
> comments:
>
No.

The *actual* startup time of the syncdaemon is ~15s, see the bootchart.
During this entire period it is consuming large amounts of CPU and I/O.

Your logs are simply not logging what it's doing properly.

Scott
--
Scott James Remnant
<email address hidden>

[Martin Pitt (pitti)]

Guillermo Gonzalez [2009-07-21 16:02 -0000]:
> So, syncdaemon is started by a dbus call issued by the nautilus
> extension. what do you think it's the way this should work?

Oh, I thought Rodney said that enabling file sync would create an
autostart .desktop file for the panel applet, and the applet would
dbus-activate the sync daemon?

> We could check if there is a OAuth token available before starting
> syncdaemon to avoid starting it and also avoid creating the ~/Ubuntu
> One and ~/.cache/ubuntuone folders.

Well, from what I've heard, the panel applet/icon will go away soon.
You probably want to create ~/Ubuntu One, so that the user has
something to click on for enabling U1. Somehow it must be possible to
tell whether the user ever enabled U1? If that's through the oauth
token, that would make perfect sense.

Thank you!

[Launchpad Janitor (janitor)]

This bug was fixed in the package ubuntuone-client - 0.91.1-0ubuntu1

---------------
ubuntuone-client (0.91.1-0ubuntu1) karmic; urgency=low

  * New upstream release.
    - Fixes Nautilus crash on exit (LP: #403086)
    - Fixes Start-up time issues (LP: #400746)
    - Fixes AttributeError during metadata migration (LP: #404280)
    - Fixes IOError during OAuth authorization (LP: #402091)

ubuntuone-client (0.91.0-0ubuntu2) karmic; urgency=low

  * Only pull in python-gnome2-desktop if python-gnomekeyring isn't available
    - Fixes LP: #403245

 -- Rodney Dawes <email address hidden> Mon, 27 Jul 2009 16:00:00 -0400

[Scott James Remnant (Canonical) (canonical-scott)]

Looks like the daemon is not started for me anymore