search

rapid7 / metasploit-framework

Metasploit Framework
https://www.metasploit.com/
Other
34.04k stars 13.94k forks source link

msfrpcd console failure caused by rex-core upgrade #16580

Closed jtylerorr closed 2 years ago

jtylerorr commented 2 years ago

Overview

Beginning with version 6.1.27, interactions with Metasploit through msfrpcd are unreliable, and sometimes result in output being truncated, input being accepted but discarded, and no error being reported to the RPC client.

I have narrowed down the cause of the issue to be the rex-core version update between 6.1.26 and 6.1.27. Manually reverting rex-core back to version 0.1.20, as used in MSF 6.1.26, fixes the buggy behavior.

The issue is difficult to reliably reproduce and may require stepping through the procedure several times. Some exploits, like the one listed, seemed to produce the buggy behavior more reliably. I have confirmed the behavior with the following exploit modules, but it likely works with others:

Steps to reproduce

  1. Start from a freshly cloned copy of metasploit-framework (currently version 6.1.42)

  2. Start msfrpcd and msfrpc

export MSF_USERNAME=username
export MSF_PASSWORD=password
./msfrpcd -U ${MSF_USERNAME} -P ${MSF_PASSWORD} -a 127.0.0.1 # Optionally start in foreground of another shell
./msfrpc -U ${MSF_USERNAME} -P ${MSF_PASSWORD} -a 127.0.0.1
  1. In the RPC client, create a console, load an exploit, set options, and run.

NOTE: The exploit used in the following example was the most likely to produce the buggy behavior in my experience. However, the problem affects a wide array of exploit modules. The behavior was observed when testing against a target that was intentionally made vulnerable to the exploit (and for which the exploit succeeded using MSF <=6.1.26). Be sure to adjust options to fit your test environment.

Many of the options set in the following call are default options for the module. They are explicitly set by some libraries such as pymetasploit3, so I explicitly set them when using msfrpc. This is likely not necessary to reproduce the buggy behavior.

