[tcat-commissioner] extra logging added and --info option to show the…

… certs

tools/tcat_ble_client/bbtc.py

@@ -34,20 +34,23 @@
 from ble.ble_connection_constants import BBTC_SERVICE_UUID, BBTC_TX_CHAR_UUID, \
     BBTC_RX_CHAR_UUID
 from ble.ble_stream import BleStream
-from ble.udp_stream import UdpStream
 from ble.ble_stream_secure import BleStreamSecure
+from ble.udp_stream import UdpStream
 from ble import ble_scanner
 from cli.cli import CLI
 from dataset.dataset import ThreadDataset
 from cli.command import CommandResult
 from utils import select_device_by_user_input
 
+logger = logging.getLogger(__name__)
+
 
 async def main():
     logging.basicConfig(level=logging.WARNING)
 
     parser = argparse.ArgumentParser(description='Device parameters')
     parser.add_argument('--debug', help='Enable debug logs', action='store_true')
+    parser.add_argument('--info', help='Enable info logs', action='store_true')
     parser.add_argument('--cert_path', help='Path to certificate chain and key', action='store', default='auth')
     group = parser.add_mutually_exclusive_group()
     group.add_argument('--mac', type=str, help='Device MAC address', action='store')
@@ -57,8 +60,13 @@ async def main():
     args = parser.parse_args()
 
     if args.debug:
-        logging.getLogger('ble_stream').setLevel(logging.DEBUG)
-        logging.getLogger('ble_stream_secure').setLevel(logging.DEBUG)
+        logging.getLogger('ble.ble_stream').setLevel(logging.DEBUG)
+        logging.getLogger('ble.ble_stream_secure').setLevel(logging.DEBUG)
+        logging.getLogger('ble.udp_stream').setLevel(logging.DEBUG)
+    elif args.info:
+        logging.getLogger('ble.ble_stream').setLevel(logging.INFO)
+        logging.getLogger('ble.ble_stream_secure').setLevel(logging.INFO)
+        logging.getLogger('ble.udp_stream').setLevel(logging.INFO)
 
     device = await get_device_by_args(args)
 
@@ -73,7 +81,7 @@ async def main():
             cafile=path.join(args.cert_path, 'ca_cert.pem'),
         )
 
-        print('Setting up secure channel...')
+        print('Setting up secure channel..', end='')
         await ble_sstream.do_handshake()
         print('Done')
 
@@ -85,13 +93,14 @@ async def main():
         user_input = await loop.run_in_executor(None, lambda: input('> '))
         if user_input.lower() == 'exit':
             print('Disconnecting...')
+            # FIXME must send Alert + close here. Otherwise in simulation mode, Device gets stuck later on.
             break
         try:
             result: CommandResult = await cli.evaluate_input(user_input)
             if result:
                 result.pretty_print()
         except Exception as e:
-            print(e)
+            logger.error(e)
 
 
 async def get_device_by_args(args):

tools/tcat_ble_client/ble/ble_stream_secure.py

@@ -28,7 +28,9 @@
 
 import asyncio
 import ssl
+import sys
 import logging
+import utils
 
 logger = logging.getLogger(__name__)
 
@@ -41,17 +43,21 @@ def __init__(self, stream):
         self.incoming = ssl.MemoryBIO()
         self.outgoing = ssl.MemoryBIO()
         self.ssl_object = None
+        self.cert = ''
 
     def load_cert(self, certfile='', keyfile='', cafile=''):
         if certfile and keyfile:
             self.ssl_context.load_cert_chain(certfile=certfile, keyfile=keyfile)
+            self.cert = utils.load_cert_pem(certfile)
         elif certfile:
             self.ssl_context.load_cert_chain(certfile=certfile)
+            self.cert = utils.load_cert_pem(certfile)
 
         if cafile:
             self.ssl_context.load_verify_locations(cafile=cafile)
 
     async def do_handshake(self):
+        is_debug = logger.getEffectiveLevel() <= logging.DEBUG
         self.ssl_object = self.ssl_context.wrap_bio(
             incoming=self.incoming,
             outgoing=self.outgoing,
@@ -60,8 +66,21 @@ async def do_handshake(self):
         )
         while True:
             try:
+                if not is_debug:
+                    print('.', end='')
+                sys.stdout.flush()
                 self.ssl_object.do_handshake()
+                print('\n')
+
+                # show peer cert and own cert, if --info argument given.
+                logger.info(f'TCAT Device cert:\n{self.ssl_object.getpeercert(binary_form=False)}')
+                peer_cert_der_hex = utils.base64_string(self.ssl_object.getpeercert(binary_form=True))
+                logger.info(f'TCAT Device certificate, base64: (paste in https://lapo.it/asn1js/ to decode)\n{peer_cert_der_hex}')
+                logger.info(f'TCAT Commissioner cert, PEM:\n{self.cert}')
+                ca_cert_der_hex = utils.base64_string(self.ssl_object.getpeercert(binary_form=True))
+                logger.info(f'TCAT Commissioner CA cert, base64:\n{ca_cert_der_hex}')
                 break
+
             # SSLWantWrite means ssl wants to send data over the link,
             # but might need a receive first
             except ssl.SSLWantWriteError:
@@ -71,7 +90,7 @@ async def do_handshake(self):
                 data = self.outgoing.read()
                 if data:
                     await self.stream.send(data)
-                await asyncio.sleep(0.1)
+                await asyncio.sleep(0.02)
 
             # SSLWantRead means ssl wants to receive data from the link,
             # but might need to send first
@@ -82,7 +101,15 @@ async def do_handshake(self):
                 output = await self.stream.recv(4096)
                 if output:
                     self.incoming.write(output)
-                await asyncio.sleep(0.1)
+                await asyncio.sleep(0.02)
+
+            except ssl.CertificateError as e:
+                logger.error(f'Certificate validation error: {e}')
+                break
+
+            except ssl.SSLError as e:
+                logger.error(f'Certificate validation error: {e}')
+                break
 
     async def send(self, bytes):
         self.ssl_object.write(bytes)
@@ -117,3 +144,4 @@ async def send_with_resp(self, bytes):
         await self.send(bytes)
         res = await self.recv(buffersize=4096, timeout=5)
         return res
+

tools/tcat_ble_client/ble/udp_stream.py

@@ -26,11 +26,7 @@
   POSSIBILITY OF SUCH DAMAGE.
 """
 
-from itertools import count, takewhile
-from typing import Iterator
 import logging
-import time
-from asyncio import sleep
 import socket
 
 logger = logging.getLogger(__name__)
@@ -54,3 +50,6 @@ async def recv(self, bufsize):
         message = self.socket.recv(bufsize)
         logger.debug(f'retrieved {message}')
         return message
+
+    def close(self):
+        self.socket.close()

tools/tcat_ble_client/utils/__init__.py

@@ -26,6 +26,8 @@
   POSSIBILITY OF SUCH DAMAGE.
 """
 
+import base64
+
 
 def get_int_in_range(min_value, max_value):
     while True:
@@ -61,3 +63,12 @@ def select_device_by_user_input(tcat_devices):
     print('Selected ', device)
 
     return device
+
+
+def base64_string(bindata):
+    return base64.b64encode(bindata).decode('ascii')
+
+
+def load_cert_pem(fn):
+    with open(fn, 'r') as file:
+        return file.read()