SONY driver:Speed up XML cache updating and fix saving to disk from device views

src/calibre/devices/prs505/driver.py

@@ -8,7 +8,7 @@ Device driver for the SONY devices
 
 import os, time, re
 
-from calibre.devices.usbms.driver import USBMS
+from calibre.devices.usbms.driver import USBMS, debug_print
 from calibre.devices.prs505 import MEDIA_XML
 from calibre.devices.prs505 import CACHE_XML
 from calibre.devices.prs505.sony_cache import XMLCache
@@ -128,12 +128,15 @@ class PRS505(USBMS):
         return XMLCache(paths, prefixes)
 
     def books(self, oncard=None, end_session=True):
+        debug_print('PRS505: starting fetching books for card', oncard)
         bl = USBMS.books(self, oncard=oncard, end_session=end_session)
         c = self.initialize_XML_cache()
         c.update_booklist(bl, {'carda':1, 'cardb':2}.get(oncard, 0))
+        debug_print('PRS505: finished fetching books for card', oncard)
         return bl
 
     def sync_booklists(self, booklists, end_session=True):
+        debug_print('PRS505: started sync_booklists')
         c = self.initialize_XML_cache()
         blists = {}
         for i in c.paths:
@@ -149,5 +152,6 @@ class PRS505(USBMS):
         c.write()
 
         USBMS.sync_booklists(self, booklists, end_session=end_session)
+        debug_print('PRS505: finished sync_booklists')
 
 

src/calibre/devices/prs505/sony_cache.py

@@ -14,6 +14,7 @@ from lxml import etree
 
 from calibre import prints, guess_type
 from calibre.devices.errors import DeviceError
+from calibre.devices.usbms.driver import debug_print
 from calibre.constants import DEBUG
 from calibre.ebooks.chardet import xml_to_unicode
 from calibre.ebooks.metadata import authors_to_string, title_sort
@@ -61,7 +62,7 @@ class XMLCache(object):
 
     def __init__(self, paths, prefixes):
         if DEBUG:
-            prints('Building XMLCache...')
+            debug_print('Building XMLCache...')
             pprint(paths)
         self.paths = paths
         self.prefixes = prefixes
@@ -97,16 +98,17 @@ class XMLCache(object):
         self.record_roots[0] = recs[0]
 
         self.detect_namespaces()
+        debug_print('Done building XMLCache...')
 
 
     # Playlist management {{{
     def purge_broken_playlist_items(self, root):
+        id_map = self.build_id_map(root)
         for pl in root.xpath('//*[local-name()="playlist"]'):
             seen = set([])
             for item in list(pl):
                 id_ = item.get('id', None)
-                if id_ is None or id_ in seen or not root.xpath(
+                if id_ is None or id_ in seen or id_map.get(id_, None) is None:
-                    '//*[local-name()!="item" and @id="%s"]'%id_):
                     if DEBUG:
                         if id_ is None:
                             cause = 'invalid id'
@@ -127,7 +129,7 @@ class XMLCache(object):
             for playlist in root.xpath('//*[local-name()="playlist"]'):
                 if len(playlist) == 0 or not playlist.get('title', None):
                     if DEBUG:
