saleemrashid / frida-sslkeylog

Frida tool to dump an NSS Key Log for Wireshark, from a process using dynamically linked OpenSSL (or BoringSSL)
110 stars 22 forks source link

Occasional pyasn1.error.SubstrateUnderrunError #2

Open myocytebd opened 4 years ago

myocytebd commented 4 years ago

The script is able to retrieve some keylog. But sometimes pyasn1.error.SubstrateUnderrunError is thrown:

Exception in thread Thread-1:
Traceback (most recent call last):
  File "D:\Python\Python38-32\lib\threading.py", line 932, in _bootstrap_inner
    self.run()
  File "D:\Python\Python38-32\lib\threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "D:\Python\Python38-32\lib\site-packages\frida_tools\application.py", line 604, in _run
    work()
  File "frida-sslkeylog-master/sslkeylog", line 37, in <lambda>
    self._reactor.schedule(lambda: self._on_message(message, data))
  File "frida-sslkeylog-master/sslkeylog", line 51, in _on_message
    self._on_session(data)
  File "frida-sslkeylog-master/sslkeylog", line 57, in _on_session
    asn1Sequence, _ = decoder.decode(data)
  File "D:\Python\Python38-32\lib\site-packages\pyasn1\codec\ber\decoder.py", line 1446, in __call__
    raise error.SubstrateUnderrunError('%d-octet short' % (length - len(substrate)))
pyasn1.error.SubstrateUnderrunError: 68-octet short

When it happens, i2d_SSL_SESSION returns a very short length (13 in my case). Maybe some status check or error check should be performed before trying to encode it?

rbray89 commented 2 years ago

I found this to be b'NOT RESUMABLE' in my case. Threw the ASN.1 Decode into a try/except block.

rburcham commented 2 years ago

Has anyone determined why this has started happening? 1 month ago I had success reading tls pre-master keys from an app_process instance running a 100% java implementation of CUrl.

Now with the same test case on the same device and same frida version all of a sudden I am getting this error 100% of the time.

rburcham commented 2 years ago

Like I mentioned above, I get this error 100% of the time now. While investigating I've added some debugging to the sslkeylog python to see just what is coming back from frida.

diff --git a/sslkeylog b/sslkeylog
index aeae3e5..549957b 100755
--- a/sslkeylog
+++ b/sslkeylog
@@ -15,7 +15,7 @@ class Application(ConsoleApplication):
     MASTER_KEY_LENGTH = 48

     def _add_options(self, parser):
-        parser.add_option("-o", "--output", help="SSL keylog file to write")
+        parser.add_argument("-o", "--output", help="SSL keylog file to write")

     def _initialize(self, parser, options, args):
         self._file = open(options.output, "a")
@@ -50,16 +50,18 @@ class Application(ConsoleApplication):
             if message["payload"] == "session":
                 self._on_session(data)
                 return
-
-        print(message)
+        else:
+            self._log("info", "_on_message type: {}".format(message["type"]))
+            self._log("info", "_on_message: {}".format(message))

     def _on_session(self, data):
-        asn1Sequence, _ = decoder.decode(data)
-
-        session_id = asn1Sequence[3].asOctets()
-        master_key = asn1Sequence[4].asOctets()
-
-        self._keylog(session_id, master_key)
+        try:
+            asn1Sequence, _ = decoder.decode(data)
+            session_id = asn1Sequence[3].asOctets()
+            master_key = asn1Sequence[4].asOctets()
+            self._keylog(session_id, master_key)
+        except:
+            self._log("warning", "ASN1 decode failed on {}".format(data))

     def _cache_session(self, session_id):
         if session_id in self._session_cache:

This shows the very first message passed up from frida to _on_message is an error:

_on_message type: error
_on_message: {'type': 'error', 'description': 'Error: access violation accessing 0x1b0', 'stack': 'Error: access violation accessing 0x1b0\n    at encodeSSLSession (/script1.js:51)\n    at handleSSL (/script1.js:61)\n    at onEnter (/script1.js:78)', 'fileName': '/script1.js', 'lineNumber': 51, 'columnNumber': 1}

I don't know what Error: access violation accessing 0x1b0 means but I'm certain this is where the Session ID would have been initialized, because what follows are multiple b'NOT RESUMABLE' lines, followed by many Uninitialized Session ID: ... lines.

Might need to take the access violation error over to the frida gitlab to see if there are any pointers.