Fixed download-size issues. Also no longer truncating files.

Fixes dsoprea#111.
Fixes dsoprea#116.

Author: dsoprea

gdrivefs/gdfs/opened_file.py

@@ -301,7 +301,7 @@ def __load_base_from_remote(self):
                 _logger.exception("There was an export-format error.")
                 raise fuse.FuseOSError(ENOENT)
 
-            self.__fh = open(self.__temp_filepath, 'w+')
+            self.__fh = open(self.__temp_filepath, 'r+')
 
             self.__is_dirty = False
             self.__is_loaded = True
@@ -370,7 +370,7 @@ def flush(self):
     @dec_hint(['offset', 'length'], prefix='OF')
     def read(self, offset, length):
 
-        _logger.debug("Checking write-cache file (flush).")
+        _logger.debug("Reading (%d) bytes at offset (%d).", length, offset)
 
         # We don't care if the cache file is dirty (not on this system, at 
         # least).
@@ -380,8 +380,14 @@ def read(self, offset, length):
         self.__fh.seek(offset)
         data = self.__fh.read(length)
 
+        len_ = len(data)
+
         _logger.debug("(%d) bytes retrieved from slice (%d):(%d)/(%d).",
-                      len(data), offset, length, st.st_size)
+                      len_, offset, length, st.st_size)
+
+        if len_ != length:
+            _logger.warning("Read request is only returning (%d) bytes when "
+                            "(%d) bytes were requested.", len_, length)
 
         return data
 

gdrivefs/gdtool/chunked_download.py

@@ -70,7 +70,7 @@ def next_chunk(self, num_retries=0):
 
         for retry_num in xrange(num_retries + 1):
             _logger.debug("Attempting to read chunk. ATTEMPT=(%d)/(%d)", 
-                          retry_num, num_retries)
+                          retry_num + 1, num_retries + 1)
 
             if retry_num > 0:
                 self._sleep(self._rand() * 2**retry_num)
@@ -79,36 +79,57 @@ def next_chunk(self, num_retries=0):
                                 retry_num, self._uri, resp.status)
 
             resp, content = self._http.request(self._uri, headers=headers)
-            _logger.debug("Chunk status: (%d)", resp.status)
             if resp.status < 500:
                 break
 
-        if resp.status in [200, 206]:
-            if 'content-location' in resp and resp['content-location'] != self._uri:
-                self._uri = resp['content-location']
+        _logger.debug("Received chunk of size (%d).", len(content))
 
-            self._progress += len(content)
+        if resp.status in [200, 206]:
+            try:
+                if resp['content-location'] != self._uri:
+                    self._uri = resp['content-location']
+            except KeyError:
+                pass
+
+            received_size_b = len(content)
+            self._progress += received_size_b
             self._fd.write(content)
 
-            # This method doesn't seem documented, but we've seen cases where 
-            # this is available, but "content-range" isn't.
-            if 'content-length' in resp:
-                self._total_size = int(resp['content-length'])
-
-                _logger.debug("Received download size (content-length): "
-                              "(%d)", self._total_size)
-
-            # This might be legacy (or at least not provided for zero-length 
-            # files).
-            elif 'content-range' in resp and self._total_size is None:
-                content_range = resp['content-range']
-                length = content_range.rsplit('/', 1)[1]
-                length = int(length)
-
-                self._total_size = length
+            # This seems to be the most correct method to get the filesize, but 
+            # we've seen it not exist.
+            if 'content-range' in resp:
+                if self._total_size is None:
+                    content_range = resp['content-range']
+                    length = content_range.rsplit('/', 1)[1]
+                    length = int(length)
+
+                    self._total_size = length
+
+                    _logger.debug("Received download size (content-range): "
+                                  "(%d)", self._total_size)
+
+            # There's a chance that "content-range" will be omitted for zero-
+            # length files (or maybe files that are complete within the first 
+            # chunk).
+
+            else:
+# TODO(dustin): Is this a valid assumption, or should it be an error?
+                _logger.warning("No 'content-range' found in response. "
+                                "Assuming that we've received all data.")
+
+                self._total_size = received_size_b
+
+# TODO(dustin): We were using this for a while, but it appears to be no larger 
+#               then a single chunk.
+#
+#            # This method doesn't seem documented, but we've seen cases where 
+#            # this is available, but "content-range" isn't.
+#            if 'content-length' in resp:
+#                self._total_size = int(resp['content-length'])
+#
+#                _logger.debug("Received download size (content-length): "
+#                              "(%d)", self._total_size)
 
-                _logger.debug("Received download size (content-range): "
-                              "(%d)", self._total_size)
 
             assert self._total_size is not None, \
                    "File-size was not provided."

gdrivefs/gdtool/drive.py

@@ -204,9 +204,6 @@ def list_changes(self, start_change_id=None, page_token=None):
         back. Change-IDs are integers, but are not necessarily sequential.
         """
 
-        _logger.debug("Listing changes starting at ID [%s] with page_token "
-                      "[%s].", start_change_id, page_token)
-
         client = self.__auth.get_client()
 
         response = client.changes().list(
@@ -216,6 +213,10 @@ def list_changes(self, start_change_id=None, page_token=None):
         self.__assert_response_kind(response, 'drive#changeList')
 
         items = response[u'items']
+
+        if items:
+            _logger.debug("We received (%d) changes to apply.", len(items))
+
         largest_change_id = int(response[u'largestChangeId'])
         next_page_token = response.get(u'nextPageToken')
 
@@ -408,8 +409,8 @@ def download_to_local(self, output_file_path, normalized_entry, mime_type,
         the data has changed since any prior attempts.
         """
 
-        _logger.info("Downloading entry with ID [%s] and mime-type [%s].",
-                     normalized_entry.id, mime_type)
+        _logger.info("Downloading entry with ID [%s] and mime-type [%s] to "
+                     "[%s].", normalized_entry.id, mime_type, output_file_path)
 
         if mime_type != normalized_entry.mime_type and \
                 mime_type not in normalized_entry.download_links:
@@ -464,7 +465,6 @@ def download_to_local(self, output_file_path, normalized_entry, mime_type,
 
             while 1:
                 status, done, total_size = downloader.next_chunk()
-                
                 assert status.total_size is not None, \
                        "total_size is None"
 
@@ -492,6 +492,8 @@ def download_to_local(self, output_file_path, normalized_entry, mime_type,
                 if done is True:
                     break
 
+            _logger.debug("Download complete. Offset is: (%d)", f.tell())
+
         utime(output_file_path, (time.time(), gd_mtime_epoch))
 
         return (total_size, True)
@@ -548,9 +550,10 @@ def __insert_entry(self, is_file, filename, parents, mime_type,
             accessed_datetime = now_phrase 
 
         _logger.info("Creating entry with filename [%s] under parent(s) "
-                     "[%s] with mime-type [%s]. MTIME=[%s] ATIME=[%s]",
+                     "[%s] with mime-type [%s]. MTIME=[%s] ATIME=[%s] "
+                     "DATA_FILEPATH=[%s]",
                      filename, ', '.join(parents), mime_type, 
-                     modified_datetime, accessed_datetime)
+                     modified_datetime, accessed_datetime, data_filepath)
 
         client = self.__auth.get_client()