-                        prints('Removing playlist id:', playlist.get('id', None),
+                        debug_print('Removing playlist id:', playlist.get('id', None),
                                 playlist.get('title', None))
                     playlist.getparent().remove(playlist)
 
@@ -149,20 +151,25 @@ class XMLCache(object):
                     seen.add(title)
 
     def get_playlist_map(self):
+        debug_print('Start get_playlist_map')
         ans = {}
         self.ensure_unique_playlist_titles()
+        debug_print('after ensure_unique_playlist_titles')
         self.prune_empty_playlists()
+        debug_print('get_playlist_map loop')
         for i, root in self.record_roots.items():
+            debug_print('get_playlist_map loop', i)
+            id_map = self.build_id_map(root)
             ans[i] = []
             for playlist in root.xpath('//*[local-name()="playlist"]'):
                 items = []
                 for item in playlist:
                     id_ = item.get('id', None)
-                    records = root.xpath(
+                    record = id_map.get(id_, None)
-                        '//*[local-name()="text" and @id="%s"]'%id_)
+                    if record is not None:
-                    if records:
+                        items.append(record)
-                        items.append(records[0])
                 ans[i].append((playlist.get('title'), items))
+        debug_print('end get_playlist_map')
         return ans
 
     def get_or_create_playlist(self, bl_idx, title):
@@ -171,7 +178,7 @@ class XMLCache(object):
             if playlist.get('title', None) == title:
                 return playlist
         if DEBUG:
-            prints('Creating playlist:', title)
+            debug_print('Creating playlist:', title)
         ans = root.makeelement('{%s}playlist'%self.namespaces[bl_idx],
                 nsmap=root.nsmap, attrib={
                     'uuid' : uuid(),
@@ -185,7 +192,7 @@ class XMLCache(object):
 
     def fix_ids(self): # {{{
         if DEBUG:
-            prints('Running fix_ids()')
+            debug_print('Running fix_ids()')
 
         def ensure_numeric_ids(root):
             idmap = {}
@@ -198,8 +205,8 @@ class XMLCache(object):
                     idmap[id_] = '-1'
 
             if DEBUG and idmap:
-                prints('Found non numeric ids:')
+                debug_print('Found non numeric ids:')
-                prints(list(idmap.keys()))
+                debug_print(list(idmap.keys()))
             return idmap
 
         def remap_playlist_references(root, idmap):
@@ -210,7 +217,7 @@ class XMLCache(object):
                     if id_ in idmap:
                         item.set('id', idmap[id_])
                         if DEBUG:
-                            prints('Remapping id %s to %s'%(id_, idmap[id_]))
+                            debug_print('Remapping id %s to %s'%(id_, idmap[id_]))
 
         def ensure_media_xml_base_ids(root):
             for num, tag in enumerate(('library', 'watchSpecial')):
@@ -260,6 +267,8 @@ class XMLCache(object):
         last_bl = max(self.roots.keys())
         max_id = self.max_id(self.roots[last_bl])
         self.roots[0].set('nextID', str(max_id+1))
+        debug_print('Finished running fix_ids()')
+
     # }}}
 
     # Update JSON from XML {{{
@@ -267,7 +276,7 @@ class XMLCache(object):
         if bl_index not in self.record_roots:
             return
         if DEBUG:
-            prints('Updating JSON cache:', bl_index)
+            debug_print('Updating JSON cache:', bl_index)
         root = self.record_roots[bl_index]
         pmap = self.get_playlist_map()[bl_index]
         playlist_map = {}
@@ -279,13 +288,14 @@ class XMLCache(object):
                         playlist_map[path] = []
                     playlist_map[path].append(title)
 
+        lpath_map = self.build_lpath_map(root)
         for book in bl:
-            record = self.book_by_lpath(book.lpath, root)
+            record = lpath_map[book.lpath]
             if record is not None:
                 title = record.get('title', None)
                 if title is not None and title != book.title:
                     if DEBUG:
-                        prints('Renaming title', book.title, 'to', title)
+                        debug_print('Renaming title', book.title, 'to', title)
                     book.title = title
 # We shouldn't do this for Sonys, because the reader strips
 # all but the first author.
@@ -310,20 +320,24 @@ class XMLCache(object):
                 if book.lpath in playlist_map:
                     tags = playlist_map[book.lpath]
                     book.device_collections = tags
+        debug_print('Finished updating JSON cache:', bl_index)
 
     # }}}
 
     # Update XML from JSON {{{
     def update(self, booklists, collections_attributes):
+        debug_print('Starting update XML from JSON')
         playlist_map = self.get_playlist_map()
 
         for i, booklist in booklists.items():
             if DEBUG:
-                prints('Updating XML Cache:', i)
+                debug_print('Updating XML Cache:', i)
             root = self.record_roots[i]
+            lpath_map = self.build_lpath_map(root)
             for book in booklist:
                 path = os.path.join(self.prefixes[i], *(book.lpath.split('/')))
-                record = self.book_by_lpath(book.lpath, root)
+#                record = self.book_by_lpath(book.lpath, root)
+                record = lpath_map.get(book.lpath, None)
                 if record is None:
                     record = self.create_text_record(root, i, book.lpath)
                 self.update_text_record(record, book, path, i)
@@ -337,16 +351,19 @@ class XMLCache(object):
         # This is needed to update device_collections
         for i, booklist in booklists.items():
             self.update_booklist(booklist, i)
+        debug_print('Finished update XML from JSON')
 
     def update_playlists(self, bl_index, root, booklist, playlist_map,
             collections_attributes):
+        debug_print('Starting update_playlists')
         collections = booklist.get_collections(collections_attributes)
+        lpath_map = self.build_lpath_map(root)
         for category, books in collections.items():
-            records = [self.book_by_lpath(b.lpath, root) for b in books]
+            records = [lpath_map.get(b.lpath, None) for b in books]
             # Remove any books that were not found, although this
             # *should* never happen
             if DEBUG and None in records:
-                prints('WARNING: Some elements in the JSON cache were not'
+                debug_print('WARNING: Some elements in the JSON cache were not'
                         ' found in the XML cache')
             records = [x for x in records if x is not None]
             for rec in records:
@@ -355,7 +372,7 @@ class XMLCache(object):
             ids = [x.get('id', None) for x in records]
             if None in ids:
                 if DEBUG:
-                    prints('WARNING: Some <text> elements do not have ids')
+                    debug_print('WARNING: Some <text> elements do not have ids')
                     ids = [x for x in ids if x is not None]
 
             playlist = self.get_or_create_playlist(bl_index, category)
@@ -379,20 +396,21 @@ class XMLCache(object):
             title = playlist.get('title', None)
             if title not in collections:
                 if DEBUG:
-                    prints('Deleting playlist:', playlist.get('title', ''))
+                    debug_print('Deleting playlist:', playlist.get('title', ''))
                 playlist.getparent().remove(playlist)
                 continue
             books = collections[title]
-            records = [self.book_by_lpath(b.lpath, root) for b in books]
+            records = [lpath_map.get(b.lpath, None) for b in books]
             records = [x for x in records if x is not None]
             ids = [x.get('id', None) for x in records]
             ids = [x for x in ids if x is not None]
             for item in list(playlist):
                 if item.get('id', None) not in ids:
                     if DEBUG:
-                        prints('Deleting item:', item.get('id', ''),
+                        debug_print('Deleting item:', item.get('id', ''),
                                 'from playlist:', playlist.get('title', ''))
                     playlist.remove(item)
+        debug_print('Finishing update_playlists')
 
     def create_text_record(self, root, bl_id, lpath):
         namespace = self.namespaces[bl_id]
@@ -409,7 +427,7 @@ class XMLCache(object):
         date = strftime(timestamp)
         if date != record.get('date', None):
             if DEBUG:
-                prints('Changing date of', path, 'from',
+                debug_print('Changing date of', path, 'from',
                         record.get('date', ''), 'to', date)
                 prints('\tctime', strftime(os.path.getctime(path)))
                 prints('\tmtime', strftime(os.path.getmtime(path)))
@@ -475,12 +493,24 @@ class XMLCache(object):
     # }}}
 
     # Utility methods {{{
+
+    def build_lpath_map(self, root):
+        m = {}
+        for bk in root.xpath('//*[local-name()="text"]'):
+            m[bk.get('path')] = bk
+        return m
+
+    def build_id_map(self, root):
+        m = {}
+        for bk in root.xpath('//*[local-name()="text"]'):
+            m[bk.get('id')] = bk
+        return m
+
     def book_by_lpath(self, lpath, root):
         matches = root.xpath(u'//*[local-name()="text" and @path="%s"]'%lpath)
         if matches:
             return matches[0]
 
-
     def max_id(self, root):
         ans = -1
         for x in root.xpath('//*[@id]'):
@@ -516,9 +546,9 @@ class XMLCache(object):
                 self.namespaces[i] = ns
 
         if DEBUG:
-            prints('Found nsmaps:')
+            debug_print('Found nsmaps:')
             pprint(self.nsmaps)
-            prints('Found namespaces:')
+            debug_print('Found namespaces:')
             pprint(self.namespaces)
     # }}}
 

src/calibre/devices/usbms/books.py

@@ -46,7 +46,8 @@ class Book(MetaInformation):
             self.smart_update(other)
 
     def __eq__(self, other):
-        return self.path == getattr(other, 'path', None)
+        # use lpath because the prefix can change, changing path
+        return self.path == getattr(other, 'lpath', None)
 
     @dynamic_property
     def db_id(self):
@@ -97,13 +98,24 @@ class Book(MetaInformation):
 
 class BookList(_BookList):
 
+    def __init__(self, oncard, prefix, settings):
+        _BookList.__init__(self, oncard, prefix, settings)
+        self._bookmap = {}
+
     def supports_collections(self):
         return False
 
     def add_book(self, book, replace_metadata):
-        if book not in self:
+        try:
+            b = self.index(book)
+        except ValueError, IndexError:
+            b = None
+        if b is None:
             self.append(book)
             return True
+        if replace_metadata:
+            self[b].smart_update(book)
+            return True
         return False
 
     def remove_book(self, book):
@@ -112,7 +124,6 @@ class BookList(_BookList):
     def get_collections(self):
         return {}
 
-
 class CollectionsBookList(BookList):
 
     def supports_collections(self):

src/calibre/devices/usbms/driver.py

@@ -12,15 +12,24 @@ for a particular device.
 
 import os
 import re
+import time
 import json
 from itertools import cycle
 
 from calibre import prints, isbytestring
-from calibre.constants import filesystem_encoding
+from calibre.constants import filesystem_encoding, DEBUG
 from calibre.devices.usbms.cli import CLI
 from calibre.devices.usbms.device import Device
 from calibre.devices.usbms.books import BookList, Book
 
+BASE_TIME = None
+def debug_print(*args):
+    global BASE_TIME
+    if BASE_TIME is None:
+        BASE_TIME = time.time()
+    if DEBUG:
+        prints('DEBUG: %6.1f'%(time.time()-BASE_TIME), *args)
+
 # CLI must come before Device as it implements the CLI functions that
 # are inherited from the device interface in Device.
 class USBMS(CLI, Device):
@@ -47,6 +56,8 @@ class USBMS(CLI, Device):
     def books(self, oncard=None, end_session=True):
         from calibre.ebooks.metadata.meta import path_to_ext
 
+        debug_print ('USBMS: Fetching list of books from device. oncard=', oncard)
+
         dummy_bl = BookList(None, None, None)
 
         if oncard == 'carda' and not self._card_a_prefix:
@@ -136,8 +147,8 @@ class USBMS(CLI, Device):
                 need_sync = True
                 del bl[idx]
 
-        #print "count found in cache: %d, count of files in metadata: %d, need_sync: %s" % \
+        debug_print('USBMS: count found in cache: %d, count of files in metadata: %d, need_sync: %s' % \
-        #      (len(bl_cache), len(bl), need_sync)
+            (len(bl_cache), len(bl), need_sync))
         if need_sync: #self.count_found_in_bl != len(bl) or need_sync:
             if oncard == 'cardb':
                 self.sync_booklists((None, None, bl))
@@ -147,10 +158,13 @@ class USBMS(CLI, Device):
                 self.sync_booklists((bl, None, None))
 
         self.report_progress(1.0, _('Getting list of books on device...'))
+        debug_print('USBMS: Finished fetching list of books from device. oncard=', oncard)
         return bl
 
     def upload_books(self, files, names, on_card=None, end_session=True,
                      metadata=None):
+        debug_print('USBMS: uploading %d books'%(len(files)))
+
         path = self._sanity_check(on_card, files)
 
         paths = []
@@ -174,6 +188,7 @@ class USBMS(CLI, Device):
             self.report_progress((i+1) / float(len(files)), _('Transferring books to device...'))
 
         self.report_progress(1.0, _('Transferring books to device...'))
+        debug_print('USBMS: finished uploading %d books'%(len(files)))
         return zip(paths, cycle([on_card]))
 
     def upload_cover(self, path, filename, metadata):
@@ -186,6 +201,8 @@ class USBMS(CLI, Device):
         pass
 
     def add_books_to_metadata(self, locations, metadata, booklists):
+        debug_print('USBMS: adding metadata for %d books'%(len(metadata)))
+
         metadata = iter(metadata)
         for i, location in enumerate(locations):
             self.report_progress((i+1) / float(len(locations)), _('Adding books to device metadata listing...'))
@@ -218,8 +235,10 @@ class USBMS(CLI, Device):
                 book.size = os.stat(self.normalize_path(path)).st_size
             booklists[blist].add_book(book, replace_metadata=True)
         self.report_progress(1.0, _('Adding books to device metadata listing...'))
+        debug_print('USBMS: finished adding metadata')
 
     def delete_books(self, paths, end_session=True):
+        debug_print('USBMS: deleting %d books'%(len(paths)))
         for i, path in enumerate(paths):
             self.report_progress((i+1) / float(len(paths)), _('Removing books from device...'))
             path = self.normalize_path(path)
@@ -240,8 +259,11 @@ class USBMS(CLI, Device):
                     except:
                         pass
         self.report_progress(1.0, _('Removing books from device...'))
+        debug_print('USBMS: finished deleting %d books'%(len(paths)))
 
     def remove_books_from_metadata(self, paths, booklists):
+        debug_print('USBMS: removing metadata for %d books'%(len(paths)))
+
         for i, path in enumerate(paths):
             self.report_progress((i+1) / float(len(paths)), _('Removing books from device metadata listing...'))
             for bl in booklists:
@@ -249,8 +271,11 @@ class USBMS(CLI, Device):
                     if path.endswith(book.path):
                         bl.remove_book(book)
         self.report_progress(1.0, _('Removing books from device metadata listing...'))
+        debug_print('USBMS: finished removing metadata for %d books'%(len(paths)))
 
     def sync_booklists(self, booklists, end_session=True):
+        debug_print('USBMS: starting sync_booklists')
+
         if not os.path.exists(self.normalize_path(self._main_prefix)):
             os.makedirs(self.normalize_path(self._main_prefix))
 
@@ -267,6 +292,7 @@ class USBMS(CLI, Device):
         write_prefix(self._card_b_prefix, 2)
 
         self.report_progress(1.0, _('Sending metadata to device...'))
+        debug_print('USBMS: finished sync_booklists')
 
     @classmethod
     def path_to_unicode(cls, path):

src/calibre/gui2/device.py

@@ -122,7 +122,7 @@ class DeviceManager(Thread):
             try:
                 dev.open()
             except:
-                print 'Unable to open device', dev
+                prints('Unable to open device', str(dev))
                 traceback.print_exc()
                 continue
             self.connected_device = dev
@@ -168,11 +168,11 @@ class DeviceManager(Thread):
             if possibly_connected_devices:
                 if not self.do_connect(possibly_connected_devices,
                                        is_folder_device=False):
-                    print 'Connect to device failed, retrying in 5 seconds...'
+                    prints('Connect to device failed, retrying in 5 seconds...')
                     time.sleep(5)
                     if not self.do_connect(possibly_connected_devices,
                                        is_folder_device=False):
-                        print 'Device connect failed again, giving up'
+                        prints('Device connect failed again, giving up')
 
     def umount_device(self, *args):
         if self.is_device_connected and not self.job_manager.has_device_jobs():
@@ -317,7 +317,7 @@ class DeviceManager(Thread):
     def _save_books(self, paths, target):
         '''Copy books from device to disk'''
         for path in paths:
-            name = path.rpartition(getattr(self.device, 'path_sep', '/'))[2]
+            name = path.rpartition(os.sep)[2]
             dest = os.path.join(target, name)
             if os.path.abspath(dest) != os.path.abspath(path):
                 f = open(dest, 'wb')