diff --git a/src/calibre/devices/apple/driver.py b/src/calibre/devices/apple/driver.py index f82899ade2..f9724dc5fd 100644 --- a/src/calibre/devices/apple/driver.py +++ b/src/calibre/devices/apple/driver.py @@ -9,8 +9,7 @@ import cStringIO, ctypes, datetime, os, platform, re, shutil, sys, tempfile, tim from calibre import fit_image, confirm_config_name, strftime as _strftime from calibre.constants import ( - __appname__, __version__, DEBUG as CALIBRE_DEBUG, isosx, iswindows, - cache_dir as _cache_dir) + __appname__, __version__, isosx, iswindows, cache_dir as _cache_dir) from calibre.devices.errors import OpenFeedback, UserFeedback from calibre.devices.usbms.deviceconfig import DeviceConfig from calibre.devices.interface import DevicePlugin @@ -21,8 +20,6 @@ from calibre.utils.config import config_dir, dynamic, prefs from calibre.utils.date import now, parse_date from calibre.utils.zipfile import ZipFile -DEBUG = CALIBRE_DEBUG - def strftime(fmt='%Y/%m/%d %H:%M:%S', dt=None): if not hasattr(dt, 'timetuple'): @@ -130,12 +127,16 @@ class DriverBase(DeviceConfig, DevicePlugin): ':::' + _("

This setting should match your iTunes Preferences|Advanced setting.

" "

Disabling will store copies of books transferred to iTunes in your calibre configuration directory.

" - "

Enabling indicates that iTunes is configured to store copies in your iTunes Media folder.

") + "

Enabling indicates that iTunes is configured to store copies in your iTunes Media folder.

"), + _(u'Enable debug logging') + + ':::' + + _("Print driver debug messages to console"), ] EXTRA_CUSTOMIZATION_DEFAULT = [ True, True, False, + False, ] @classmethod @@ -306,6 +307,12 @@ class ITUNES(DriverBase): sources = None update_msg = None update_needed = False + verbose = False + + def __init__(self, path): + self.verbose = self.settings().extra_customization[3] + if self.verbose: + logger().info("%s.__init__():" % self.__class__.__name__) @property def cache_dir(self): @@ -327,7 +334,7 @@ class ITUNES(DriverBase): (L{books}(oncard=None), L{books}(oncard='carda'), L{books}(oncard='cardb')). ''' - if DEBUG: + if self.verbose: logger().info("%s.add_books_to_metadata()" % self.__class__.__name__) task_count = float(len(self.update_list)) @@ -372,7 +379,7 @@ class ITUNES(DriverBase): if self.cached_books[cb]['uuid'] == p_book['uuid']: if self.cached_books[cb]['title'] == p_book['title'] and \ self.cached_books[cb]['author'] == p_book['author']: - if DEBUG: + if self.verbose: self._dump_cached_book(self.cached_books[cb], header="removing from self.cached_books:", indent=2) self.cached_books.pop(cb) break @@ -387,7 +394,7 @@ class ITUNES(DriverBase): # Charles thinks this should be # for new_book in metadata[0]: for new_book in locations[0]: - if DEBUG: + if self.verbose: logger().info(" adding '%s' by '%s' to booklists[0]" % (new_book.title, new_book.author)) booklists[0].append(new_book) @@ -412,7 +419,7 @@ class ITUNES(DriverBase): """ if not oncard: - if DEBUG: + if self.verbose: logger().info("%s.books():" % self.__class__.__name__) if self.settings().extra_customization[self.CACHE_COVERS]: logger().info(" Cover fetching/caching enabled") @@ -458,7 +465,7 @@ class ITUNES(DriverBase): } if self.report_progress is not None: - self.report_progress((i + 1) / book_count, + self.report_progress(float((i + 1)*100 / book_count)/100, _('%(num)d of %(tot)d') % dict(num=i + 1, tot=book_count)) self._purge_orphans(library_books, cached_books) @@ -499,7 +506,7 @@ class ITUNES(DriverBase): } if self.report_progress is not None: - self.report_progress((i + 1) / book_count, + self.report_progress(float((i + 1)*100 / book_count)/100, _('%(num)d of %(tot)d') % dict(num=i + 1, tot=book_count)) self._purge_orphans(library_books, cached_books) @@ -510,7 +517,7 @@ class ITUNES(DriverBase): if self.report_progress is not None: self.report_progress(1.0, _('finished')) self.cached_books = cached_books - if DEBUG: + if self.verbose: self._dump_booklist(booklist, 'returning from books()', indent=2) self._dump_cached_books('returning from books()', indent=2) return booklist @@ -543,12 +550,12 @@ class ITUNES(DriverBase): # Check for connected book-capable device self.sources = self._get_sources() if 'iPod' in self.sources and not self.ejected: - #if DEBUG: + #if self.verbose: #sys.stdout.write('.') #sys.stdout.flush() return True else: - if DEBUG: + if self.verbose: sys.stdout.write('-') sys.stdout.flush() return False @@ -556,7 +563,7 @@ class ITUNES(DriverBase): # Called at entry # We need to know if iTunes sees the iPad # It may have been ejected - if DEBUG: + if self.verbose: logger().info("%s.can_handle()" % self.__class__.__name__) self._launch_iTunes() @@ -569,15 +576,15 @@ class ITUNES(DriverBase): if (not 'iPod' in self.sources) or (self.sources['iPod'] == ''): attempts -= 1 time.sleep(1.0) - if DEBUG: + if self.verbose: logger().warning(" waiting for connected iDevice, attempt #%d" % (10 - attempts)) else: - if DEBUG: + if self.verbose: logger().info(' found connected iDevice') break else: # iTunes running, but not connected iPad - if DEBUG: + if self.verbose: logger().info(' self.ejected = True') self.ejected = True return False @@ -610,16 +617,16 @@ class ITUNES(DriverBase): pythoncom.CoInitialize() self.sources = self._get_sources() if 'iPod' in self.sources: - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() - if DEBUG: + if self.verbose: logger().info("%s.can_handle_windows:\n confirming connected iPad" % self.__class__.__name__) self.ejected = False self._discover_manual_sync_mode() return True else: - if DEBUG: + if self.verbose: logger().info("%s.can_handle_windows():\n device ejected" % self.__class__.__name__) self.ejected = True return False @@ -632,7 +639,7 @@ class ITUNES(DriverBase): pythoncom.CoUninitialize() else: - if DEBUG: + if self.verbose: logger().info("%s.can_handle_windows():\n Launching iTunes" % self.__class__.__name__) try: @@ -647,15 +654,15 @@ class ITUNES(DriverBase): if (not 'iPod' in self.sources) or (self.sources['iPod'] == ''): attempts -= 1 time.sleep(1.0) - if DEBUG: + if self.verbose: logger().warning(" waiting for connected iDevice, attempt #%d" % (10 - attempts)) else: - if DEBUG: + if self.verbose: logger().info(' found connected iPad in iTunes') break else: # iTunes running, but not connected iPad - if DEBUG: + if self.verbose: logger().info(' iDevice has been ejected') self.ejected = True return False @@ -706,7 +713,7 @@ class ITUNES(DriverBase): logger().info("%s.delete_books()" % self.__class__.__name__) for path in paths: if self.cached_books[path]['lib_book']: - if DEBUG: + if self.verbose: logger().info(" Deleting '%s' from iTunes library" % (path)) if isosx: @@ -757,7 +764,7 @@ class ITUNES(DriverBase): Un-mount / eject the device from the OS. This does not check if there are pending GUI jobs that need to communicate with the device. ''' - if DEBUG: + if self.verbose: logger().info("%s:eject(): ejecting '%s'" % (self.__class__.__name__, self.sources['iPod'])) if isosx: self.iTunes.eject(self.sources['iPod']) @@ -788,7 +795,7 @@ class ITUNES(DriverBase): In Windows, a sync-in-progress blocks this call until sync is complete """ - if DEBUG: + if self.verbose: logger().info("%s.free_space()" % self.__class__.__name__) free_space = 0 @@ -821,7 +828,7 @@ class ITUNES(DriverBase): Ask device for device information. See L{DeviceInfoQuery}. @return: (device name, device version, software version on device, mime type) """ - if DEBUG: + if self.verbose: logger().info("%s.get_device_information()" % self.__class__.__name__) return (self.sources['iPod'], 'hw v1.0', 'sw v1.0', 'unknown mime type') @@ -831,7 +838,7 @@ class ITUNES(DriverBase): Read the file at C{path} on the device and write it to outfile. @param outfile: file object like C{sys.stdout} or the result of an C{open} call ''' - if DEBUG: + if self.verbose: logger().info("%s.get_file(): exporting '%s'" % (self.__class__.__name__, path)) try: @@ -861,7 +868,7 @@ class ITUNES(DriverBase): if self.iTunes is None: raise OpenFeedback(self.ITUNES_SANDBOX_LOCKOUT_MESSAGE) - if DEBUG: + if self.verbose: vendor_id = "0x%x" % connected_device[0] product_id = "0x%x" % connected_device[1] bcd = "0x%x" % connected_device[2] @@ -882,17 +889,17 @@ class ITUNES(DriverBase): if dynamic.get(confirm_config_name(self.DISPLAY_DISABLE_DIALOG), True): raise AppleOpenFeedback(self) else: - if DEBUG: + if self.verbose: logger().info(" %s" % self.UNSUPPORTED_DIRECT_CONNECT_MODE_MESSAGE) # Log supported DEVICE_IDs and BCDs - if DEBUG: + if self.verbose: logger().info(" BCD: %s" % ['0x%x' % x for x in sorted(self.BCD)]) logger().info(" PRODUCT_ID: %s" % ['0x%x' % x for x in sorted(self.PRODUCT_ID)]) # Confirm/create thumbs archive if not os.path.exists(self.cache_dir): - if DEBUG: + if self.verbose: logger().info(" creating thumb cache at '%s'" % self.cache_dir) os.makedirs(self.cache_dir) @@ -902,18 +909,18 @@ class ITUNES(DriverBase): zfw.writestr("iTunes Thumbs Archive", '') zfw.close() else: - if DEBUG: + if self.verbose: logger().info(" existing thumb cache at '%s'" % self.archive_path) # If enabled in config options, create/confirm an iTunes storage folder if not self.settings().extra_customization[self.USE_ITUNES_STORAGE]: self.iTunes_local_storage = os.path.join(config_dir, 'iTunes storage') if not os.path.exists(self.iTunes_local_storage): - if DEBUG: + if self.verbose: logger()(" creating iTunes_local_storage at '%s'" % self.iTunes_local_storage) os.mkdir(self.iTunes_local_storage) else: - if DEBUG: + if self.verbose: logger()(" existing iTunes_local_storage at '%s'" % self.iTunes_local_storage) def remove_books_from_metadata(self, paths, booklists): @@ -928,10 +935,10 @@ class ITUNES(DriverBase): NB: This will not find books that were added by a different installation of calibre as uuids are different ''' - if DEBUG: + if self.verbose: logger().info("%s.remove_books_from_metadata()" % self.__class__.__name__) for path in paths: - if DEBUG: + if self.verbose: self._dump_cached_book(self.cached_books[path], indent=2) logger().info(" looking for '%s' by '%s' uuid:%s" % (self.cached_books[path]['title'], @@ -977,17 +984,17 @@ class ITUNES(DriverBase): except: thumb = None if thumb: - if DEBUG: + if self.verbose: logger().info(" deleting '%s' from cover cache" % (thumb_path)) zf.delete(thumb_path) else: - if DEBUG: + if self.verbose: logger().info(" '%s' not found in cover cache" % thumb_path) zf.close() break else: - if DEBUG: + if self.verbose: logger().error(" unable to find '%s' by '%s' (%s)" % (self.cached_books[path]['title'], self.cached_books[path]['author'], @@ -1008,7 +1015,7 @@ class ITUNES(DriverBase): task does not have any progress information :detected_device: Device information from the device scanner """ - if DEBUG: + if self.verbose: logger().info("%s.reset()" % self.__class__.__name__) if report_progress: self.set_progress_reporter(report_progress) @@ -1020,7 +1027,7 @@ class ITUNES(DriverBase): If it is called with -1 that means that the task does not have any progress information ''' - if DEBUG: + if self.verbose: logger().info("%s.set_progress_reporter()" % self.__class__.__name__) self.report_progress = report_progress @@ -1028,7 +1035,7 @@ class ITUNES(DriverBase): def set_plugboards(self, plugboards, pb_func): # This method is called with the plugboard that matches the format # and a device name of ITUNES - if DEBUG: + if self.verbose: logger().info("%s.set_plugboard()" % self.__class__.__name__) #logger().info(' plugboard: %s' % plugboards) self.plugboards = plugboards @@ -1046,11 +1053,11 @@ class ITUNES(DriverBase): L{books}(oncard='cardb')). ''' - if DEBUG: + if self.verbose: logger().info("%s.sync_booklists()" % self.__class__.__name__) if self.update_needed: - if DEBUG: + if self.verbose: logger().info(' calling _update_device') self._update_device(msg=self.update_msg, wait=False) self.update_needed = False @@ -1073,7 +1080,7 @@ class ITUNES(DriverBase): @return: A 3 element list with total space in bytes of (1, 2, 3). If a particular device doesn't have any of these locations it should return 0. """ - if DEBUG: + if self.verbose: logger().info("%s.total_space()" % self.__class__.__name__) capacity = 0 if isosx: @@ -1111,7 +1118,7 @@ class ITUNES(DriverBase): self.problem_msg = _("Some cover art could not be converted.\n" "Click 'Show Details' for a list.") - if DEBUG: + if self.verbose: logger().info("%s.upload_books()" % self.__class__.__name__) if isosx: @@ -1128,7 +1135,7 @@ class ITUNES(DriverBase): self._update_iTunes_metadata(metadata[i], db_added, lb_added, this_book) # Add new_book to self.cached_books - if DEBUG: + if self.verbose: logger().info("%s.upload_books()" % self.__class__.__name__) logger().info(" adding '%s' by '%s' uuid:%s to self.cached_books" % (metadata[i].title, @@ -1175,7 +1182,7 @@ class ITUNES(DriverBase): self._update_iTunes_metadata(metadata[i], db_added, lb_added, this_book) # Add new_book to self.cached_books - if DEBUG: + if self.verbose: logger().info("%s.upload_books()" % self.__class__.__name__) logger().info(" adding '%s' by '%s' uuid:%s to self.cached_books" % (metadata[i].title, @@ -1225,7 +1232,7 @@ class ITUNES(DriverBase): if pl.special_kind() == appscript.k.Books: break else: - if DEBUG: + if self.verbose: logger().error(" Device|Books playlist not found") # Add the passed book to the Device|Books playlist @@ -1239,12 +1246,12 @@ class ITUNES(DriverBase): break except: attempts -= 1 - if DEBUG: + if self.verbose: logger().warning(" failed to add book, waiting %.1f seconds to try again (attempt #%d)" % (delay, (3 - attempts))) time.sleep(delay) else: - if DEBUG: + if self.verbose: logger().error(" failed to add '%s' to Device|Books" % metadata.title) raise UserFeedback("Unable to add '%s' in direct connect mode" % metadata.title, details=None, level=UserFeedback.ERROR) @@ -1262,7 +1269,7 @@ class ITUNES(DriverBase): pl.SpecialKind == self.PlaylistSpecialKind.index('Books'): break else: - if DEBUG: + if self.verbose: logger().info(" no Books playlist found") # Add the passed book to the Device|Books playlist @@ -1272,16 +1279,16 @@ class ITUNES(DriverBase): fa = FileArray(file_s) op_status = pl.AddFiles(fa) - if DEBUG: + if self.verbose: sys.stdout.write(" uploading '%s' to Device|Books ..." % metadata.title) sys.stdout.flush() while op_status.InProgress: time.sleep(0.5) - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() - if DEBUG: + if self.verbose: sys.stdout.write("\n") sys.stdout.flush() @@ -1292,16 +1299,16 @@ class ITUNES(DriverBase): This would be the preferred approach (as under OSX) It works in _add_library_book() ''' - if DEBUG: + if self.verbose: sys.stdout.write(" waiting for handle to added '%s' ..." % metadata.title) sys.stdout.flush() while not op_status.Tracks: time.sleep(0.5) - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() - if DEBUG: + if self.verbose: print added = op_status.Tracks[0] else: @@ -1324,7 +1331,7 @@ class ITUNES(DriverBase): ''' windows assumes pythoncom wrapper ''' - if DEBUG: + if self.verbose: logger().info(" %s._add_library_book()" % self.__class__.__name__) if isosx: import appscript @@ -1336,21 +1343,21 @@ class ITUNES(DriverBase): FileArray = ctypes.c_char_p * 1 fa = FileArray(file_s) op_status = lib.AddFiles(fa) - if DEBUG: + if self.verbose: logger().info(" file added to Library|Books") logger().info(" iTunes adding '%s'" % file) - if DEBUG: + if self.verbose: sys.stdout.write(" iTunes copying '%s' ..." % metadata.title) sys.stdout.flush() while op_status.InProgress: time.sleep(0.5) - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() - if DEBUG: + if self.verbose: sys.stdout.write("\n") sys.stdout.flush() @@ -1360,15 +1367,15 @@ class ITUNES(DriverBase): Originally disabled because op_status.Tracks never returned a value after adding file. Seems to be working with iTunes 9.2.1.5 06 Aug 2010 ''' - if DEBUG: + if self.verbose: sys.stdout.write(" waiting for handle to added '%s' ..." % metadata.title) sys.stdout.flush() while op_status.Tracks is None: time.sleep(0.5) - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() - if DEBUG: + if self.verbose: print added = op_status.Tracks[0] else: @@ -1392,7 +1399,7 @@ class ITUNES(DriverBase): fp = cached_book['lib_book'].location().path fp = cached_book['lib_book'].Location ''' - if DEBUG: + if self.verbose: logger().info(" %s._add_new_copy()" % self.__class__.__name__) if fpath.rpartition('.')[2].lower() == 'epub': @@ -1428,7 +1435,7 @@ class ITUNES(DriverBase): ''' from PIL import Image as PILImage - if DEBUG: + if self.verbose: logger().info(" %s._cover_to_thumb()" % self.__class__.__name__) thumb = None @@ -1445,7 +1452,7 @@ class ITUNES(DriverBase): height = img.size[1] scaled, nwidth, nheight = fit_image(width, height, self.MAX_COVER_WIDTH, self.MAX_COVER_HEIGHT) if scaled: - if DEBUG: + if self.verbose: logger().info(" cover scaled from %sx%s to %sx%s" % (width, height, nwidth, nheight)) img = img.resize((nwidth, nheight), PILImage.ANTIALIAS) @@ -1475,7 +1482,7 @@ class ITUNES(DriverBase): try: lb_added.artworks[1].data_.set(cover_data) except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " adding artwork to '%s' in the iTunes Library" % metadata.title) pass @@ -1485,7 +1492,7 @@ class ITUNES(DriverBase): db_added.artworks[1].data_.set(cover_data) logger().info(" writing '%s' cover to iDevice" % metadata.title) except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " adding artwork to '%s' on the iDevice" % metadata.title) #import traceback @@ -1507,7 +1514,7 @@ class ITUNES(DriverBase): else: lb_added.AddArtworkFromFile(tc) except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " when adding artwork to '%s' in the iTunes Library" % metadata.title) pass @@ -1519,7 +1526,7 @@ class ITUNES(DriverBase): db_added.AddArtworkFromFile(tc) elif format == 'pdf': - if DEBUG: + if self.verbose: logger().info(" unable to set PDF cover via automation interface") try: @@ -1534,7 +1541,7 @@ class ITUNES(DriverBase): of.close() # Refresh the thumbnail cache - if DEBUG: + if self.verbose: logger().info(" refreshing cached thumb for '%s'" % metadata.title) zfw = ZipFile(self.archive_path, mode='a') thumb_path = path.rpartition('.')[0] + '.jpg' @@ -1548,14 +1555,14 @@ class ITUNES(DriverBase): except: pass else: - if DEBUG: + if self.verbose: logger().info(" no cover defined in metadata for '%s'" % metadata.title) return thumb def _create_new_book(self, fpath, metadata, path, db_added, lb_added, thumb, format): ''' ''' - if DEBUG: + if self.verbose: logger().info(" %s._create_new_book()" % self.__class__.__name__) this_book = Book(metadata.title, authors_to_string(metadata.authors)) @@ -1604,7 +1611,7 @@ class ITUNES(DriverBase): Assumes pythoncom for windows wait is passed when launching iTunes, as it seems to need a moment to come to its senses ''' - if DEBUG: + if self.verbose: logger().info(" %s._discover_manual_sync_mode()" % self.__class__.__name__) if wait: time.sleep(wait) @@ -1630,7 +1637,7 @@ class ITUNES(DriverBase): except: self.manual_sync_mode = False else: - if DEBUG: + if self.verbose: logger().info(" adding tracer to empty Books|Playlist") try: added = pl.add(appscript.mactypes.File(P('tracer.epub')), to=pl) @@ -1653,7 +1660,7 @@ class ITUNES(DriverBase): if dev_books is not None and dev_books.Count: first_book = dev_books.Item(1) - #if DEBUG: + #if self.verbose: #logger().info(" determing manual mode by modifying '%s' by %s" % (first_book.Name, first_book.Artist)) try: first_book.BPM = 0 @@ -1661,7 +1668,7 @@ class ITUNES(DriverBase): except: self.manual_sync_mode = False else: - if DEBUG: + if self.verbose: logger().info(" sending tracer to empty Books|Playlist") fpath = P('tracer.epub') mi = MetaInformation('Tracer', ['calibre']) @@ -1673,7 +1680,7 @@ class ITUNES(DriverBase): except: self.manual_sync_mode = False - if DEBUG: + if self.verbose: logger().info(" iTunes.manual_sync_mode: %s" % self.manual_sync_mode) def _dump_booklist(self, booklist, header=None, indent=0): @@ -1779,11 +1786,11 @@ class ITUNES(DriverBase): timestamp = ts['content'] if not title or not author: - if DEBUG: + if self.verbose: logger().error(" couldn't extract title/author from %s in %s" % (opf, fpath)) logger().error(" title: %s author: %s timestamp: %s" % (title, author, timestamp)) else: - if DEBUG: + if self.verbose: logger().error(" can't find .opf in %s" % fpath) zf.close() return (title, author, timestamp) @@ -1805,7 +1812,7 @@ class ITUNES(DriverBase): def _dump_library_books(self, library_books): ''' ''' - if DEBUG: + if self.verbose: logger().info("\n library_books:") for book in library_books: logger().info(" %s" % book) @@ -1838,7 +1845,7 @@ class ITUNES(DriverBase): ''' if iswindows: dev_books = self._get_device_books_playlist() - if DEBUG: + if self.verbose: logger().info(" %s._find_device_book()" % self.__class__.__name__) logger().info(" searching for '%s' by '%s' (%s)" % (search['title'], search['author'], search['uuid'])) @@ -1846,7 +1853,7 @@ class ITUNES(DriverBase): while attempts: # Try by uuid - only one hit if 'uuid' in search and search['uuid']: - if DEBUG: + if self.verbose: logger().info(" searching by uuid '%s' ..." % search['uuid']) hits = dev_books.Search(search['uuid'], self.SearchField.index('All')) if hits: @@ -1856,24 +1863,24 @@ class ITUNES(DriverBase): # Try by author - there could be multiple hits if search['author']: - if DEBUG: + if self.verbose: logger().info(" searching by author '%s' ..." % search['author']) hits = dev_books.Search(search['author'], self.SearchField.index('Artists')) if hits: for hit in hits: if hit.Name == search['title']: - if DEBUG: + if self.verbose: logger().info(" found '%s' by %s (%s)" % (hit.Name, hit.Artist, hit.Composer)) return hit # Search by title if no author available - if DEBUG: + if self.verbose: logger().info(" searching by title '%s' ..." % search['title']) hits = dev_books.Search(search['title'], self.SearchField.index('All')) if hits: for hit in hits: if hit.Name == search['title']: - if DEBUG: + if self.verbose: logger().info(" found '%s'" % (hit.Name)) return hit @@ -1882,7 +1889,7 @@ class ITUNES(DriverBase): if search['format'] == 'pdf': title = re.sub(r'[^0-9a-zA-Z ]', '_', search['title']) author = re.sub(r'[^0-9a-zA-Z ]', '_', search['author']) - if DEBUG: + if self.verbose: logger().info(" searching by name: '%s - %s'" % (title, author)) hits = dev_books.Search('%s - %s' % (title, author), self.SearchField.index('All')) @@ -1891,15 +1898,15 @@ class ITUNES(DriverBase): logger().info(" found '%s' by %s (%s)" % (hit.Name, hit.Artist, hit.Composer)) return hit else: - if DEBUG: + if self.verbose: logger().info(" no PDF hits") attempts -= 1 time.sleep(0.5) - if DEBUG: + if self.verbose: logger().warning(" attempt #%d" % (10 - attempts)) - if DEBUG: + if self.verbose: logger().error(" no hits") return None @@ -1908,7 +1915,7 @@ class ITUNES(DriverBase): Windows-only method to get a handle to a library book in the current pythoncom session ''' if iswindows: - if DEBUG: + if self.verbose: logger().info(" %s._find_library_book()" % self.__class__.__name__) ''' if 'uuid' in search: @@ -1922,11 +1929,11 @@ class ITUNES(DriverBase): for source in self.iTunes.sources: if source.Kind == self.Sources.index('Library'): lib = source - if DEBUG: + if self.verbose: logger().info(" Library source: '%s' kind: %s" % (lib.Name, self.Sources[lib.Kind])) break else: - if DEBUG: + if self.verbose: logger().info(" Library source not found") if lib is not None: @@ -1934,47 +1941,47 @@ class ITUNES(DriverBase): for pl in lib.Playlists: if pl.Kind == self.PlaylistKind.index('User') and \ pl.SpecialKind == self.PlaylistSpecialKind.index('Books'): - if DEBUG: + if self.verbose: logger().info(" Books playlist: '%s'" % (pl.Name)) lib_books = pl break else: - if DEBUG: + if self.verbose: logger().error(" no Books playlist found") attempts = 9 while attempts: # Find book whose Album field = search['uuid'] if 'uuid' in search and search['uuid']: - if DEBUG: + if self.verbose: logger().info(" searching by uuid '%s' ..." % search['uuid']) hits = lib_books.Search(search['uuid'], self.SearchField.index('All')) if hits: hit = hits[0] - if DEBUG: + if self.verbose: logger().info(" found '%s' by %s (%s)" % (hit.Name, hit.Artist, hit.Composer)) return hit # Search by author if known if search['author']: - if DEBUG: + if self.verbose: logger().info(" searching by author '%s' ..." % search['author']) hits = lib_books.Search(search['author'], self.SearchField.index('Artists')) if hits: for hit in hits: if hit.Name == search['title']: - if DEBUG: + if self.verbose: logger().info(" found '%s' by %s (%s)" % (hit.Name, hit.Artist, hit.Composer)) return hit # Search by title if no author available - if DEBUG: + if self.verbose: logger().info(" searching by title '%s' ..." % search['title']) hits = lib_books.Search(search['title'], self.SearchField.index('All')) if hits: for hit in hits: if hit.Name == search['title']: - if DEBUG: + if self.verbose: logger().info(" found '%s'" % (hit.Name)) return hit @@ -1983,7 +1990,7 @@ class ITUNES(DriverBase): if search['format'] == 'pdf': title = re.sub(r'[^0-9a-zA-Z ]', '_', search['title']) author = re.sub(r'[^0-9a-zA-Z ]', '_', search['author']) - if DEBUG: + if self.verbose: logger().info(" searching by name: %s - %s" % (title, author)) hits = lib_books.Search('%s - %s' % (title, author), self.SearchField.index('All')) @@ -1992,15 +1999,15 @@ class ITUNES(DriverBase): logger().info(" found '%s' by %s (%s)" % (hit.Name, hit.Artist, hit.Composer)) return hit else: - if DEBUG: + if self.verbose: logger().info(" no PDF hits") attempts -= 1 time.sleep(0.5) - if DEBUG: + if self.verbose: logger().warning(" attempt #%d" % (10 - attempts)) - if DEBUG: + if self.verbose: logger().error(" search for '%s' yielded no hits" % search['title']) return None @@ -2039,7 +2046,7 @@ class ITUNES(DriverBase): logger().info(" returning thumb from cache for '%s'" % title) return thumb_data - if DEBUG: + if self.verbose: logger().info(" %s._generate_thumbnail('%s'):" % (self.__class__.__name__, title)) if isosx: @@ -2048,7 +2055,7 @@ class ITUNES(DriverBase): data = book.artworks[1].raw_data().data except: # If no artwork, write an empty marker to cache - if DEBUG: + if self.verbose: logger().error(" error fetching iTunes artwork for '%s'" % title) zfw.writestr(thumb_path, 'None') zfw.close() @@ -2070,7 +2077,7 @@ class ITUNES(DriverBase): # Cache the tagged thumb zfw.writestr(thumb_path, thumb_data) except: - if DEBUG: + if self.verbose: logger().error(" error generating thumb for '%s', caching empty marker" % book.name()) self._dump_hex(data[:32]) thumb_data = None @@ -2084,7 +2091,7 @@ class ITUNES(DriverBase): elif iswindows: if not book.Artwork.Count: - if DEBUG: + if self.verbose: logger().info(" no artwork available for '%s'" % book.Name) zfw.writestr(thumb_path, 'None') zfw.close() @@ -2109,7 +2116,7 @@ class ITUNES(DriverBase): # Cache the tagged thumb zfw.writestr(thumb_path, thumb_data) except: - if DEBUG: + if self.verbose: logger().error(" error generating thumb for '%s', caching empty marker" % book.Name) thumb_data = None # Cache the empty cover @@ -2143,7 +2150,7 @@ class ITUNES(DriverBase): ''' Assumes pythoncom wrapper for Windows ''' - if DEBUG: + if self.verbose: logger().info("\n %s._get_device_books()" % self.__class__.__name__) device_books = [] @@ -2156,7 +2163,7 @@ class ITUNES(DriverBase): dev_books = None for pl in device.playlists(): if pl.special_kind() == appscript.k.Books: - if DEBUG: + if self.verbose: logger().info(" Book playlist: '%s'" % (pl.name())) dev_books = pl.file_tracks() break @@ -2165,14 +2172,14 @@ class ITUNES(DriverBase): for book in dev_books: if book.kind() in self.Audiobooks: - if DEBUG: + if self.verbose: logger().info(" ignoring '%s' of type '%s'" % (book.name(), book.kind())) else: - if DEBUG: + if self.verbose: logger().info(" %-40.40s %-30.30s %-40.40s [%s]" % (book.name(), book.artist(), book.composer(), book.kind())) device_books.append(book) - if DEBUG: + if self.verbose: logger().info() elif iswindows: @@ -2188,23 +2195,23 @@ class ITUNES(DriverBase): for pl in device.Playlists: if pl.Kind == self.PlaylistKind.index('User') and \ pl.SpecialKind == self.PlaylistSpecialKind.index('Books'): - if DEBUG: + if self.verbose: logger().info(" Books playlist: '%s'" % (pl.Name)) dev_books = pl.Tracks break else: - if DEBUG: + if self.verbose: logger().info(" no Books playlist found") for book in dev_books: if book.KindAsString in self.Audiobooks: - if DEBUG: + if self.verbose: logger().info(" ignoring '%s' of type '%s'" % (book.Name, book.KindAsString)) else: - if DEBUG: + if self.verbose: logger().info(" %-40.40s %-30.30s %-40.40s [%s]" % (book.Name, book.Artist, book.Composer, book.KindAsString)) device_books.append(book) - if DEBUG: + if self.verbose: logger().info() finally: @@ -2227,7 +2234,7 @@ class ITUNES(DriverBase): pl.SpecialKind == self.PlaylistSpecialKind.index('Books'): break else: - if DEBUG: + if self.verbose: logger().error(" no iPad|Books playlist found") return pl @@ -2236,7 +2243,7 @@ class ITUNES(DriverBase): Populate a dict of paths from iTunes Library|Books Windows assumes pythoncom wrapper ''' - if DEBUG: + if self.verbose: logger().info("\n %s._get_library_books()" % self.__class__.__name__) library_books = {} @@ -2248,11 +2255,11 @@ class ITUNES(DriverBase): for source in self.iTunes.sources(): if source.kind() == appscript.k.library: lib = source - if DEBUG: + if self.verbose: logger().info(" Library source: '%s'" % (lib.name())) break else: - if DEBUG: + if self.verbose: logger().error(' Library source not found') if lib is not None: @@ -2260,18 +2267,18 @@ class ITUNES(DriverBase): if lib.playlists(): for pl in lib.playlists(): if pl.special_kind() == appscript.k.Books: - if DEBUG: + if self.verbose: logger().info(" Books playlist: '%s'" % (pl.name())) break else: - if DEBUG: + if self.verbose: logger().info(" no Library|Books playlist found") lib_books = pl.file_tracks() for book in lib_books: # This may need additional entries for international iTunes users if book.kind() in self.Audiobooks: - if DEBUG: + if self.verbose: logger().info(" ignoring '%s' of type '%s'" % (book.name(), book.kind())) else: # Collect calibre orphans - remnants of recipe uploads @@ -2284,18 +2291,18 @@ class ITUNES(DriverBase): if False: logger().info(" found iTunes PTF '%s' in Library|Books" % book.name()) except: - if DEBUG: + if self.verbose: logger().error(" iTunes returned an error returning .location() with %s" % book.name()) library_books[path] = book - if DEBUG: + if self.verbose: logger().info(" %-30.30s %-30.30s %-40.40s [%s]" % (book.name(), book.artist(), book.album(), book.kind())) else: - if DEBUG: + if self.verbose: logger().info(' no Library playlists') else: - if DEBUG: + if self.verbose: logger().info(' no Library found') elif iswindows: @@ -2314,22 +2321,22 @@ class ITUNES(DriverBase): for pl in lib.Playlists: if pl.Kind == self.PlaylistKind.index('User') and \ pl.SpecialKind == self.PlaylistSpecialKind.index('Books'): - if DEBUG: + if self.verbose: logger().info(" Books playlist: '%s'" % (pl.Name)) lib_books = pl.Tracks break else: - if DEBUG: + if self.verbose: logger().error(" no Library|Books playlist found") else: - if DEBUG: + if self.verbose: logger().error(" no Library playlists found") try: for book in lib_books: # This may need additional entries for international iTunes users if book.KindAsString in self.Audiobooks: - if DEBUG: + if self.verbose: logger().info(" ignoring %-30.30s of type '%s'" % (book.Name, book.KindAsString)) else: format = 'pdf' if book.KindAsString.startswith('PDF') else 'epub' @@ -2343,10 +2350,10 @@ class ITUNES(DriverBase): logger().info(" found iTunes PTF '%s' in Library|Books" % book.Name) library_books[path] = book - if DEBUG: + if self.verbose: logger().info(" %-30.30s %-30.30s %-40.40s [%s]" % (book.Name, book.Artist, book.Album, book.KindAsString)) except: - if DEBUG: + if self.verbose: logger().info(" no books in library") self.library_orphans = library_orphans @@ -2392,7 +2399,7 @@ class ITUNES(DriverBase): # If more than one connected iDevice, remove all from list to prevent driver initialization if kinds.count('iPod') > 1: - if DEBUG: + if self.verbose: logger().error(" %d connected iPod devices detected, calibre supports a single connected iDevice" % kinds.count('iPod')) while kinds.count('iPod'): index = kinds.index('iPod') @@ -2412,7 +2419,7 @@ class ITUNES(DriverBase): def _launch_iTunes(self): ''' ''' - if DEBUG: + if self.verbose: logger().info(" %s._launch_iTunes():\n Instantiating iTunes" % self.__class__.__name__) if isosx: @@ -2425,7 +2432,7 @@ class ITUNES(DriverBase): # Instantiate iTunes running_apps = appscript.app('System Events') if not 'iTunes' in running_apps.processes.name(): - if DEBUG: + if self.verbose: logger().info("%s:_launch_iTunes(): Launching iTunes" % self.__class__.__name__) try: self.iTunes = iTunes = appscript.app('iTunes', hide=True) @@ -2458,7 +2465,7 @@ class ITUNES(DriverBase): as_binding = "static" except: self.iTunes = None - if DEBUG: + if self.verbose: logger().info(" unable to communicate with iTunes via %s %s using any binding" % (as_name, as_version)) return @@ -2475,7 +2482,7 @@ class ITUNES(DriverBase): logger().error(" media_dir: %s" % media_dir) ''' - if DEBUG: + if self.verbose: logger().info(" %s %s" % (__appname__, __version__)) logger().info(" [OSX %s, %s %s (%s), %s driver version %d.%d.%d]" % (platform.mac_ver()[0], @@ -2544,7 +2551,7 @@ class ITUNES(DriverBase): logger().error(" no media dir found: string: %s" % string) ''' - if DEBUG: + if self.verbose: logger().info(" %s %s" % (__appname__, __version__)) logger().info(" [Windows %s - %s (%s), driver version %d.%d.%d]" % (self.iTunes.Windows[0].name, self.iTunes.Version, self.initial_status, @@ -2559,7 +2566,7 @@ class ITUNES(DriverBase): ''' PURGE_ORPHANS = False - if DEBUG: + if self.verbose: logger().info(" %s._purge_orphans()" % self.__class__.__name__) #self._dump_library_books(library_books) #logger().info(" cached_books:\n %s" % "\n ".join(cached_books.keys())) @@ -2569,7 +2576,7 @@ class ITUNES(DriverBase): if book not in cached_books and \ str(library_books[book].description()).startswith(self.description_prefix): if PURGE_ORPHANS: - if DEBUG: + if self.verbose: logger().info(" '%s' not found on iDevice, removing from iTunes" % book) btr = { 'title': library_books[book].name(), @@ -2577,14 +2584,14 @@ class ITUNES(DriverBase): 'lib_book': library_books[book]} self._remove_from_iTunes(btr) else: - if DEBUG: + if self.verbose: logger().info(" '%s' found in iTunes, but not on iDevice" % (book)) elif iswindows: if book not in cached_books and \ library_books[book].Description.startswith(self.description_prefix): if PURGE_ORPHANS: - if DEBUG: + if self.verbose: logger().info(" '%s' not found on iDevice, removing from iTunes" % book) btr = { 'title': library_books[book].Name, @@ -2592,13 +2599,13 @@ class ITUNES(DriverBase): 'lib_book': library_books[book]} self._remove_from_iTunes(btr) else: - if DEBUG: + if self.verbose: logger().info(" '%s' found in iTunes, but not on iDevice" % (book)) def _remove_existing_copy(self, path, metadata): ''' ''' - if DEBUG: + if self.verbose: logger().info(" %s._remove_existing_copy()" % self.__class__.__name__) if self.manual_sync_mode: @@ -2613,7 +2620,7 @@ class ITUNES(DriverBase): self._remove_from_iTunes(self.cached_books[book]) break else: - if DEBUG: + if self.verbose: logger().info(" '%s' not in cached_books" % metadata.title) else: # Delete existing from Library|Books, add to self.update_list @@ -2623,22 +2630,22 @@ class ITUNES(DriverBase): (self.cached_books[book]['title'] == metadata.title and \ self.cached_books[book]['author'] == metadata.author)): self.update_list.append(self.cached_books[book]) - if DEBUG: + if self.verbose: logger().info(" deleting library book '%s'" % metadata.title) self._remove_from_iTunes(self.cached_books[book]) break else: - if DEBUG: + if self.verbose: logger().info(" '%s' not found in cached_books" % metadata.title) def _remove_from_device(self, cached_book): ''' Windows assumes pythoncom wrapper ''' - if DEBUG: + if self.verbose: logger().info(" %s._remove_from_device()" % self.__class__.__name__) if isosx: - if DEBUG: + if self.verbose: logger().info(" deleting '%s' from iDevice" % cached_book['title']) try: cached_book['dev_book'].delete() @@ -2647,11 +2654,11 @@ class ITUNES(DriverBase): elif iswindows: hit = self._find_device_book(cached_book) if hit: - if DEBUG: + if self.verbose: logger().info(" deleting '%s' from iDevice" % cached_book['title']) hit.Delete() else: - if DEBUG: + if self.verbose: logger().warning(" unable to remove '%s' by '%s' (%s) from device" % (cached_book['title'], cached_book['author'], cached_book['uuid'])) @@ -2659,14 +2666,14 @@ class ITUNES(DriverBase): ''' iTunes does not delete books from storage when removing from database via automation ''' - if DEBUG: + if self.verbose: logger().info(" %s._remove_from_iTunes():" % self.__class__.__name__) if isosx: ''' Manually remove the book from iTunes storage ''' try: fp = cached_book['lib_book'].location().path - if DEBUG: + if self.verbose: logger().info(" processing %s" % fp) if fp.startswith(prefs['library_path']): logger().info(" '%s' stored in calibre database, not removed" % cached_book['title']) @@ -2675,18 +2682,18 @@ class ITUNES(DriverBase): os.path.exists(fp): # Delete the copy in iTunes_local_storage os.remove(fp) - if DEBUG: + if self.verbose: logger()(" removing from iTunes_local_storage") else: # Delete from iTunes Media folder if os.path.exists(fp): os.remove(fp) - if DEBUG: + if self.verbose: logger().info(" deleting from iTunes storage") author_storage_path = os.path.split(fp)[0] try: os.rmdir(author_storage_path) - if DEBUG: + if self.verbose: logger().info(" removing empty author directory") except: author_files = os.listdir(author_storage_path) @@ -2694,24 +2701,24 @@ class ITUNES(DriverBase): author_files.pop(author_files.index('.DS_Store')) if not author_files: os.rmdir(author_storage_path) - if DEBUG: + if self.verbose: logger().info(" removing empty author directory") else: logger().info(" '%s' does not exist at storage location" % cached_book['title']) except: # We get here if there was an error with .location().path - if DEBUG: + if self.verbose: logger().info(" '%s' by %s not found in iTunes storage" % (cached_book['title'], cached_book['author'])) # Delete the book from the iTunes database try: self.iTunes.delete(cached_book['lib_book']) - if DEBUG: + if self.verbose: logger().info(" removing from iTunes database") except: - if DEBUG: + if self.verbose: logger().info(" unable to remove from iTunes database") elif iswindows: @@ -2729,7 +2736,7 @@ class ITUNES(DriverBase): fp = book.Location if book: - if DEBUG: + if self.verbose: logger().info(" processing %s" % fp) if fp.startswith(prefs['library_path']): logger().info(" '%s' stored in calibre database, not removed" % cached_book['title']) @@ -2738,34 +2745,34 @@ class ITUNES(DriverBase): os.path.exists(fp): # Delete the copy in iTunes_local_storage os.remove(fp) - if DEBUG: + if self.verbose: logger()(" removing from iTunes_local_storage") else: # Delete from iTunes Media folder if os.path.exists(fp): os.remove(fp) - if DEBUG: + if self.verbose: logger().info(" deleting from iTunes storage") author_storage_path = os.path.split(fp)[0] try: os.rmdir(author_storage_path) - if DEBUG: + if self.verbose: logger().info(" removing empty author directory") except: pass else: logger().info(" '%s' does not exist at storage location" % cached_book['title']) else: - if DEBUG: + if self.verbose: logger().info(" '%s' not found in iTunes storage" % cached_book['title']) # Delete the book from the iTunes database try: book.Delete() - if DEBUG: + if self.verbose: logger().info(" removing from iTunes database") except: - if DEBUG: + if self.verbose: logger().info(" unable to remove from iTunes database") def title_sorter(self, title): @@ -2777,7 +2784,7 @@ class ITUNES(DriverBase): from calibre.ebooks.metadata.epub import set_metadata from lxml import etree - if DEBUG: + if self.verbose: logger().info(" %s._update_epub_metadata()" % self.__class__.__name__) # Fetch plugboard updates @@ -2805,16 +2812,16 @@ class ITUNES(DriverBase): old_ts = parse_date(timestamp) metadata.timestamp = datetime.datetime(old_ts.year, old_ts.month, old_ts.day, old_ts.hour, old_ts.minute, old_ts.second, old_ts.microsecond + 1, old_ts.tzinfo) - if DEBUG: + if self.verbose: logger().info(" existing timestamp: %s" % metadata.timestamp) else: metadata.timestamp = now() - if DEBUG: + if self.verbose: logger().info(" add timestamp: %s" % metadata.timestamp) else: metadata.timestamp = now() - if DEBUG: + if self.verbose: logger().warning(" missing block in OPF file") logger().info(" add timestamp: %s" % metadata.timestamp) @@ -2845,7 +2852,7 @@ class ITUNES(DriverBase): ''' Trigger a sync, wait for completion ''' - if DEBUG: + if self.verbose: logger().info(" %s:_update_device():\n %s" % (self.__class__.__name__, msg)) if isosx: @@ -2853,11 +2860,11 @@ class ITUNES(DriverBase): if wait: # This works if iTunes has books not yet synced to iPad. - if DEBUG: + if self.verbose: sys.stdout.write(" waiting for iPad sync to complete ...") sys.stdout.flush() while len(self._get_device_books()) != (len(self._get_library_books()) + len(self._get_purchased_book_ids())): - if DEBUG: + if self.verbose: sys.stdout.write('.') sys.stdout.flush() time.sleep(2) @@ -2870,7 +2877,7 @@ class ITUNES(DriverBase): self.iTunes = win32com.client.Dispatch("iTunes.Application") self.iTunes.UpdateIPod() if wait: - if DEBUG: + if self.verbose: sys.stdout.write(" waiting for iPad sync to complete ...") sys.stdout.flush() while True: @@ -2878,7 +2885,7 @@ class ITUNES(DriverBase): lb_count = len(self._get_library_books()) pb_count = len(self._get_purchased_book_ids()) if db_count != lb_count + pb_count: - if DEBUG: + if self.verbose: #sys.stdout.write(' %d != %d + %d\n' % (db_count,lb_count,pb_count)) sys.stdout.write('.') sys.stdout.flush() @@ -2893,7 +2900,7 @@ class ITUNES(DriverBase): def _update_iTunes_metadata(self, metadata, db_added, lb_added, this_book): ''' ''' - if DEBUG: + if self.verbose: logger().info(" %s._update_iTunes_metadata()" % self.__class__.__name__) STRIP_TAGS = re.compile(r'<[^<]*?/?>') @@ -2945,7 +2952,7 @@ class ITUNES(DriverBase): # Otherwise iTunes grabs the first dc:subject from the opf metadata # If title_sort applied in plugboard, that overrides using series/index as title_sort if metadata_x.series and self.settings().extra_customization[self.USE_SERIES_AS_CATEGORY]: - if DEBUG: + if self.verbose: logger().info(" %s._update_iTunes_metadata()" % self.__class__.__name__) logger().info(" using Series name '%s' as Genre" % metadata_x.series) @@ -2989,7 +2996,7 @@ class ITUNES(DriverBase): break elif metadata_x.tags is not None: - if DEBUG: + if self.verbose: logger().info(" %susing Tag as Genre" % "no Series name available, " if self.settings().extra_customization[self.USE_SERIES_AS_CATEGORY] else '') for tag in metadata_x.tags: @@ -3039,7 +3046,7 @@ class ITUNES(DriverBase): if db_added: db_added.AlbumRating = (metadata_x.rating * 10) except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " setting AlbumRating on iDevice") @@ -3048,7 +3055,7 @@ class ITUNES(DriverBase): # iTunes balks on setting EpisodeNumber, but it sticks (9.1.1.12) if metadata_x.series and self.settings().extra_customization[self.USE_SERIES_AS_CATEGORY]: - if DEBUG: + if self.verbose: logger().info(" using Series name as Genre") # Format the index as a sort key index = metadata_x.series_index @@ -3064,13 +3071,13 @@ class ITUNES(DriverBase): try: lb_added.TrackNumber = metadata_x.series_index except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " setting TrackNumber in iTunes") try: lb_added.EpisodeNumber = metadata_x.series_index except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " setting EpisodeNumber in iTunes") @@ -3092,13 +3099,13 @@ class ITUNES(DriverBase): try: db_added.TrackNumber = metadata_x.series_index except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " setting TrackNumber on iDevice") try: db_added.EpisodeNumber = metadata_x.series_index except: - if DEBUG: + if self.verbose: logger().warning(" iTunes automation interface reported an error" " setting EpisodeNumber on iDevice") @@ -3112,7 +3119,7 @@ class ITUNES(DriverBase): break elif metadata_x.tags is not None: - if DEBUG: + if self.verbose: logger().info(" using Tag as Genre") for tag in metadata_x.tags: if self._is_alpha(tag[0]): @@ -3126,7 +3133,7 @@ class ITUNES(DriverBase): ''' Ensure iDevice metadata is writable. DC mode only ''' - if DEBUG: + if self.verbose: logger().info(" %s._wait_for_writable_metadata()" % self.__class__.__name__) attempts = 9 @@ -3140,16 +3147,16 @@ class ITUNES(DriverBase): except: attempts -= 1 time.sleep(delay) - if DEBUG: + if self.verbose: logger().warning(" waiting %.1f seconds for iDevice metadata to become writable (attempt #%d)" % (delay, (10 - attempts))) else: - if DEBUG: + if self.verbose: logger().error(" failed to write device metadata") def _xform_metadata_via_plugboard(self, book, format): ''' Transform book metadata from plugboard templates ''' - if DEBUG: + if self.verbose: logger().info(" %s._xform_metadata_via_plugboard()" % self.__class__.__name__) if self.plugboard_func: @@ -3173,7 +3180,7 @@ class ITUNES(DriverBase): logger().info(" tags: %s %s" % (book.tags, ">>> %s" % newmi.tags if book.tags != newmi.tags else '')) else: - if DEBUG: + if self.verbose: logger()(" matching plugboard not found") else: @@ -3197,8 +3204,9 @@ class ITUNES_ASYNC(ITUNES): connected = False def __init__(self, path): - if DEBUG: - logger().info("%s.__init__()" % self.__class__.__name__) + self.verbose = self.settings().extra_customization[3] + if self.verbose: + logger().info("%s.__init__():" % self.__class__.__name__) try: import appscript @@ -3247,7 +3255,7 @@ class ITUNES_ASYNC(ITUNES): """ if not oncard: - if DEBUG: + if self.verbose: logger().info("%s.books()" % self.__class__.__name__) if self.settings().extra_customization[self.CACHE_COVERS]: logger().info(" Cover fetching/caching enabled") @@ -3296,7 +3304,7 @@ class ITUNES_ASYNC(ITUNES): } if self.report_progress is not None: - self.report_progress((i + 1) / book_count, + self.report_progress(float((i + 1)*100 / book_count)/100, _('%(num)d of %(tot)d') % dict(num=i + 1, tot=book_count)) elif iswindows: @@ -3338,7 +3346,7 @@ class ITUNES_ASYNC(ITUNES): } if self.report_progress is not None: - self.report_progress((i + 1) / book_count, + self.report_progress(float((i + 1)*100 / book_count)/100, _('%(num)d of %(tot)d') % dict(num=i + 1, tot=book_count)) @@ -3348,7 +3356,7 @@ class ITUNES_ASYNC(ITUNES): if self.report_progress is not None: self.report_progress(1.0, _('finished')) self.cached_books = cached_books - if DEBUG: + if self.verbose: self._dump_booklist(booklist, 'returning from books()', indent=2) self._dump_cached_books('returning from books()', indent=2) return booklist @@ -3361,7 +3369,7 @@ class ITUNES_ASYNC(ITUNES): Un-mount / eject the device from the OS. This does not check if there are pending GUI jobs that need to communicate with the device. ''' - if DEBUG: + if self.verbose: logger().info("%s.eject()" % self.__class__.__name__) self.iTunes = None self.connected = False @@ -3376,7 +3384,7 @@ class ITUNES_ASYNC(ITUNES): @return: A 3 element list with free space in bytes of (1, 2, 3). If a particular device doesn't have any of these locations it should return -1. """ - if DEBUG: + if self.verbose: logger().info("%s.free_space()" % self.__class__.__name__) free_space = 0 if isosx: @@ -3393,7 +3401,7 @@ class ITUNES_ASYNC(ITUNES): Ask device for device information. See L{DeviceInfoQuery}. @return: (device name, device version, software version on device, mime type) """ - if DEBUG: + if self.verbose: logger().info("%s.get_device_information()" % self.__class__.__name__) return ('iTunes', 'hw v1.0', 'sw v1.0', 'mime type normally goes here') @@ -3419,13 +3427,13 @@ class ITUNES_ASYNC(ITUNES): if self.iTunes is None: raise OpenFeedback(self.ITUNES_SANDBOX_LOCKOUT_MESSAGE) - if DEBUG: + if self.verbose: logger().info("%s.open(connected_device: %s)" % (self.__class__.__name__, repr(connected_device))) # Confirm/create thumbs archive if not os.path.exists(self.cache_dir): - if DEBUG: + if self.verbose: logger().info(" creating thumb cache '%s'" % self.cache_dir) os.makedirs(self.cache_dir) @@ -3435,18 +3443,18 @@ class ITUNES_ASYNC(ITUNES): zfw.writestr("iTunes Thumbs Archive", '') zfw.close() else: - if DEBUG: + if self.verbose: logger().info(" existing thumb cache at '%s'" % self.archive_path) # If enabled in config options, create/confirm an iTunes storage folder if not self.settings().extra_customization[self.USE_ITUNES_STORAGE]: self.iTunes_local_storage = os.path.join(config_dir, 'iTunes storage') if not os.path.exists(self.iTunes_local_storage): - if DEBUG: + if self.verbose: logger()(" creating iTunes_local_storage at '%s'" % self.iTunes_local_storage) os.mkdir(self.iTunes_local_storage) else: - if DEBUG: + if self.verbose: logger()(" existing iTunes_local_storage at '%s'" % self.iTunes_local_storage) def sync_booklists(self, booklists, end_session=True): @@ -3457,7 +3465,7 @@ class ITUNES_ASYNC(ITUNES): L{books}(oncard='cardb')). ''' - if DEBUG: + if self.verbose: logger().info("%s.sync_booklists()" % self.__class__.__name__) # Inform user of any problem books @@ -3471,7 +3479,7 @@ class ITUNES_ASYNC(ITUNES): def unmount_device(self): ''' ''' - if DEBUG: + if self.verbose: logger().info("%s.unmount_device()" % self.__class__.__name__) self.connected = False diff --git a/src/calibre/devices/idevice/libimobiledevice.py b/src/calibre/devices/idevice/libimobiledevice.py index f293ef89a6..5256e70215 100644 --- a/src/calibre/devices/idevice/libimobiledevice.py +++ b/src/calibre/devices/idevice/libimobiledevice.py @@ -18,8 +18,284 @@ from datetime import datetime from calibre.constants import DEBUG, islinux, isosx, iswindows from calibre.devices.usbms.driver import debug_print -from calibre_plugins.marvin.parse_xml import XmlPropertyListParser + #from calibre.devices.idevice.parse_xml import XmlPropertyListParser +# *** Temporarily here until added to the code tree + +class PropertyListParseError(Exception): + """Raised when parsing a property list is failed.""" + pass + +class XmlPropertyListParser(object): + """ + The ``XmlPropertyListParser`` class provides methods that + convert `Property Lists`_ objects from xml format. + Property list objects include ``string``, ``unicode``, + ``list``, ``dict``, ``datetime``, and ``int`` or ``float``. + + :copyright: 2008 by Takanori Ishikawa + :license: MIT License + + .. _Property List: http://developer.apple.com/documentation/Cocoa/Conceptual/PropertyLists/ + """ + + def _assert(self, test, message): + if not test: + raise PropertyListParseError(message) + + # ------------------------------------------------ + # SAX2: ContentHandler + # ------------------------------------------------ + def setDocumentLocator(self, locator): + pass + def startPrefixMapping(self, prefix, uri): + pass + def endPrefixMapping(self, prefix): + pass + def startElementNS(self, name, qname, attrs): + pass + def endElementNS(self, name, qname): + pass + def ignorableWhitespace(self, whitespace): + pass + def processingInstruction(self, target, data): + pass + def skippedEntity(self, name): + pass + + def startDocument(self): + self.__stack = [] + self.__plist = self.__key = self.__characters = None + # For reducing runtime type checking, + # the parser caches top level object type. + self.__in_dict = False + + def endDocument(self): + self._assert(self.__plist is not None, "A top level element must be .") + self._assert( + len(self.__stack) is 0, + "multiple objects at top level.") + + def startElement(self, name, attributes): + if name in XmlPropertyListParser.START_CALLBACKS: + XmlPropertyListParser.START_CALLBACKS[name](self, name, attributes) + if name in XmlPropertyListParser.PARSE_CALLBACKS: + self.__characters = [] + + def endElement(self, name): + if name in XmlPropertyListParser.END_CALLBACKS: + XmlPropertyListParser.END_CALLBACKS[name](self, name) + if name in XmlPropertyListParser.PARSE_CALLBACKS: + # Creates character string from buffered characters. + content = ''.join(self.__characters) + # For compatibility with ``xml.etree`` and ``plistlib``, + # convert text string to ascii, if possible + try: + content = content.encode('ascii') + except (UnicodeError, AttributeError): + pass + XmlPropertyListParser.PARSE_CALLBACKS[name](self, name, content) + self.__characters = None + + def characters(self, content): + if self.__characters is not None: + self.__characters.append(content) + + # ------------------------------------------------ + # XmlPropertyListParser private + # ------------------------------------------------ + def _push_value(self, value): + if not self.__stack: + self._assert(self.__plist is None, "Multiple objects at top level") + self.__plist = value + else: + top = self.__stack[-1] + #assert isinstance(top, (dict, list)) + if self.__in_dict: + k = self.__key + if k is None: + raise PropertyListParseError("Missing key for dictionary.") + top[k] = value + self.__key = None + else: + top.append(value) + + def _push_stack(self, value): + self.__stack.append(value) + self.__in_dict = isinstance(value, dict) + + def _pop_stack(self): + self.__stack.pop() + self.__in_dict = self.__stack and isinstance(self.__stack[-1], dict) + + def _start_plist(self, name, attrs): + self._assert(not self.__stack and self.__plist is None, " more than once.") + self._assert(attrs.get('version', '1.0') == '1.0', + "version 1.0 is only supported, but was '%s'." % attrs.get('version')) + + def _start_array(self, name, attrs): + v = list() + self._push_value(v) + self._push_stack(v) + + def _start_dict(self, name, attrs): + v = dict() + self._push_value(v) + self._push_stack(v) + + def _end_array(self, name): + self._pop_stack() + + def _end_dict(self, name): + if self.__key is not None: + raise PropertyListParseError("Missing value for key '%s'" % self.__key) + self._pop_stack() + + def _start_true(self, name, attrs): + self._push_value(True) + + def _start_false(self, name, attrs): + self._push_value(False) + + def _parse_key(self, name, content): + if not self.__in_dict: + print("XmlPropertyListParser() WARNING: ignoring %s ( elements must be contained in element)" % content) + #raise PropertyListParseError(" element '%s' must be in element." % content) + else: + self.__key = content + + def _parse_string(self, name, content): + self._push_value(content) + + def _parse_data(self, name, content): + import base64 + self._push_value(base64.b64decode(content)) + + # http://www.apple.com/DTDs/PropertyList-1.0.dtd says: + # + # Contents should conform to a subset of ISO 8601 + # (in particular, YYYY '-' MM '-' DD 'T' HH ':' MM ':' SS 'Z'. + # Smaller units may be omitted with a loss of precision) + import re + DATETIME_PATTERN = re.compile(r"(?P\d\d\d\d)(?:-(?P\d\d)(?:-(?P\d\d)(?:T(?P\d\d)(?::(?P\d\d)(?::(?P\d\d))?)?)?)?)?Z$") + + def _parse_date(self, name, content): + import datetime + + units = ('year', 'month', 'day', 'hour', 'minute', 'second', ) + pattern = XmlPropertyListParser.DATETIME_PATTERN + match = pattern.match(content) + if not match: + raise PropertyListParseError("Failed to parse datetime '%s'" % content) + + groups, components = match.groupdict(), [] + for key in units: + value = groups[key] + if value is None: + break + components.append(int(value)) + while len(components) < 3: + components.append(1) + + d = datetime.datetime(*components) + self._push_value(d) + + def _parse_real(self, name, content): + self._push_value(float(content)) + + def _parse_integer(self, name, content): + self._push_value(int(content)) + + START_CALLBACKS = { + 'plist': _start_plist, + 'array': _start_array, + 'dict': _start_dict, + 'true': _start_true, + 'false': _start_false, + } + + END_CALLBACKS = { + 'array': _end_array, + 'dict': _end_dict, + } + + PARSE_CALLBACKS = { + 'key': _parse_key, + 'string': _parse_string, + 'data': _parse_data, + 'date': _parse_date, + 'real': _parse_real, + 'integer': _parse_integer, + } + + # ------------------------------------------------ + # XmlPropertyListParser + # ------------------------------------------------ + def _to_stream(self, io_or_string): + if isinstance(io_or_string, basestring): + # Creates a string stream for in-memory contents. + from cStringIO import StringIO + return StringIO(io_or_string) + elif hasattr(io_or_string, 'read') and callable(getattr(io_or_string, 'read')): + return io_or_string + else: + raise TypeError('Can\'t convert %s to file-like-object' % type(io_or_string)) + + def _parse_using_etree(self, xml_input): + from xml.etree.cElementTree import iterparse + + parser = iterparse(self._to_stream(xml_input), events=('start', 'end')) + self.startDocument() + try: + for action, element in parser: + name = element.tag + if action == 'start': + if name in XmlPropertyListParser.START_CALLBACKS: + XmlPropertyListParser.START_CALLBACKS[name](self, element.tag, element.attrib) + elif action == 'end': + if name in XmlPropertyListParser.END_CALLBACKS: + XmlPropertyListParser.END_CALLBACKS[name](self, name) + if name in XmlPropertyListParser.PARSE_CALLBACKS: + XmlPropertyListParser.PARSE_CALLBACKS[name](self, name, element.text or "") + element.clear() + except SyntaxError, e: + raise PropertyListParseError(e) + + self.endDocument() + return self.__plist + + def _parse_using_sax_parser(self, xml_input): + from xml.sax import make_parser, handler, xmlreader, \ + SAXParseException + source = xmlreader.InputSource() + source.setByteStream(self._to_stream(xml_input)) + reader = make_parser() + reader.setContentHandler(self) + try: + reader.parse(source) + except SAXParseException, e: + raise PropertyListParseError(e) + + return self.__plist + + def parse(self, xml_input): + """ + Parse the property list (`.plist`, `.xml, for example) ``xml_input``, + which can be either a string or a file-like object. + + >>> parser = XmlPropertyListParser() + >>> parser.parse(r'' + ... r'Python.py' + ... r'') + {'Python': '.py'} + """ + try: + return self._parse_using_etree(xml_input) + except ImportError: + # No xml.etree.ccElementTree found. + return self._parse_using_sax_parser(xml_input) + +# *** End temporary addition class libiMobileDeviceException(Exception): def __init__(self, value): @@ -313,6 +589,28 @@ class libiMobileDevice(): #self.lib.idevice_device_list_free() return device_list + def get_folder_size(self, path): + ''' + Recursively descend through a dir to add all file sizes in folder + ''' + def _calculate_folder_size(path, initial_folder_size): + ''' + Recursively calculate folder size + ''' + this_dir = self._afc_read_directory(path) + folder_size = 0 + for item in this_dir: + folder_size += int(this_dir[item]['st_size']) + if this_dir[item]['st_ifmt'] == 'S_IFDIR': + new_path = '/'.join([path, item]) + initial_folder_size += _calculate_folder_size(new_path, folder_size) + return folder_size + initial_folder_size + + self._log_location(path) + stats = self.stat(path) + cumulative_folder_size = _calculate_folder_size(path, int(stats['st_size'])) + return cumulative_folder_size + def get_installed_apps(self, applist): ''' Generate a sorted dict of installed apps from applist @@ -340,7 +638,7 @@ class libiMobileDevice(): given by path. ''' self._log_location("'%s'" % path) - return self._afc_read_directory(path).keys() + return self._afc_read_directory(path) def load_library(self): if islinux: @@ -1504,6 +1802,51 @@ class libiMobileDevice(): self.log(" device_name: %s" % device_name) return device_name + def _lockdown_get_value(self): + ''' + Retrieves a preferences plist using an optional domain and/or key name. + + Args: + client: (LOCKDOWND_CLIENT_T) An initialized lockdown client + domain: (const char *) The domain to query on or NULL for global domain + key: (const char *) The key name to request or NULL to query for all keys + value: (PLIST_T *) A plist node representing the result value code + + Return: + error: LOCKDOWN_E_SUCCESS on success, + NP_E_INVALID_ARG when client is NULL + ''' + self._log_location() + + preferences = c_char_p() + profiles_preferences = ['SerialNumber', 'ModelNumber', 'DeviceColor', 'ProductType', + 'TimeZone', 'DeviceName', 'UniqueDeviceID', 'TimeZoneOffsetFromUTC', + 'DeviceClass', 'HardwareModel', 'TimeIntervalSince1970', + 'FirmwareVersion', 'PasswordProtected', 'ProductVersion'] + preferences_dict = {} + + error = self.lib.lockdownd_get_value(byref(self.control), + None, + None, + byref(preferences)) & 0xFFFF + if error: + error_description = self.LIB_ERROR_TEMPLATE.format( + cls=self.__class__.__name__, + func=sys._getframe().f_code.co_name, + desc=self._lockdown_error(error)) + raise libiMobileDeviceException(error_description) + else: + xml = POINTER(c_char_p)() + xml_len = c_uint(0) + self.plist_lib.plist_to_xml(c_char_p.from_buffer(preferences), byref(xml), byref(xml_len)) + preferences_list = XmlPropertyListParser().parse(string_at(xml, xml_len.value)) + for pref in sorted(profiles_preferences): + #self.log(" {0:21}: {1}".format(pref, preferences_list[pref])) + preferences_dict[pref] = preferences_list[pref] + + self.plist_lib.plist_free(preferences) + return preferences_dict + def _lockdown_goodbye(self): ''' Sends a Goodbye request lockdownd, signaling the end of communication