rpc.call('console.create')
console = _['id']
rpc.call('console.write', console, "use exploit/multi/http/apache_activemq_upload_jsp
set VERBOSE True
set WfsDelay 2
set EnableContextEncoding False
set DisablePayloadHandler False
set RPORT 8161
set SSL False
set UserAgent Mozilla/5.0 (Macintosh; Intel Mac OS X 12.2; rv:97.0) Gecko/20100101 Firefox/97.0
set HttpUsername 
set HttpPassword 
set DigestAuthIIS True
set SSLVersion Auto
set FingerprintCheck True
set DOMAIN WORKSTATION
set HttpTrace False
set HttpTraceHeadersOnly False
set HttpTraceColors red/blu
set HTTP::uri_encode_mode hex-normal
set HTTP::uri_full_url False
set HTTP::pad_method_uri_count 1
set HTTP::pad_uri_version_count 1
set HTTP::pad_method_uri_type space
set HTTP::pad_uri_version_type space
set HTTP::method_random_valid False
set HTTP::method_random_invalid False
set HTTP::method_random_case False
set HTTP::version_random_valid False
set HTTP::version_random_invalid False
set HTTP::uri_dir_self_reference False
set HTTP::uri_dir_fake_relative False
set HTTP::uri_use_backslashes False
set HTTP::pad_fake_headers False
set HTTP::pad_fake_headers_count 0
set HTTP::pad_get_params False
set HTTP::pad_get_params_count 16
set HTTP::pad_post_params False
set HTTP::pad_post_params_count 16
set HTTP::uri_fake_end False
set HTTP::uri_fake_params_start False
set HTTP::header_folding False
set AllowNoCleanup False
set BasicAuthUser admin
set BasicAuthPass admin
set AutoCleanup true
set RHOSTS XX.XX.XX.XX
set payload java/meterpreter/reverse_tcp
set VERBOSE False
set LPORT 8000
set ReverseAllowProxy False
set ReverseListenerThreaded False
set StagerRetryCount 10
set StagerRetryWait 5
set PingbackRetries 0
set PingbackSleep 30
set PayloadUUIDTracking False
set EnableStageEncoding False
set StageEncodingFallback True
set JavaMeterpreterDebug False
set Spawn 2
set AutoLoadStdapi True
set AutoVerifySessionTimeout 30
set AutoSystemInfo True
set EnableUnicodeEncoding False
set SessionRetryTotal 3600
set SessionRetryWait 10
set SessionExpirationTimeout 604800
set SessionCommunicationTimeout 300
set AutoUnhookProcess False
set MeterpreterDebugBuild False
set LHOST eth0
run -z\n")
  1. Once the exploit is running, enter the following command repeatedly, until the response contains"busy"=>false.
rpc.call('console.read', console)
  1. (IN WORKING VERSIONS; <= 6.1.26) The output produced by step 3 SHOULD show the module successfully completing and creating at least one meterpreter session. At this point, you SHOULD be able to repeatedly enter the following command sequence to show that the console is still functional by returning the 
rpc.call('console.write', console, "version\n")
# => {"wrote"=>8}
rpc.call('console.read', console)
# => {"data"=>"XXXXXXX", "prompt"=>"msf6 exploit(multi/http/apache_activemq_upload_jsp) > ", "busy"=>false}
  1. (IN BUGGY VERSIONS; >= 6.1.27) The output produced by step 3 MAY be truncated and not show any sessions created. In some cases, it did not even echo all the options being set. There is not indication that the exploit finished, or the console crashed. At this point, entering the same command sequence will eventually result in an unexpected output of {"wrote"=>nil}.
rpc.call('console.write', console, "version\n")
# => {"wrote"=>8}
rpc.call('console.read', console)
# => {"data"=>"XXXXXXX", "prompt"=>"msf6 exploit(multi/http/apache_activemq_upload_jsp) > ", "busy"=>false}rpc.call('console.write', console, "version\n")
# => {"wrote"=>nil}
rpc.call('console.read', console)
# => {"data"=>"XXXXXXX", "prompt"=>"msf6 exploit(multi/http/apache_activemq_upload_jsp) > ", "busy"=>false}

Were you following a specific guide/tutorial or reading documentation?

No.

Expected behavior

This is described in detail in the steps to reproduce.

Using a reliable exploit against an intentionally vulnerable target, the exploit should always succeed in creating a meterpreter session.

Current behavior

This is described in detail in the steps to reproduce.

Even when using a reliable exploit against an intentionally vulnerable target, the console will sometimes truncate output and become non-responsive.

Metasploit version

This behavior is observed in version 6.1.27-6.1.42(current).

Additional Information

I have narrowed down the cause of the problem to being the version of dependency rex-core. In MSF version 6.1.26, rex-core version 0.1.20 is used. In MSF version 6.1.27, rex-core version 0.1.25 is used.

For any version of MSF >= 6.1.27, manually downgrading rex-core to version 0.1.20 using the following commands removes the observed buggy behavior.

sed -i 's/rex-core (0.1..*)/rex-core (0.1.20)/' Gemfile.lock
bundle install

However, since I am not familiar with the metasploit-framework source code, I do not know if this dependency change will introduce other bugs.

adfoster-r7 commented 2 years ago

Thanks for raising an issue :+1:

If you still have the environment available, you could also manually specify in your Gemfile specific versions of rex-core:

diff --git a/Gemfile b/Gemfile
index 8ff2b3d38f..cc00dfe4b5 100755
--- a/Gemfile
+++ b/Gemfile
@@ -9,6 +9,8 @@ group :coverage do
   gem 'simplecov', '0.18.2'
 end

+gem 'rex-core', '0.1.21'
+
 group :development do
   # Markdown formatting for yard
   gem 'redcarpet'
(END)

Followed by an explicit update:

bundle update rex-core

Which should generate a new Gemfile.lock:

diff --git a/Gemfile.lock b/Gemfile.lock
index e562d74c42..b8ea332300 100644
--- a/Gemfile.lock
+++ b/Gemfile.lock
@@ -364,7 +364,7 @@ GEM
       rex-core
       rex-struct2
       rex-text
-    rex-core (0.1.28)
+    rex-core (0.1.22)
     rex-encoder (0.1.6)
       metasm
       rex-arch
@@ -526,6 +526,7 @@ DEPENDENCIES
   pry-byebug
   rake
   redcarpet
+  rex-core (= 0.1.22)
   rspec-rails
   rspec-rerun
   rubocop

It looks like rex-core 0.1.21 was just a small utility script, so it is most likely 0.1.22-0.1.25 that caused the issue I think 🤔

jtylerorr commented 2 years ago

@adfoster-r7 - Thanks for the quick response.

I tested with rex-core versions 0.1.21-0.1.25 using the method you described above. While it's difficult to conclusively prove absence of the bug, it does seem very likely that it is introduced in rex-core 0.1.25.

For reference: rex-core 0.1.25 diff

If downgrading rex-core is a sufficient fix for metasploit-framework it would be great to have it merged in ASAP and possibly have a bug reported to the rex-core project. However, it is unclear to me if any parts of metasploit-framework are dependent on newer versions of rex-core.

adfoster-r7 commented 2 years ago

The rex-core 0.1.25 release was aimed to fix an issue with reverse portfwd over here - https://github.com/rapid7/metasploit-framework/issues/15968

I'm not sure why that fix would impact the RPC API just yet though 🤔

EmilioPanti commented 2 years ago

I noticed the same problem after the update to version 6.1.43.

When I execute a "console.write" call to the RPC server sometimes it succeeds other times it fails (returning null to the field of bytes written). The success/failure would seem to be completely random.

github-actions[bot] commented 2 years ago

Hi!

This issue has been left open with no activity for a while now.

We get a lot of issues, so we currently close issues after 60 days of inactivity. It’s been at least 30 days since the last update here. If we missed this issue or if you want to keep it open, please reply here. You can also add the label "not stale" to keep this issue open!

As a friendly reminder: the best way to see this issue, or any other, fixed is to open a Pull Request.

rasheed-rd commented 2 years ago

I've noticed the same problem when running auxiliary/scanner/snmp/snmp_login through the RPC API. I'm on version 6.1.27-dev and rex-core 0.1.25. The module will succeed about 80% of the time, the other 20% is a mix of failures with no output and some with truncated output.

adfoster-r7 commented 2 years ago

Confirmed with shorter replication steps

Start the daemon in the foreground:

export MSF_USERNAME=username
export MSF_PASSWORD=password
 ./msfrpcd -U ${MSF_USERNAME} -P ${MSF_PASSWORD} -a 127.0.0.1 -f

Connect a client:

export MSF_USERNAME=username
export MSF_PASSWORD=password
./msfrpc -U ${MSF_USERNAME} -P ${MSF_PASSWORD} -a 127.0.0.1

In the client - create a console, and write/read to it:

>> console = rpc.call('console.create')['id'];  sleep 1; 10.times { puts("Write result: #{rpc.call('console.write', console, "version\n")}"); puts("Read result: #{rpc.call('console.read', console)}"); }

Output on latest release 6.2.9, with rex-core 0.1.25

Write result: {"wrote"=>8}
Read result: {"data"=>"\n ______________________________________________________________________________\n|                                                                              |\n|                   METASPLOIT CYBER MISSILE COMMAND V5                        |\n|______________________________________________________________________________|\n      \\                                  /                      /\n       \\     .                          /                      /            x\n        \\                              /                      /\n         \\                            /          +           /\n          \\            +             /                      /\n           *                        /                      /\n                                   /      .               /\n    X                             /                      /            X\n                                 /                     ###\n                                /                     # % #\n                               /                       ###\n                      .       /\n     .                       /      .            *           .\n                            /\n                           *\n                  +                       *\n\n                                       ^\n####      __     __     __          #######         __     __     __        ####\n####    /    \\ /    \\ /    \\      ###########     /    \\ /    \\ /    \\      ####\n################################################################################\n################################################################################\n# WAVE 5 ######## SCORE 31337 ################################## HIGH FFFFFFFF #\n################################################################################\n                                                           https://metasploit.com\n\n\n       =[ metasploit v6.2.9-dev-4bbae96840                ]\n+ -- --=[ 2230 exploits - 1177 auxiliary - 398 post       ]\n+ -- --=[ 864 payloads - 45 encoders - 11 nops            ]\n+ -- --=[ 9 evasion                                       ]\n\nMetasploit tip: Save the current environment with the \nsave command, future console restarts will use this \nenvironment again\n\nFramework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}

Expected output, when running gem rex-core 0.1.24

>> console = rpc.call('console.create')['id']; 10.times { puts("Write result: #{rpc.call('console.write', console, "version\n")}"); puts("Read result: #{rpc.c
all('console.read', console)}"); }
Write result: {"wrote"=>8}
Read result: {"data"=>"\nUnable to handle kernel NULL pointer dereference at virtual address 0xd34db33f\nEFLAGS: 00010046\neax: 00000001 ebx: f77c8c00 ecx: 00000000 edx: f77f0001\nesi: 803bf014 edi: 8023c755 ebp: 80237f84 esp: 80237f60\nds: 0018   es: 0018  ss: 0018\nProcess Swapper (Pid: 0, process nr: 0, stackpage=80377000)\n\n\nStack: 90909090990909090990909090\n       90909090990909090990909090\n       90909090.90909090.90909090\n       90909090.90909090.90909090\n       90909090.90909090.09090900\n       90909090.90909090.09090900\n       ..........................\n       cccccccccccccccccccccccccc\n       cccccccccccccccccccccccccc\n       ccccccccc.................\n       cccccccccccccccccccccccccc\n       cccccccccccccccccccccccccc\n       .................ccccccccc\n       cccccccccccccccccccccccccc\n       cccccccccccccccccccccccccc\n       ..........................\n       ffffffffffffffffffffffffff\n       ffffffff..................\n       ffffffffffffffffffffffffff\n       ffffffff..................\n       ffffffff..................\n       ffffffff..................\n\n\nCode: 00 00 00 00 M3 T4 SP L0 1T FR 4M 3W OR K! V3 R5 I0 N5 00 00 00 00\nAiee, Killing Interrupt handler\nKernel panic: Attempted to kill the idle task!\nIn swapper task - not syncing\n\n\n       =[ metasploit v6.2.9-dev-4bbae96840                ]\n+ -- --=[ 2230 exploits - 1177 auxiliary - 398 post       ]\n+ -- --=[ 864 payloads - 45 encoders - 11 nops            ]\n+ -- --=[ 9 evasion                                       ]\n\nMetasploit tip: View missing module options with show \nmissing\n\nFramework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
adfoster-r7 commented 2 years ago

Verified synchronously without the need for running an actual RPC service.

Running in bundle exec irb or bundle exec ruby ./example.rb

require 'pathname'
require Pathname.new(__dir__).realpath.expand_path.join('config', 'boot')
require 'msfenv'

framework ||= Msf::Simple::Framework.create; service = OpenStruct.new(framework: framework); rpc = Msf::RPC::RPC_Console.new(service); console = rpc.rpc_create({ 'DisableBanner' => true })['id'];  10.times { puts("Write result: #{rpc.rpc_write(console, "version\n")}"); sleep 0.5; puts("Read result: #{rpc.rpc_read(console)}"); }

rex-core 0.1.24 successful:

3.0.2 :015 > framework ||= Msf::Simple::Framework.create; service = OpenStruct.new(framework: framework); rpc = Msf::RPC::RPC_Console.new(service); console = rpc.rpc_create({ 'DisableBanner' => true })['id'];  
10.times { puts("Write result: #{rpc.rpc_write(console, "version\n")}"); sleep 0.5; puts("Read result: #{rpc.rpc_read(console)}"); }
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}

rex-core 0.1.25 failing:

3.0.2 :007 > framework ||= Msf::Simple::Framework.create; service = OpenStruct.new(framework: framework); rpc = Msf::RPC::RPC_Console.new(service); console = rpc.rpc_create({ 'DisableBanner' => true })['id'];  
10.times { puts("Write result: #{rpc.rpc_write(console, "version\n")}"); sleep 0.5; puts("Read result: #{rpc.rpc_read(console)}"); }
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"Framework: 6.2.9-dev-4bbae96840\nConsole  : 6.2.9-dev-4bbae96840\n", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>8}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}
Write result: {"wrote"=>nil}
Read result: {"data"=>"", "prompt"=>"msf6 auxiliary(scanner/vnc/vnc_login) > ", "busy"=>false}

Stacktrace from error log tail -f ~/.msf4/logs/framework.log

Collapse ``` [07/26/2022 15:06:19] [w(0)] core: monitor_rsock: exception during read: Errno::EAGAIN Resource temporarily unavailable [07/26/2022 15:06:19] [d(0)] core: HistoryManager.pop_context name: :msfconsole [07/26/2022 15:06:19] [e(0)] core: Thread Exception: WebConsoleShell critical=false source: /Users/user/Documents/code/metasploit-framework/lib/msf/ui/web/web_console.rb:84:in `initialize' /Users/user/Documents/code/metasploit-framework/lib/msf/ui/web/driver.rb:62:in `new' /Users/user/Documents/code/metasploit-framework/lib/msf/ui/web/driver.rb:62:in `create_console' /Users/user/Documents/code/metasploit-framework/lib/msf/core/rpc/v10/rpc_console.rb:28:in `rpc_create' test.rb:8:in `
' - IOError closed stream Call stack: /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/input/buffer.rb:52:in `getc' /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/input/buffer.rb:52:in `gets' /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/bidirectional_pipe.rb:118:in `gets' /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/bidirectional_pipe.rb:148:in `pgets' /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/shell.rb:323:in `get_input_line' /Users/user/Documents/code/metasploit-framework/lib/rex/ui/text/shell.rb:145:in `run' /Users/user/Documents/code/metasploit-framework/lib/msf/ui/web/web_console.rb:84:in `block in initialize' /Users/user/Documents/code/metasploit-framework/lib/msf/core/thread_manager.rb:105:in `block in spawn' /Users/user/.rvm/gems/ruby-3.0.2@metasploit-framework/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context' ```
adfoster-r7 commented 2 years ago

I've created a pull request up to hopefully fix this issue https://github.com/rapid7/metasploit-framework/pull/16822 - let me know if that works for you 👍

rasheed-rd commented 2 years ago

I've created a pull request up to hopefully fix this issue #16822 - let me know if that works for you 👍

@adfoster-r7 I pulled down your branch and ran it, the behavior I'm seeing is that when I first run msfrpcd ./msfrpcd -P PASSWORD -a 127.0.0.1 -f -S my attempts to run snmp_login fail anywhere between 10-45 times then it seems to work 100% of the time.

adfoster-r7 commented 2 years ago

@rasheed-rd Thanks for taking a look! I believe your issue is different than the original error report then - as you said in your original replication steps from https://github.com/rapid7/metasploit-framework/pull/16812#issuecomment-1194304318

1- I pulled the latest metasploit docker image (Framework Version: 6.0.55-dev) and ran it starting msfrpcd.

6.0.55 is quite old, almost a year ago. The version is from before this regression/bug was introduced by rex-core 0.1.25 - Metasploit 6.1.27. I've created a separate issue for tracking the effort of building newer Docker builds over here - https://github.com/rapid7/metasploit-framework/issues/16826

I'll need to see if I can replicate your snmp_login issue, but I have a feeling it might be a race condition in your Python script rather than metasploit-framework.

For context - I think you may need to update your Python script to handle reading until busy is True at least once, or data is available and Busy is False. I believe there's a small period of time between writing a command to the console, and the command actually executing and being marked as 'busy'

adfoster-r7 commented 2 years ago

@rasheed-rd It looks like pymetasploit has that logic in place already via the run_module_with_output method: https://github.com/DanMcInerney/pymetasploit3/blob/9776da55b0abacfa843a32204f3972ec7d9b3de7/pymetasploit3/msfrpc.py#L2258-L2267

So I believe you'd want something similar there in your own script :+1:

rasheed-rd commented 2 years ago

@adfoster-r7 Thanks for the explanation. It work perfectly after updating my script!