Metadata load is too slow

Reported by Martin Albisetti on 2009-09-25
84
This bug affects 15 people
Affects Status Importance Assigned to Milestone
Ubuntu One Client
High
Guillermo Gonzalez
ubuntuone-client (Ubuntu)
High
Unassigned

Bug Description

Metadata load takes a lot of time, specially if the user has a lot of files.

Martin Albisetti (beuno) wrote :
Martin Albisetti (beuno) wrote :
Martin Albisetti (beuno) wrote :

Actually, I think apport hasn't attached anything useful to debug the applet crash....

Changed in ubuntuone-client:
status: New → Triaged
tags: added: desktop+
Changed in ubuntuone-client:
assignee: nobody → Rodney Dawes (dobey)
Rodney Dawes (dobey) wrote :

2009-09-25 14:23:30,810 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
2009-09-25 14:30:17,435 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 3191, idx_node_id: 3191, shares: 7

^ Why is that a 7 minute difference?!

Rodney Dawes (dobey) wrote :

Reassigning to Guillermo to take a look at why there is a 7 minute gap to load the metadata.

Changed in ubuntuone-client:
assignee: Rodney Dawes (dobey) → Guillermo Gonzalez (verterok)
Guillermo Gonzalez (verterok) wrote :

Hi,

I talked with Martin via IRC, and he can't reproduce this.

I think the problem with the 7 minutes might be related to a very slow creation of the filesystem manager index.

Facundo, any ideas on what might be causing such delay?

Thanks.

Changed in ubuntuone-client:
assignee: Guillermo Gonzalez (verterok) → Facundo Batista (facundo)
Changed in ubuntuone-client:
importance: Undecided → Medium
summary: - Clicked on the icon to connect, boom
+ Need to profile metadata loading to see if it's too slow
tags: added: facundo-lucid
tags: added: chicharra-lucid-speed
removed: facundo-lucid
Roman Yepishev (rye) on 2009-12-05
tags: added: metadata-loading
tags: added: u1-lucid
tags: added: chicharra
tags: removed: u1-lucid

Hi All,

