Merge pull request #303 from Duke-GCB/302-upload-progress-bar-speed-v2

Show speed in upload progress

Author: johnbradley

ddsc/core/download.py

@@ -7,7 +7,7 @@
 import queue
 from ddsc.core.localstore import HashUtil
 from ddsc.core.ddsapi import DDS_TOTAL_HEADER
-from ddsc.core.util import humanize_bytes
+from ddsc.core.util import humanize_bytes, transfer_speed_str
 
 SWIFT_EXPIRED_STATUS_CODE = 401
 S3_EXPIRED_STATUS_CODE = 403
@@ -324,11 +324,11 @@ def make_spinner_char(self, current_time):
         return self.spinner_chars[half_seconds % 4]
 
     def make_download_speed(self, current_time, total_bytes_downloaded):
-        elapsed_seconds = current_time - self.start_time
-        if elapsed_seconds > 0 and total_bytes_downloaded > 0:
-            bytes_per_second = float(total_bytes_downloaded) / (elapsed_seconds + 0.5)
-            return '@ {}/s'.format(humanize_bytes(bytes_per_second))
-        return ''
+        return transfer_speed_str(
+            current_time=current_time,
+            start_time=self.start_time,
+            transferred_bytes=total_bytes_downloaded
+        )
 
     def get_download_progress(self):
         files_downloaded = 0

ddsc/core/fileuploader.py

@@ -403,7 +403,7 @@ def send(self):
             while sent_chunks != self.num_chunks_to_send:
                 chunk = infile.read(self.chunk_size)
                 self._send_chunk(chunk, chunk_num)
-                self.progress_queue.processed(1)
+                self.progress_queue.processed((1, len(chunk)))
                 chunk_num += 1
                 sent_chunks += 1
 

ddsc/core/projectuploader.py

@@ -453,7 +453,7 @@ def after_run(self, remote_file_data):
             self.local_file.set_remote_values_after_send(remote_file_id,
                                                          remote_hash_dict['algorithm'],
                                                          remote_hash_dict['value'])
-            self.settings.watcher.transferring_item(self.local_file)
+            self.settings.watcher.transferring_item(self.local_file, transferred_bytes=self.local_file.size)
         else:
             self.settings.watcher.increment_progress()
 

ddsc/core/tests/test_projectuploader.py

@@ -373,4 +373,4 @@ def test_after_run_when_file_is_sent(self):
         cmd.after_run(remote_file_data)
         cmd.file_upload_post_processor.run.assert_called_with(cmd.settings.data_service, remote_file_data)
         cmd.local_file.set_remote_values_after_send.assert_called_with('abc123', 'md5', 'abcdefg')
-        cmd.settings.watcher.transferring_item.assert_called_with(cmd.local_file)
+        cmd.settings.watcher.transferring_item.assert_called_with(cmd.local_file, transferred_bytes=cmd.local_file.size)

ddsc/core/tests/test_util.py

@@ -26,66 +26,70 @@ def test_verify_terminal_encoding_none_is_ok(self):
 
 class TestProgressBar(TestCase):
     @patch('ddsc.core.util.sys.stdout')
-    def test_show_no_waiting(self, mock_stdout):
+    @patch('ddsc.core.util.transfer_speed_str')
+    def test_show_no_waiting(self, mock_transfer_speed_str, mock_stdout):
         progress_bar = ProgressBar()
+        mock_transfer_speed_str.return_value = ' @ 100 MB/s'
 
         # replace line with our progress
-        progress_bar.update(percent_done=0, details='sending really_long_filename.txt')
+        progress_bar.update(percent_done=0, details='sending really_long_filename.txt', transferred_bytes=0)
         progress_bar.show()
-        expected = '\rProgress: 0% - sending really_long_filename.txt'
+        expected = '\rProgress: 0% @ 100 MB/s - sending really_long_filename.txt'
         mock_stdout.write.assert_called_with(expected)
 
         # replace line with our progress (make sure it is long enough to blank out previous line)
-        progress_bar.update(percent_done=10, details='sending short.txt')
+        progress_bar.update(percent_done=10, details='sending short.txt', transferred_bytes=100)
         progress_bar.show()
-        expected = '\rProgress: 10% - sending short.txt              '
+        expected = '\rProgress: 10% @ 100 MB/s - sending short.txt              '
         mock_stdout.write.assert_called_with(expected)
 
-        progress_bar.update(percent_done=15, details='sending short.txt')
+        progress_bar.update(percent_done=15, details='sending short.txt', transferred_bytes=50)
         progress_bar.show()
-        expected = '\rProgress: 15% - sending short.txt              '
+        expected = '\rProgress: 15% @ 100 MB/s - sending short.txt              '
         mock_stdout.write.assert_called_with(expected)
 
         # we finish uploading(go to newline)
         progress_bar.set_state(ProgressBar.STATE_DONE)
         progress_bar.show()
