Standardise Error Logging

lib/metasploit/framework/data_service/proxy/core.rb

@@ -167,8 +167,7 @@ def data_service_operation(&block)
   end
 
   def log_error(exception, ui_message)
-    elog "#{ui_message}: #{exception.message}"
-    exception.backtrace.each { |line| elog "#{line}" }
+    elog(ui_message, error: exception)
     # TODO: We should try to surface the original exception, instead of just a generic one.
     # This should not display the full backtrace, only the message.
     raise exception

lib/metasploit/framework/ntds/parser.rb

@@ -56,7 +56,7 @@ def pull_batch
           begin
             raw_batch_data = channel.read(BATCH_SIZE)
           rescue EOFError => e
-            elog("NTDS Parser: Error pulling batch - #{e}")
+            elog('NTDS Parser: Error pulling batch', error: e)
             raw_batch_data = nil
           end
           raw_batch_data

lib/msf/base/sessions/meterpreter.rb

@@ -559,7 +559,7 @@ def load_session_info
     rescue ::Exception => e
       # Log the error but otherwise ignore it so we don't kill the
       # session if reporting failed for some reason
-      elog("Error loading sysinfo: #{e.class}: #{e}")
+      elog('Error loading sysinfo', error: e)
       dlog("Call stack:\n#{e.backtrace.join("\n")}")
     end
   end

lib/msf/base/sessions/pingback.rb

@@ -70,10 +70,7 @@ def uuid_read
       rescue => e
         # TODO: Can we have a more specific exception handler?
         # Test: what if we send no bytes back?  What if we send less than 16 bytes?  Or more than?
-        elog("Can't get original UUID")
-        elog("Exception Class: #{e.class.name}")
-        elog("Exception Message: #{e.message}")
-        elog("Exception Backtrace: #{e.backtrace}")
+        elog('Can\'t get original UUID', error: e)
       end
     else
       print_warning("WARNING: UUID verification and logging is not available, because the database is not active.")

lib/msf/base/simple/auxiliary.rb

@@ -212,9 +212,7 @@ def self.job_run_proc(ctx, &block)
         end
       end
 
-      elog("Auxiliary failed: #{e.class} #{e}", 'core', LEV_0)
-      dlog("Call stack:\n#{$@.join("\n")}", 'core', LEV_3)
-
+      elog('Auxiliary failed', error: e)
       mod.cleanup
 
     end

lib/msf/base/simple/evasion.rb

@@ -95,8 +95,7 @@ def self.run_simple(oevasion, opts, &block)
     rescue ::Exception => e
       evasion.error = e
       evasion.print_error("evasion failed: #{e}")
-      elog("Evasion failed (#{evasion.refname}): #{e}", 'core', LEV_0)
-      dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+      elog("Evasion failed (#{evasion.refname})", error: e)
     end
 
     nil

lib/msf/base/simple/exploit.rb

@@ -150,8 +150,7 @@ def self.exploit_simple(oexploit, opts, &block)
     rescue ::Exception => e
       exploit.error = e
       exploit.print_error("Exploit failed: #{e}")
-      elog("Exploit failed (#{exploit.refname}): #{e}", 'core', LEV_0)
-      dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+      elog("Exploit failed (#{exploit.refname})", error: e)
     end
 
     return driver.session if driver

lib/msf/base/simple/post.rb

@@ -137,9 +137,7 @@ def self.job_run_proc(ctx)
         end
       end
 
-      elog("Post failed: #{e.class} #{e}", 'core', LEV_0)
-      dlog("Call stack:\n#{$@.join("\n")}", 'core', LEV_3)
-
+      elog('Post failed', error: e)
       mod.cleanup
 
       return
@@ -162,4 +160,3 @@ def self.job_cleanup_proc(ctx)
 
 end
 end
-

lib/msf/core/auxiliary/scanner.rb

@@ -124,7 +124,7 @@ def run
             raise $!
           rescue ::Exception => e
             print_status("Error: #{targ}: #{e.class} #{e.message}")
-            elog("Error running against host #{targ}: #{e.message}\n#{e.backtrace.join("\n")}")
+            elog("Error running against host #{targ}", error: e)
           ensure
             nmod.cleanup
           end

lib/msf/core/db_manager.rb

@@ -169,7 +169,7 @@ def initialize_database_support
 
     rescue ::Exception => e
       self.error = e