This bug is quite prevalent to me after I tried to backup my entire home folder to ubuntuone (with the help of Roman we could see that it was around 380000 files). Took about 3 hours to copy the data to the ubuntuone folder (don't know why local disc copies was so slow, ran at about 700KBs, disk is never that slow), seems to have taken about 8 hours to index and then takes another 8 hours each time the pc starts up to read the data. During that time the PC is practically unusable. CPU is fine (Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz) but the disk access is the problem. Firefox greys out, nautilus greys out, everything is just horribly slow. Iotop shows that that the disk is continuously running at about 400K/s read

Total DISK READ: 382.60 K/s | Total DISK WRITE: 0.00 B/s
  TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
11118 be/4 ruald 382.60 K/s 0.00 B/s 0.00 % 0.00 % python /usr/lib/ubuntuone-client/ubuntuone-syncdaemon

I have been trying to backup my entire home folder to u1 since i purchased 50GB of space bout 3 months so to get this working properly is quite a priority for me. Please let me know if you require any other info.

I logged a bug this morning re the client applet crashing while the syncd is still running, not knowing that reading the data is what it was still doing (https://bugs.launchpad.net/ubuntu/+source/ubuntuone-client/+bug/537138)

Might be some useful info in there as well.

Thanks

Roman Yepishev (rye) wrote :

Here's the info about syncdaemon startup from psypher:

2010-03-12 07:15:59,194 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
2010-03-12 07:54:56,636 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 195799, idx_node_id: 14082, shares: 1
2010-03-12 07:54:56,642 - ubuntuone.SyncDaemon.HQ - INFO - HashQueue: _hasher started
2010-03-12 07:54:57,239 - ubuntuone.SyncDaemon.DBus - INFO - DBusInterface initialized.
...
2010-03-12 07:54:57,241 - ubuntuone.SyncDaemon.Main - NOTE - Local rescan starting...
2010-03-12 07:54:57,241 - ubuntuone.SyncDaemon.local_rescan - INFO - start scan all shares
2010-03-12 08:05:48,303 - ubuntuone.SyncDaemon.Main - NOTE - ---- MARK (state: READING; queues: metadata: 0; content: 0; hash: 0, fsm-cache: hit=8 miss=587391) ----
...
2010-03-12 08:10:24,726 - ubuntuone.SyncDaemon.Main - NOTE - Local rescan finished!
2010-03-12 08:10:24,727 - ubuntuone.SyncDaemon.Main - INFO - hash queue empty. We are ready!

So it takes 39 minutes to load metadata and 15 minutes to rescan all local files.

Metadata loading _is_ slow.

Roman Yepishev (rye) wrote :

Another thing with metadata being stored as enormous amount of files is that we will be unable to use readahead(2) facility - too many files to cache, too small files and the gain of readahead in this case is close to zero. Having it all in one file might speed-up the syncdaemon startup, since ureadahead profiling might find out that we are loading such file on startup and cache it e.g. during/before gdm login.

Facundo Batista (facundo) wrote :

Discussed it, and this is what we will do:

- create benchmarks for this
- design a new structure that...
    - be really faster to build the index from it (that is what actually takes too long at the start)
    - don't be seriously slower than it is now when writing or reading a separate node

This structure will be a big file in the fileshelf path that will replace the actual dir with lot of small files.

Changed in ubuntuone-client:
status: Triaged → Confirmed
assignee: Facundo Batista (facundo) → Ubuntu One Foundations+ team (ubuntuone-foundations+)
tags: added: chicharra-maverick
removed: chicharra-lucid-speed
psypher (psypher246) wrote :

please could some more attention be given to this issue, it is are making this commercial product completely unusable in real world situations. I know as I have been trying to use it for 3 months now and it just doesn't work as expected. Considering canceling my account :(

summary: - Need to profile metadata loading to see if it's too slow
+ Metadata load is too slow
description: updated
tags: added: chicharra-natty
removed: chicharra-maverick
Changed in ubuntuone-client:
importance: Medium → High
Natalia Bidart (nataliabidart) wrote :

Some info from my current system in my laptop:

nessita@miro:~$ u1sdtool --list-folders | grep subscribed=True
4: id=2db262f5-a151-4c19-969c-bb5ced753c61 subscribed=True path=/home/nessita/Documents/tesis
5: id=0e0a3c0d-ddb8-4926-ad71-c33fd6079e6a subscribed=True path=/home/nessita/.purple/logs
8: id=9ea892f8-15fa-4201-bdbf-8de99fa5f588 subscribed=True path=/home/nessita/Public

nessita@miro:~$ find Ubuntu\ One/ Documents/tesis/ Public/ .purple/logs | wc -l
27074

* Every first time I start syncdaemon (in each boot), the metadata load doesn't finish and SD apparently crashes without leaving any trace. This means that the log file has nothing but:

2010-11-11 08:54:50,330 - ubuntuone.SyncDaemon.VM.MD - DEBUG - metadata version: 6
2010-11-11 08:54:50,385 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata

and syncdaemon is not working. So I run u1sdtool -s again, and the log file is rotates and the load metadata process restart, and I get something like this:

2010-11-11 09:04:12,049 - ubuntuone.SyncDaemon.VM.MD - DEBUG - metadata version: 6
2010-11-11 09:04:12,050 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
2010-11-11 09:06:05,100 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 19704, idx_node_id: 15127, shares: 12

So the second metadata load process finish because the first attempt cached most of the files in the disk cache. So the second attempt takes 2 minutes when most of the files are already in the disk cache! So this amount of time is extremely large.

Natalia Bidart (nataliabidart) wrote :

Starting syncdaemon with:

/usr/lib/ubuntuone-client/ubuntuone-syncdaemon --logging-level=DEBUG

will complete the metadata load in the first attempt. In this case, it took:

2010-11-11 13:07:56,933 - ubuntuone.SyncDaemon.VM.MD - DEBUG - metadata version: 6
2010-11-11 13:07:57,021 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
2010-11-11 13:12:45,864 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 19704, idx_node_id: 16948, shares: 12

Almost 5 minutes of intensive disk usage (which makes the rest of the desktop pretty unusable due to IO starvation).

Natalia Bidart (nataliabidart) wrote :

I separated from this bug the problem of sycdaemon silently crashing on bug #683116

Changed in ubuntuone-client (Ubuntu):
status: New → Triaged
importance: Undecided → High
Changed in ubuntuone-client:
assignee: Ubuntu One Foundations+ team (ubuntuone-foundations+) → Guillermo Gonzalez (verterok)
status: Confirmed → Fix Committed
Guillermo Gonzalez (verterok) wrote :

This is now fixed in trunk,

according to Martin logs:

2011-01-10 12:17:48,642 - ubuntuone.SyncDaemon.tritcask - INFO - Initializing Tritcask on: /home/beuno/.local/share/ubuntuone/syncdaemon/tritcask
2011-01-10 12:17:48,644 - ubuntuone.SyncDaemon.tritcask - DEBUG - lookingup data files
2011-01-10 12:17:48,645 - ubuntuone.SyncDaemon.tritcask - INFO - found 1 data files and 0 dead files
2011-01-10 12:17:48,645 - ubuntuone.SyncDaemon.tritcask - DEBUG - building the keydir, using: ['129450510717705']
2011-01-10 12:17:48,646 - ubuntuone.SyncDaemon.tritcask - DEBUG - loading entries from (build_hint=False): /home/beuno/.local/share/ubuntuone/syncdaemon/tritcask/129450510717705.live.tritcask-v1.data
2011-01-10 12:17:48,720 - ubuntuone.SyncDaemon.tritcask - INFO - keydir ready! (keys: 2264)
2011-01-10 12:17:48,721 - ubuntuone.SyncDaemon.VM.MD - DEBUG - metadata version: 7
2011-01-10 12:17:48,725 - ubuntuone.SyncDaemon.fsm - INFO - loading updated metadata
2011-01-10 12:17:48,854 - ubuntuone.SyncDaemon.fsm - INFO - initialized: idx_path: 2247, idx_node_id: 2247, shares: 15

I takes less than a second to load the metadata and build the indexes.

Rodney Dawes (dobey) on 2011-01-25
Changed in ubuntuone-client:
status: Fix Committed → Fix Released
Launchpad Janitor (janitor) wrote :

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

---------------
ubuntuone-client (1.5.3-0ubuntu1) natty; urgency=low

  * New upstream release.
    - Metadata load is too slow (LP: #436612)
    - Out of space dialog is broken (LP: #650671)
    - Should not autoconnect when there are no credentials (LP: #701588)
    - gsd extension should not ask for sso credentials (LP: #702171)
 -- Rodney Dawes <email address hidden> Tue, 25 Jan 2011 16:42:52 -0500

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

Duplicates of this bug

Other bug subscribers