-        expected = '\rDone: 100%                                     \n'
+        expected = '\rDone: 100% @ 100 MB/s                                     \n'
         mock_stdout.write.assert_called_with(expected)
 
     @patch('ddsc.core.util.sys.stdout')
-    def test_show_with_waiting(self, mock_stdout):
+    @patch('ddsc.core.util.transfer_speed_str')
+    def test_show_with_waiting(self, mock_transfer_speed_str, mock_stdout):
         progress_bar = ProgressBar()
+        mock_transfer_speed_str.return_value = ' @ 100 MB/s'
 
         # we make some progress
-        progress_bar.update(percent_done=10, details='sending short.txt')
+        progress_bar.update(percent_done=10, details='sending short.txt', transferred_bytes=100)
         progress_bar.show()
-        expected = '\rProgress: 10% - sending short.txt'
+        expected = '\rProgress: 10% @ 100 MB/s - sending short.txt'
         mock_stdout.write.assert_called_with(expected)
 
         # we get stuck waiting
         progress_bar.wait_msg = "Waiting for project"
         progress_bar.set_state(ProgressBar.STATE_WAITING)
         progress_bar.show()
-        expected = '\rProgress: 10% - Waiting for project'
+        expected = '\rProgress: 10% @ 100 MB/s - Waiting for project'
         mock_stdout.write.assert_called_with(expected)
 
         # waiting takes priority over progress updates
         # (we may be able to upload some folders while waiting to upload files)
-        progress_bar.update(percent_done=15, details='sending short.txt')
+        progress_bar.update(percent_done=15, details='sending short.txt', transferred_bytes=50)
         progress_bar.show()
-        expected = '\rProgress: 15% - Waiting for project'
+        expected = '\rProgress: 15% @ 100 MB/s - Waiting for project'
         mock_stdout.write.assert_called_with(expected)
 
         # we are not longer waiting
         progress_bar.set_state(ProgressBar.STATE_RUNNING)
         progress_bar.show()
-        expected = '\rProgress: 15% - sending short.txt  '
+        expected = '\rProgress: 15% @ 100 MB/s - sending short.txt  '
         mock_stdout.write.assert_called_with(expected)
 
         # we finish uploading(go to newline)
         progress_bar.set_state(ProgressBar.STATE_DONE)
         progress_bar.show()
-        expected = '\rDone: 100%                         \n'
+        expected = '\rDone: 100% @ 100 MB/s                         \n'
         mock_stdout.write.assert_called_with(expected)
 
     @patch('ddsc.core.util.sys.stdout')
@@ -111,20 +115,20 @@ def test_show_waiting(self, mock_stdout):
 
 class TestProgressPrinter(TestCase):
     @patch('ddsc.core.util.ProgressBar')
-    def test_stuff(self, mock_progress_bar):
+    def test_general_functionality(self, mock_progress_bar):
         progress_printer = ProgressPrinter(total=10, msg_verb='sending')
 
         # pretend we just created a project
         mock_project = Mock(kind=KindType.project_str, path='')
-        progress_printer.transferring_item(item=mock_project, increment_amt=1)
-        mock_progress_bar.return_value.update.assert_called_with(10, 'sending project')
+        progress_printer.transferring_item(item=mock_project, increment_amt=1, transferred_bytes=100)
+        mock_progress_bar.return_value.update.assert_called_with(10, 100, 'sending project')
         mock_progress_bar.return_value.show.assert_called()
         mock_progress_bar.reset_mock()
 
         # pretend we just created a folder
         mock_project = Mock(kind=KindType.folder_str, path='/data')
-        progress_printer.transferring_item(item=mock_project, increment_amt=2)
-        mock_progress_bar.return_value.update.assert_called_with(30, 'sending data')
+        progress_printer.transferring_item(item=mock_project, increment_amt=2, transferred_bytes=200)
+        mock_progress_bar.return_value.update.assert_called_with(30, 300, 'sending data')
         mock_progress_bar.return_value.show.assert_called()
         mock_progress_bar.reset_mock()
 
@@ -141,7 +145,7 @@ def test_stuff(self, mock_progress_bar):
         # pretend we uploaded a file
         mock_project = Mock(kind=KindType.file_str, path='/data/log.txt')
         progress_printer.transferring_item(item=mock_project, increment_amt=2)
-        mock_progress_bar.return_value.update.assert_called_with(50, 'sending log.txt')
+        mock_progress_bar.return_value.update.assert_called_with(50, 300, 'sending log.txt')
         mock_progress_bar.return_value.show.assert_called()
         mock_progress_bar.reset_mock()
 