-      elog("DB is not enabled due to load error: #{e}")
+      elog('DB is not enabled due to load error', error: e)
       return false
     end
 
@@ -221,20 +221,24 @@ def init_db(opts)
     # already true or if framework.db.connect called after_establish_connection.
     if !! error
       if error.to_s =~ /RubyGem version.*pg.*0\.11/i
-        elog("***")
-        elog("*")
-        elog("* Metasploit now requires version 0.11 or higher of the 'pg' gem for database support")
-        elog("* There a three ways to accomplish this upgrade:")
-        elog("* 1. If you run Metasploit with your system ruby, simply upgrade the gem:")
-        elog("*    $ rvmsudo gem install pg ")
-        elog("* 2. Use the Community Edition web interface to apply a Software Update")
-        elog("* 3. Uninstall, download the latest version, and reinstall Metasploit")
-        elog("*")
-        elog("***")
-        elog("")
-        elog("")
+        err_msg = <<~ERROR
+        ***
+        *
+        * Metasploit now requires version 0.11 or higher of the 'pg' gem for database support
+        * There are three ways to accomplish this upgrade:
+        * 1. If you run Metasploit with your system ruby, simply upgrade the gem:
+        *    $ rvmsudo gem install pg
+        * 2. Use the Community Edition web interface to apply a Software Update
+        * 3. Uninstall, download the latest version, and reinstall Metasploit
+        *
+        ***
+
+
+        ERROR
+        elog(err_msg)
       end
 
+      # +error+ is not an instance of +Exception+, it is, in fact, a +String+
       elog("Failed to connect to the database: #{error}")
     end
 

lib/msf/core/db_manager/connection.rb

@@ -18,8 +18,7 @@ def after_establish_connection
       migrate
     rescue ::Exception => exception
       self.error = exception
-      elog("DB.connect threw an exception: #{exception}")
-      dlog("Call stack: #{exception.backtrace.join("\n")}", LEV_1)
+      elog('DB.connect threw an exception', error: exception)
 
       # remove connection to prevent issues when re-establishing connection
       ActiveRecord::Base.remove_connection
@@ -59,8 +58,7 @@ def connect(opts={})
       end
     rescue ::Exception => e
       self.error = e
-      elog("DB.connect threw an exception: #{e}")
-      dlog("Call stack: #{$@.join"\n"}", LEV_1)
+      elog('DB.connect threw an exception', error: e)
       return false
     ensure
       after_establish_connection
@@ -135,7 +133,7 @@ def disconnect
       self.modules_cached = false
     rescue ::Exception => e
       self.error = e
-      elog("DB.disconnect threw an exception: #{e}")
+      elog('DB.disconnect threw an exception:', error: e)
     end
   end
 end

lib/msf/core/db_manager/migration.rb

@@ -46,8 +46,7 @@ def migrate(verbose=false)
           # as StandardError
       rescue StandardError => error
         self.error = error
-        elog("DB.migrate threw an exception: #{error}")
-        dlog("Call stack:\n#{error.backtrace.join "\n"}")
+        elog('DB.migrate threw an exception', error: error)
       end
     end
 

lib/msf/core/db_manager/module_cache.rb

@@ -307,8 +307,8 @@ def update_all_module_details
           next if not obj
           begin
             update_module_details(obj)
-          rescue ::Exception
-            elog("Error updating module details for #{obj.fullname}: #{$!.class} #{$!}")
+          rescue ::Exception => e
+            elog("Error updating module details for #{obj.fullname}", error: e)
           end
         end
       end

lib/msf/core/encoded_payload.rb

@@ -235,9 +235,8 @@ def encode
             next_encoder = true
             break
 
-          rescue ::Exception
-            elog("#{err_start}: Broken encoder #{encoder.refname}: #{$!}", 'core', LEV_0)
-            dlog("#{err_start}: Call stack\n#{$@.join("\n")}", 'core', LEV_1)
+          rescue ::Exception => e
+            elog("Broken encoder #{encoder.refname}", error: e)
             next_encoder = true
             break
           end

lib/msf/core/exploit.rb

@@ -1482,26 +1482,22 @@ def handle_exception e
       when Rex::ConnectionError
         self.fail_reason = Msf::Exploit::Failure::Unreachable
         self.print_error("Exploit failed [#{self.fail_reason}]: #{msg}")
