Add printing of time spent for APDU transactions

cards/building_blocks.py

@@ -44,6 +44,7 @@ class Card_with_ls:
                 response_EF[EF] = self.select_file(0x02, self.SELECT_P2, EF)
         
         self.sw_changed = False
+        self.last_delta = None
         
         if "-l" in options:
             print self._ls_l_template % {"name": "Name", "type": "Type", "size": "Size"}
@@ -127,6 +128,7 @@ class Card_with_read_binary:
         
         if had_one: ## If there was at least one successful pass, ignore any error SW. It probably only means "end of file"
             self.sw_changed = False
+            self.last_delta = None
         
         return contents, result.sw
     

cards/generic_card.py

@@ -1,5 +1,5 @@
 import smartcard
-import TLV_utils, crypto_utils, utils, binascii, fnmatch, re
+import TLV_utils, crypto_utils, utils, binascii, fnmatch, re, time
 from utils import C_APDU, R_APDU
 
 DEBUG = True
@@ -138,6 +138,8 @@ class Card:
         self.last_sw = None
         self.last_result = None
         self.sw_changed = False
+        self._last_start = None
+        self.last_delta = None
     
     def post_merge(self):
         ## Called after cards.__init__.Cardmultiplexer._merge_attributes
@@ -229,6 +231,9 @@ class Card:
         if DEBUG:
             print "%s\nBeginning transaction %i" % ('-'*80, self._i)
         
+        self.last_delta = None
+        self._last_start = time.time()
+        
         if hasattr(self, "before_send"):
             apdu = self.before_send(apdu)
         
@@ -237,6 +242,10 @@ class Card:
         if hasattr(self, "after_send"):
             result = self.after_send(result)
         
+        if self._last_start is not None:
+            self.last_delta = time.time() - self._last_start
+            self._last_start = None
+        
         if DEBUG:
             print "Ending transaction %i\n%s\n" % (self._i, '-'*80)
         self._i = self._i + 1

cyberflex-shell.py

@@ -227,6 +227,7 @@ class Cyberflex_Shell(Shell):
 
     def _clear_sw(self):
         self.card.sw_changed = False
+        self.card.last_delta = None
     
     def do_fancy_apdu(self, *args):
         apdu = None
@@ -307,8 +308,15 @@ class Cyberflex_Shell(Shell):
             self.stop_log()
 
     def _print_sw(self):
+        to_print = []
         if self.card.sw_changed:
-            print self.card.decode_statusword()
+            to_print.append(self.card.decode_statusword())
+        
+        if self.card.last_delta is not None:
+            to_print.append("%0.03gs" % self.card.last_delta)
+        
+        if to_print:
+            print ", ".join(to_print)
     
     def _find_driver_class(driver_name):
         for i in dir(cards):