@@ -181,10 +185,10 @@ def test_transferring_item_override_msg_verb(self, mock_os, mock_progress_bar):
         mock_os.path.basename.return_value = 'somefile.txt'
         progress_printer = ProgressPrinter(total=10, msg_verb='sending')
         progress_printer.transferring_item(Mock(), increment_amt=0)
-        progress_bar.update.assert_called_with(0, "sending somefile.txt")
+        progress_bar.update.assert_called_with(0, 0, "sending somefile.txt")
         progress_bar.reset_mock()
         progress_printer.transferring_item(Mock(), increment_amt=0, override_msg_verb='checking')
-        progress_bar.update.assert_called_with(0, "checking somefile.txt")
+        progress_bar.update.assert_called_with(0, 0, "checking somefile.txt")
 
     def test_increment_progress(self):
         progress_printer = ProgressPrinter(total=10, msg_verb='sending')

ddsc/core/util.py

@@ -2,6 +2,7 @@
 import os
 import platform
 import stat
+import time
 
 TERMINAL_ENCODING_NOT_UTF_ERROR = """
 ERROR: DukeDSClient requires UTF terminal encoding.
@@ -70,8 +71,10 @@ def __init__(self, total, msg_verb):
         self.waiting = False
         self.msg_verb = msg_verb
         self.progress_bar = ProgressBar()
+        self.transferred_bytes = 0
+        self.total_bytes = 0
 
-    def transferring_item(self, item, increment_amt=1, override_msg_verb=None):
+    def transferring_item(self, item, increment_amt=1, override_msg_verb=None, transferred_bytes=0):
         """
         Update progress that item is about to be transferred.
         :param item: LocalFile, LocalFolder, or LocalContent(project) that is about to be sent.
@@ -87,7 +90,8 @@ def transferring_item(self, item, increment_amt=1, override_msg_verb=None):
         msg_verb = self.msg_verb
         if override_msg_verb:
             msg_verb = override_msg_verb
-        self.progress_bar.update(percent_done, '{} {}'.format(msg_verb, details))
+        self.transferred_bytes += transferred_bytes
+        self.progress_bar.update(percent_done, self.transferred_bytes, '{} {}'.format(msg_verb, details))
         self.progress_bar.show()
 
     def increment_progress(self, amt=1):
@@ -138,21 +142,26 @@ def __init__(self):
         self.line = ''
         self.state = self.STATE_RUNNING
         self.wait_msg = 'Waiting'
+        self.transferred_bytes = 0
+        self.start_time = time.time()
 
-    def update(self, percent_done, details):
+    def update(self, percent_done, transferred_bytes, details):
         self.percent_done = percent_done
         self.current_item_details = details
+        self.transferred_bytes = transferred_bytes
 
     def set_state(self, state):
         self.state = state
 
     def _get_line(self):
+        speed = transfer_speed_str(current_time=time.time(), start_time=self.start_time,
+                                   transferred_bytes=self.transferred_bytes)
         if self.state == self.STATE_DONE:
-            return 'Done: 100%'
+            return 'Done: 100%{}'.format(speed)
         details = self.current_item_details
         if self.state == self.STATE_WAITING:
             details = self.wait_msg
-        return 'Progress: {}% - {}'.format(self.percent_done, details)
+        return 'Progress: {}%{} - {}'.format(self.percent_done, speed, details)
 
     def show(self):
         line = self._get_line()
@@ -344,8 +353,8 @@ def wait_for_processes(processes, size, progress_queue, watcher, item):
     while size > 0:
         progress_type, value = progress_queue.get()
         if progress_type == ProgressQueue.PROCESSED:
-            chunk_size = value
-            watcher.transferring_item(item, increment_amt=chunk_size)
+            chunk_size, transferred_bytes = value
+            watcher.transferring_item(item, increment_amt=chunk_size, transferred_bytes=transferred_bytes)
             size -= chunk_size
         elif progress_type == ProgressQueue.START_WAITING:
             watcher.start_waiting()
@@ -451,3 +460,18 @@ def join_with_commas_and_and(items):
         return ' and '.join([head_items_str, last_item])
     else:
         return last_item
+
+
+def transfer_speed_str(current_time, start_time, transferred_bytes):
+    """
+    Return transfer speed str based
+    :param current_time: float: current time
+    :param start_time: float: starting time
+    :param transferred_bytes: int: bytes transferred
+    :return: str: end user str
+    """
+    elapsed_seconds = current_time - start_time
+    if elapsed_seconds > 0 and transferred_bytes > 0:
+        bytes_per_second = float(transferred_bytes) / (elapsed_seconds + 0.5)
+        return '@ {}/s'.format(humanize_bytes(bytes_per_second))
+    return ''