-        elog("Exploit failed (#{self.refname}): #{msg}", 'core', LEV_0)
-        dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+        elog("Exploit failed (#{self.refname}): #{msg}", error: e)
 
       when Rex::BindFailed
         self.fail_reason = Msf::Exploit::Failure::BadConfig
         self.print_error("Exploit failed [#{self.fail_reason}]: #{msg}")
-        elog("Exploit failed (#{self.refname}): #{msg}", 'core', LEV_0)
-        dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+        elog("Exploit failed (#{self.refname}): #{msg}", error: e)
 
       when Timeout::Error
         self.fail_reason = Msf::Exploit::Failure::TimeoutExpired
         self.print_error("Exploit failed [#{self.fail_reason}]: #{msg}")
-        elog("Exploit failed (#{self.refname}): #{msg}", 'core', LEV_0)
-        dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+        elog("Exploit failed (#{self.refname}): #{msg}", error: e)
 
       when ::Interrupt
         self.fail_reason = Msf::Exploit::Failure::UserInterrupt
         self.print_error("Exploit failed [#{self.fail_reason}]: #{msg}")
-        elog("Exploit failed (#{self.refname}): #{msg}", 'core', LEV_0)
-        dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+        elog("Exploit failed (#{self.refname}): #{msg}", error: e)
       else
 
         # Compare as a string since not all error classes may be loaded
@@ -1531,8 +1527,7 @@ def handle_exception e
           self.print_error("Exploit failed [#{self.fail_reason}]: #{msg}")
         end
 
-        elog("Exploit failed (#{self.refname}): #{msg}", 'core', LEV_0)
-        dlog("Call stack:\n#{e.backtrace.join("\n")}", 'core', LEV_3)
+        elog("Exploit failed (#{self.refname}): #{msg}", error: e)
     end
 
     # Record the error to various places

lib/msf/core/exploit/file_dropper.rb

@@ -108,8 +108,7 @@ def cleanup
           file_rm(file)
         rescue ::Exception => e
           vprint_error("Failed to delete #{file}: #{e}")
-          elog("Failed to delete #{file}: #{e.class}: #{e}")
-          elog("Call stack:\n#{e.backtrace.join("\n")}")
+          elog("Failed to delete #{file}", error: e)
         end
       end
     end
@@ -125,8 +124,7 @@ def cleanup
           dir_rm(dir)
         rescue ::Exception => e
           vprint_error("Failed to delete #{dir}: #{e}")
-          elog("Failed to delete #{dir}: #{e.class}: #{e}")
-          elog("Call stack:\n#{e.backtrace.join("\n")}")
+          elog("Failed to delete #{dir}", error: e)
         end
       end
     end

lib/msf/core/exploit/remote/browser_exploit_server.rb

@@ -601,7 +601,7 @@ def on_request_uri(cli, request)
             begin
               method(:on_request_exploit).call(cli, request, browser_info)
             rescue BESException => e
-              elog("BESException: #{e.message}\n#{e.backtrace * "\n"}")
+              elog('BESException', error: e)
               send_not_found(cli)
               print_error("BESException: #{e.message}")
             end

lib/msf/core/exploit/smb/client/psexec.rb

@@ -227,7 +227,7 @@ def execute_command(text, bat, cmd)
     begin
       return psexec(execute)
     rescue Rex::Proto::DCERPC::Exceptions::Error, Rex::Proto::SMB::Exceptions::Error => e
-      elog("#{e.class} #{e.message}\n#{e.backtrace * "\n"}", 'rex', LEV_3)
+      elog('Unable to execute specified command', 'rex', LEV_3, error: e)
       print_error("Unable to execute specified command: #{e}")
       return false
     end

lib/msf/core/framework.rb

@@ -386,8 +386,7 @@ def session_event(name, session, opts={})
     address = session.session_host
 
     if not (address and address.length > 0)
-      elog("Session with no session_host/target_host/tunnel_peer")
-      dlog("#{session.inspect}", LEV_3)
+      elog("Session with no session_host/target_host/tunnel_peer. Session Info: #{session.inspect}")
       return
     end
 

lib/msf/core/handler.rb

@@ -210,7 +210,7 @@ def create_session(conn, opts={})
       rescue ::Exception => e
         # We just wanna show and log the error, not trying to swallow it.
         print_error("#{e.class} #{e.message}")
-        elog("#{e.class} #{e.message}\n#{e.backtrace * "\n"}")
+        elog('Could not allocate a new Session.', error: e)
         raise e
       end
 

lib/msf/core/handler/bind_named_pipe.rb

@@ -352,7 +352,7 @@ def start_handler
             begin
               session = handle_connection(simple_copy.pipe, opts)
             rescue => e
-              elog("Exception raised from BindNamedPipe.handle_connection: #{$!}")
+              elog('Exception raised from BindNamedPipe.handle_connection', error: e)
             end
           }
         }

lib/msf/core/handler/bind_tcp.rb

@@ -163,8 +163,8 @@ def start_handler
         conn_threads << framework.threads.spawn("BindTcpHandlerSession", false, client) { |client_copy|
           begin
             handle_connection(wrap_aes_socket(client_copy), opts)
-          rescue
-            elog("Exception raised from BindTcp.handle_connection: #{$!}")
+          rescue => e
+            elog('Exception raised from BindTcp.handle_connection', error: e)
           end
         }
       else

lib/msf/core/handler/bind_udp.rb

@@ -182,8 +182,8 @@ def start_handler
         conn_threads << framework.threads.spawn("BindUdpHandlerSession", false, client) { |client_copy|
           begin
             handle_connection(client_copy, opts)
-          rescue
-            elog("Exception raised from BindUdp.handle_connection: #{$!}")
+          rescue => e
+            elog('Exception raised from BindUdp.handle_connection', error: e)
           end
         }
       else

lib/msf/core/handler/reverse_tcp.rb

@@ -159,8 +159,8 @@ def start_handler
           else
             handle_connection(wrap_aes_socket(client), opts)
           end
-        rescue StandardError
-          elog("Exception raised from handle_connection: #{$ERROR_INFO.class}: #{$ERROR_INFO}\n\n#{$ERROR_POSITION.join("\n")}")
+        rescue StandardError => e
+          elog('Exception raised from handle_connection', error: e)
         end
       end
     }

lib/msf/core/handler/reverse_tcp_double.rb

@@ -97,8 +97,8 @@ def start_handler
             sock_inp, sock_out = detect_input_output(client_a_copy, client_b_copy)
             chan = TcpReverseDoubleSessionChannel.new(framework, sock_inp, sock_out)
             handle_connection(chan.lsock, { datastore: datastore })
-          rescue
-            elog("Exception raised from handle_connection: #{$!}\n\n#{$@.join("\n")}")
+          rescue => e
+            elog('Exception raised from handle_connection', error: e)
           end
         }
       end while true

lib/msf/core/handler/reverse_tcp_double_ssl.rb

@@ -146,8 +146,8 @@ def start_handler
             sock_inp, sock_out = detect_input_output(client_a_copy, client_b_copy)
             chan = TcpReverseDoubleSSLSessionChannel.new(framework, sock_inp, sock_out)
             handle_connection(chan.lsock, { datastore: datastore })
-          rescue
-            elog("Exception raised from handle_connection: #{$!}\n\n#{$@.join("\n")}")
+          rescue => e
+            elog('Exception raised from handle_connection', error: e)
           end
         }
       end while true

lib/msf/core/handler/reverse_udp.rb

@@ -222,8 +222,8 @@ def start_handler
           else
             handle_connection(client, opts)
           end
-        rescue ::Exception
-          elog("Exception raised from handle_connection: #{$!.class}: #{$!}\n\n#{$@.join("\n")}")
+        rescue ::Exception => e
+          elog('Exception raised from handle_connection', error: e)
         end
       end
     }

lib/msf/core/module/external.rb

@@ -19,7 +19,7 @@ def execute_module(path, method: :run, args: datastore, fail_on_exit: true)
       rescue Interrupt => e
         raise e
       rescue Exception => e
-        elog e.backtrace.join("\n")
+        elog('Unable to execute External Module', error: e)
         fail_with Msf::Module::Failure::Unknown, e.message
       end
     end

lib/msf/core/modules/loader/base.rb

@@ -304,7 +304,7 @@ def reload_module(original_metasploit_class_or_instance)
           reloaded_module_instance.datastore.update(original_metasploit_instance.datastore)
         end
       else
-        elog("Failed to create instance of #{original_metasploit_class_or_instance.refname} after reload.", 'core')
+        elog("Failed to create instance of #{original_metasploit_class_or_instance.refname} after reload.")
 
         # Return the old module instance to avoid an strace trace
         return original_metasploit_class_or_instance