From 1ee76305835ed989dd67cd8dd8dd2751e64c7530 Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Fri, 5 Oct 2018 09:14:28 -0700 Subject: [PATCH 1/9] reduced output to activities likely related to malware --- fakenet/diverters/diverterbase.py | 20 ++++++++++---------- fakenet/diverters/linutil.py | 4 +++- fakenet/diverters/linux.py | 19 ++++++++++--------- fakenet/diverters/windows.py | 26 +++++++++++++------------- fakenet/diverters/winutil.py | 4 ++-- fakenet/fakenet.py | 24 ++++++++++++++++-------- fakenet/listeners/DNSListener.py | 19 +++++++++++-------- fakenet/listeners/FTPListener.py | 2 +- fakenet/listeners/HTTPListener.py | 5 +++-- fakenet/listeners/IRCListener.py | 6 +++--- fakenet/listeners/POPListener.py | 6 +++--- fakenet/listeners/ProxyListener.py | 10 +++++----- fakenet/listeners/RawListener.py | 4 ++-- fakenet/listeners/SMTPListener.py | 6 +++--- fakenet/listeners/TFTPListener.py | 2 +- 15 files changed, 86 insertions(+), 71 deletions(-) diff --git a/fakenet/diverters/diverterbase.py b/fakenet/diverters/diverterbase.py index c2919ca..e4cba6d 100644 --- a/fakenet/diverters/diverterbase.py +++ b/fakenet/diverters/diverterbase.py @@ -594,16 +594,16 @@ def __init__(self, diverter_config, listeners_config, ip_addrs, # Check active interfaces if not self.check_active_ethernet_adapters(): - self.logger.warning('WARNING: No active ethernet interfaces ' + self.logger.critical('WARNING: No active ethernet interfaces ' 'detected!') - self.logger.warning(' Please enable a network interface.') + self.logger.critical(' Please enable a network interface.') sys.exit(1) # Check configured ip addresses if not self.check_ipaddresses(): - self.logger.warning('ERROR: No interface had IP address ' + self.logger.critical('ERROR: No interface had IP address ' 'configured!') - self.logger.warning(' Please configure an IP address on a ' + self.logger.critical(' Please configure an IP address on ' 'network interface.') sys.exit(1) @@ -648,11 +648,11 @@ def start(self): to the already-defined (and potentially some yet-to-be-defined) abstract methods that handle the real OS-specific stuff. """ - self.logger.info('Starting...') + self.logger.debug('Starting...') return self.startCallback() def stop(self): - self.logger.info('Stopping...') + self.logger.debug('Stopping...') return self.stopCallback() @abc.abstractmethod @@ -1048,14 +1048,14 @@ def parse_diverter_config(self): default_listener = self.getconfigval('defaulttcplistener').lower() default_port = self.listeners_config[default_listener]['port'] self.default_listener['TCP'] = int(default_port) - self.logger.error('Using default listener %s on port %d', + self.logger.debug('Using default listener %s on port %d', self.getconfigval('defaulttcplistener').lower(), self.default_listener['TCP']) default_listener = self.getconfigval('defaultudplistener').lower() default_port = self.listeners_config[default_listener]['port'] self.default_listener['UDP'] = int(default_port) - self.logger.error('Using default listener %s on port %d', + self.logger.debug('Using default listener %s on port %d', self.getconfigval('defaultudplistener').lower(), self.default_listener['UDP']) @@ -1147,7 +1147,7 @@ def handle_pkt(self, pkt, callbacks3, callbacks4): logline = self.formatPkt(pkt, pid, comm) self.pdebug(DGENPKTV, logline) elif pid and (pid != self.pid) and crit.first_packet_new_session: - self.logger.info(' pid: %d name: %s' % + self.logger.debug(' pid: %d name: %s' % (pid, comm if comm else 'Unknown')) # 2: Call layer 3 (network) callbacks @@ -1415,7 +1415,7 @@ def check_log_icmp(self, crit, pkt): None """ if pkt.is_icmp: - self.logger.info('ICMP type %d code %d %s' % ( + self.logger.debug('ICMP type %d code %d %s' % ( pkt.icmp_type, pkt.icmp_code, pkt.hdrToStr())) def getOriginalDestPort(self, orig_src_ip, orig_src_port, proto): diff --git a/fakenet/diverters/linutil.py b/fakenet/diverters/linutil.py index 145f0a3..7ff9023 100644 --- a/fakenet/diverters/linutil.py +++ b/fakenet/diverters/linutil.py @@ -261,8 +261,10 @@ def linux_capture_iptables(self): break self.iptables_captured += buf + # set logging level to debug because of erroneous output + #TODO confirm validity of this check if self.iptables_captured == '': - self.logger.error('Null iptables-save output, likely not ' + + self.logger.debug('Null iptables-save output, likely not ' + 'privileged') ret = p.wait() except OSError as e: diff --git a/fakenet/diverters/linux.py b/fakenet/diverters/linux.py index b3695c6..968015a 100644 --- a/fakenet/diverters/linux.py +++ b/fakenet/diverters/linux.py @@ -41,7 +41,7 @@ def init_diverter_linux(self): slists = ['linuxredirectnonlocal', ] self.reconfigure(portlists=[], stringlists=slists) - self.logger.info('Running in %s mode' % (self.network_mode)) + self.logger.debug('Running in %s mode' % (self.network_mode)) self.nfqueues = list() @@ -96,8 +96,8 @@ def init_diverter_linux(self): def startCallback(self): if not self.check_privileged(): - self.logger.error('The Linux Diverter requires administrative ' + - 'privileges') + self.logger.critical('The Linux Diverter requires ' + + 'administrative privileges') sys.exit(1) ret = self.linux_capture_iptables() @@ -132,7 +132,7 @@ def startCallback(self): 'numbers') % (nhooks)) qnos = self.linux_get_next_nfqueue_numbers(nhooks) if len(qnos) != nhooks: - self.logger.error('Could not procure a sufficient number of ' + + self.logger.critical('Could not procure a sufficient number of ' + 'netfilter queue numbers') sys.exit(1) @@ -149,7 +149,8 @@ def startCallback(self): self.nfqueues.append(q) ok = q.start() if not ok: - self.logger.error('Failed to start NFQUEUE for %s' % (str(q))) + self.logger.critical('Failed to start NFQUEUE for %s' + % (str(q))) self.stop() sys.exit(1) @@ -181,13 +182,13 @@ def startCallback(self): self.rules_added += rules if not ok: - self.logger.error('Failed to process LinuxRedirectNonlocal') + self.logger.critical('Failed to process LinuxRedirectNonlocal') self.stop() sys.exit(1) ok, rule = self.linux_redir_icmp() if not ok: - self.logger.error('Failed to redirect ICMP') + self.logger.critical('Failed to redirect ICMP') self.stop() sys.exit(1) @@ -212,7 +213,7 @@ def stopCallback(self): self.pdebug(DPCAP, 'Closing pcap file %s' % (self.pcap_filename)) self.pcap.close() # Only after all queues are stopped - self.logger.info('Stopped Linux Diverter') + self.logger.debug('Stopped Linux Diverter') if self.single_host_mode and self.is_set('modifylocaldns'): self.linux_restore_local_dns() @@ -311,7 +312,7 @@ def check_log_nonlocal(self, crit, pkt): # Log when a new IP is observed OR if we are not restricted to # logging only the first occurrence of a given nonlocal IP. if first_sighting or (not self.log_nonlocal_only_once): - self.logger.info( + self.logger.debug( 'Received nonlocal IPv%d datagram destined for %s' % (pkt.ipver, pkt.dst_ip)) diff --git a/fakenet/diverters/windows.py b/fakenet/diverters/windows.py index e98b346..81a4aee 100644 --- a/fakenet/diverters/windows.py +++ b/fakenet/diverters/windows.py @@ -99,7 +99,7 @@ def __init__(self, diverter_config, listeners_config, ip_addrs, self.running_on_windows = True if not self.single_host_mode: - self.logger.error('Windows diverter currently only supports ' + self.logger.critical('Windows diverter currently only supports ' 'SingleHost mode') sys.exit(1) @@ -113,7 +113,7 @@ def __init__(self, diverter_config, listeners_config, ip_addrs, if not self.external_ip: self.external_ip = socket.gethostbyname(socket.gethostname()) - self.logger.info('External IP: %s Loopback IP: %s' % + self.logger.debug('External IP: %s Loopback IP: %s' % (self.external_ip, self.loopback_ip)) ####################################################################### @@ -129,19 +129,19 @@ def __init__(self, diverter_config, listeners_config, ip_addrs, self.handle.open() except WindowsError, e: if e.winerror == 5: - self.logger.error('ERROR: Insufficient privileges to run ' + self.logger.critical('ERROR: Insufficient privileges to run ' 'windows diverter.') - self.logger.error(' Please restart with Administrator ' - 'privileges.') + self.logger.critical(' Please restart with ' + 'Administrator privileges.') sys.exit(1) elif e.winerror == 3: - self.logger.error('ERROR: Could not locate WinDivert DLL or ' - 'one of its components.') - self.logger.error(' Please make sure you have copied ' + self.logger.critical('ERROR: Could not locate WinDivert DLL ' + 'or one of its components.') + self.logger.critical(' Please make sure you have copied ' 'FakeNet-NG to the C: drive.') sys.exit(1) else: - self.logger.error('ERROR: Failed to open a handle to the ' + self.logger.critical('ERROR: Failed to open a handle to the ' 'WinDivert driver: %s', e) sys.exit(1) @@ -157,7 +157,7 @@ def startCallback(self): if self.is_set('stopdnsservice'): self.stop_service_helper('Dnscache') - self.logger.info('Diverting ports: ') + self.logger.debug('Diverting ports: ') self.flush_dns() @@ -298,11 +298,11 @@ def redirIcmpIpUnconditionally(self, crit, pkt): """ if (pkt.is_icmp and pkt.dst_ip not in [self.loopback_ip, self.external_ip]): - self.logger.info('Modifying ICMP packet (type %d, code %d):' % + self.logger.debug('Modifying ICMP packet (type %d, code %d):' % (pkt.icmp_type, pkt.icmp_code)) - self.logger.info(' from: %s' % (pkt.hdrToStr())) + self.logger.debug(' from: %s' % (pkt.hdrToStr())) pkt.dst_ip = self.getNewDestinationIp(pkt.src_ip) - self.logger.info(' to: %s' % (pkt.hdrToStr())) + self.logger.debug(' to: %s' % (pkt.hdrToStr())) return pkt diff --git a/fakenet/diverters/winutil.py b/fakenet/diverters/winutil.py index c2bef3f..ed3c22f 100644 --- a/fakenet/diverters/winutil.py +++ b/fakenet/diverters/winutil.py @@ -654,11 +654,11 @@ def start_service_helper(self, service_name='Dnscache'): self.logger.error( 'Failed to enable the service %s. (sc config)', service_name) else: - self.logger.info( + self.logger.debug( 'Successfully enabled the service %s. (sc config)', service_name) else: - self.logger.info('Successfully enabled the service %s.', + self.logger.debug('Successfully enabled the service %s.', service_name) service_status = self.query_service_status_ex(service_handle) diff --git a/fakenet/fakenet.py b/fakenet/fakenet.py index f07b466..7b9c36f 100644 --- a/fakenet/fakenet.py +++ b/fakenet/fakenet.py @@ -36,7 +36,7 @@ class Fakenet(object): def __init__(self, logging_level = logging.INFO): - self.logger = logging.getLogger('FakeNet') + self.logger = logging.getLogger('Fakenet') self.logger.setLevel(logging_level) self.logging_level = logging_level @@ -68,13 +68,14 @@ def parse_config(self, config_filename): if not os.path.exists(config_filename): - self.logger.error('Could not open configuration file %s', config_filename) + self.logger.critical('Could not open configuration file %s', + config_filename) sys.exit(1) config = ConfigParser() config.read(config_filename) - self.logger.info('Loaded configuration file: %s', config_filename) + self.logger.debug('Loaded configuration file: %s', config_filename) # Parse configuration for section in config.sections(): @@ -130,7 +131,9 @@ def start(self): if (('networkmode' not in self.diverter_config) or (self.diverter_config['networkmode'].lower() not in ['singlehost', 'multihost', 'auto'])): - self.logger.error('Error: You must configure a NetworkMode for Diverter, either SingleHost, MultiHost, or Auto') + self.logger.critical('Error: You must configure a ' + + 'NetworkMode for Diverter, either ' + + 'SingleHost, MultiHost, or Auto') sys.exit(1) # Select platform specific diverter @@ -144,8 +147,11 @@ def start(self): # Check Windows version if platform.release() in ['2000', 'XP', '2003Server', 'post2003']: - self.logger.error('Error: FakeNet-NG only supports Windows Vista+.') - self.logger.error(' Please use the original Fakenet for older versions of Windows.') + self.logger.critical('Error: FakeNet-NG only supports ' + + 'Windows Vista+.') + self.logger.critical(' Please use the original ' + + 'Fakenet for older versions of ' + + 'Windows.') sys.exit(1) if self.diverter_config['networkmode'].lower() == 'auto': @@ -162,7 +168,7 @@ def start(self): self.diverter = Diverter(self.diverter_config, self.listeners_config, ip_addrs, self.logging_level) else: - self.logger.error( + self.logger.critical( 'Error: Your system %s is currently not supported.' % (platform_name)) sys.exit(1) @@ -174,7 +180,9 @@ def start(self): # Anonymous listener if not 'listener' in listener_config: - self.logger.info('Anonymous %s listener on %s port %s...', listener_name, listener_config['protocol'], listener_config['port']) + self.logger.debug('Anonymous %s listener on %s port %s...', + listener_name, listener_config['protocol'], + listener_config['port']) continue # Get a specific provider for the listener name diff --git a/fakenet/listeners/DNSListener.py b/fakenet/listeners/DNSListener.py index 1b1b287..a2a2ae7 100644 --- a/fakenet/listeners/DNSListener.py +++ b/fakenet/listeners/DNSListener.py @@ -39,7 +39,7 @@ def __init__( self.name = 'DNS' self.port = self.config.get('port', 53) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -83,10 +83,10 @@ def parse(self,data): except Exception, e: self.server.logger.error('Error: Invalid DNS Request') - self.server.logger.info('%s', '-'*80) + self.server.logger.debug('%s', '-'*80) for line in hexdump_table(data): self.server.logger.info(line) - self.server.logger.info('%s', '-'*80,) + self.server.logger.debug('%s', '-'*80,) else: # Only Process DNS Queries @@ -157,10 +157,12 @@ def parse(self,data): fake_record = socket.gethostbyname(socket.gethostname()) if self.server.nxdomains > 0: - self.server.logger.info('Ignoring query. NXDomains: %d', self.server.nxdomains) + self.server.logger.debug('Ignoring query. NXDomains:' + + ' %d', self.server.nxdomains) self.server.nxdomains -= 1 else: - self.server.logger.info('Responding with \'%s\'', fake_record) + self.server.logger.debug('Responding with \'%s\'', + fake_record) response.add_answer(RR(qname, getattr(QTYPE,qtype), rdata=RDMAP[qtype](fake_record))) elif qtype == 'MX': @@ -170,7 +172,7 @@ def parse(self,data): # dnslib doesn't like trailing dots if fake_record[-1] == ".": fake_record = fake_record[:-1] - self.server.logger.info('Responding with \'%s\'', fake_record) + self.server.logger.debug('Responding with \'%s\'', fake_record) response.add_answer(RR(qname, getattr(QTYPE,qtype), rdata=RDMAP[qtype](fake_record))) @@ -178,7 +180,8 @@ def parse(self,data): fake_record = self.server.config.get('responsetxt', 'FAKENET') - self.server.logger.info('Responding with \'%s\'', fake_record) + self.server.logger.debug('Responding with \'%s\'', + fake_record) response.add_answer(RR(qname, getattr(QTYPE,qtype), rdata=RDMAP[qtype](fake_record))) response = response.pack() @@ -224,7 +227,7 @@ def handle(self): self.request.sendall(length+response) except socket.timeout: - self.server.logger.warning('Connection timeout.') + self.server.logger.debug('Connection timeout.') except socket.error as msg: self.server.logger.error('Error: %s', msg.strerror) diff --git a/fakenet/listeners/FTPListener.py b/fakenet/listeners/FTPListener.py index 9551b8e..3a4c5c3 100644 --- a/fakenet/listeners/FTPListener.py +++ b/fakenet/listeners/FTPListener.py @@ -244,7 +244,7 @@ def __init__(self, self.name = 'FTP' self.port = self.config.get('port', 21) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): diff --git a/fakenet/listeners/HTTPListener.py b/fakenet/listeners/HTTPListener.py index 381cff5..4fc1a76 100644 --- a/fakenet/listeners/HTTPListener.py +++ b/fakenet/listeners/HTTPListener.py @@ -112,7 +112,7 @@ def start(self): self.server_thread.start() def stop(self): - self.logger.info('Stopping...') + self.logger.debug('Stopping...') if self.server: self.server.shutdown() self.server.server_close() @@ -245,7 +245,8 @@ def get_response(self, path): self.server.logger.error('Could not locate requested file or default handler.') return (response, response_type) - self.server.logger.info('Responding with mime type: %s file: %s', response_type, response_filename) + self.server.logger.debug('Responding with mime type: %s file: %s', + response_type, response_filename) try: f = open(response_filename, 'rb') diff --git a/fakenet/listeners/IRCListener.py b/fakenet/listeners/IRCListener.py index cbe839a..349eb0a 100644 --- a/fakenet/listeners/IRCListener.py +++ b/fakenet/listeners/IRCListener.py @@ -83,7 +83,7 @@ def __init__(self, self.port = self.config.get('port', 6667) self.logger.debug('PORT: %s', self.port) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -105,7 +105,7 @@ def start(self): self.server_thread.start() def stop(self): - self.logger.info('Stopping...') + self.logger.debug('Stopping...') if self.server: self.server.shutdown() self.server.server_close() @@ -147,7 +147,7 @@ def handle(self): handler(cmd, params) except socket.timeout: - self.server.logger.warning('Connection timeout') + self.server.logger.debug('Connection timeout') except socket.error as msg: self.server.logger.error('Error: %s', msg.strerror or msg) diff --git a/fakenet/listeners/POPListener.py b/fakenet/listeners/POPListener.py index fedc57a..257b4fe 100644 --- a/fakenet/listeners/POPListener.py +++ b/fakenet/listeners/POPListener.py @@ -58,7 +58,7 @@ def __init__(self, self.name = 'POP' self.port = self.config.get('port', 110) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -94,7 +94,7 @@ def start(self): self.server_thread.start() def stop(self): - self.logger.info('Stopping...') + self.logger.debug('Stopping...') if self.server: self.server.shutdown() self.server.server_close() @@ -131,7 +131,7 @@ def handle(self): handler(cmd, params) except socket.timeout: - self.server.logger.warning('Connection timeout') + self.server.logger.debug('Connection timeout') except socket.error as msg: self.server.logger.error('Error: %s', msg.strerror or msg) diff --git a/fakenet/listeners/ProxyListener.py b/fakenet/listeners/ProxyListener.py index 33b193d..6f633e0 100644 --- a/fakenet/listeners/ProxyListener.py +++ b/fakenet/listeners/ProxyListener.py @@ -35,7 +35,7 @@ def __init__( self.server = None self.udp_fwd_table = dict() - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -78,7 +78,7 @@ def start(self): self.server_thread.daemon = True self.server_thread.start() server_ip, server_port = self.server.server_address - self.logger.info("%s Server(%s:%d) thread: %s" % (proto, server_ip, + self.logger.debug("%s Server(%s:%d) thread: %s" % (proto, server_ip, server_port, self.server_thread.name)) def stop(self): @@ -185,7 +185,7 @@ def handle(self): try: data = remote_sock.recv(BUF_SZ, socket.MSG_PEEK) - self.server.logger.info('Received %d bytes.', len(data)) + self.server.logger.debug('Received %d bytes.', len(data)) self.server.logger.debug('%s', '-'*80,) for line in hexdump_table(data): self.server.logger.debug(line) @@ -267,7 +267,7 @@ def handle(self): if data: - self.server.logger.info('Received %d bytes.', len(data)) + self.server.logger.debug('Received %d bytes.', len(data)) self.server.logger.debug('%s', '-'*80,) for line in hexdump_table(data): self.server.logger.debug(line) @@ -287,7 +287,7 @@ def handle(self): sock.sendto(data, ('localhost', int(top_listener.port))) reply = sock.recv(BUF_SZ) - self.server.logger.info('Received %d bytes.', len(data)) + self.server.logger.debug('Received %d bytes.', len(data)) sock.close() remote_sock.sendto(reply, (orig_src_ip, int(orig_src_port))) else: diff --git a/fakenet/listeners/RawListener.py b/fakenet/listeners/RawListener.py index 0fbe619..55685e8 100644 --- a/fakenet/listeners/RawListener.py +++ b/fakenet/listeners/RawListener.py @@ -32,7 +32,7 @@ def __init__(self, self.name = 'Raw' self.port = self.config.get('port', 1337) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -113,7 +113,7 @@ def handle(self): self.request.sendall(data) except socket.timeout: - self.server.logger.warning('Connection timeout') + self.server.logger.debug('Connection timeout') except socket.error as msg: self.server.logger.error('Error: %s', msg.strerror or msg) diff --git a/fakenet/listeners/SMTPListener.py b/fakenet/listeners/SMTPListener.py index 8c33225..5e6bf26 100644 --- a/fakenet/listeners/SMTPListener.py +++ b/fakenet/listeners/SMTPListener.py @@ -50,7 +50,7 @@ def __init__( self.name = 'SMTP' self.port = self.config.get('port', 25) - self.logger.info('Starting...') + self.logger.debug('Starting...') self.logger.debug('Initialized with config:') for key, value in config.iteritems(): @@ -86,7 +86,7 @@ def start(self): self.server_thread.start() def stop(self): - self.logger.info('Stopping...') + self.logger.debug('Stopping...') if self.server: self.server.shutdown() self.server.server_close() @@ -145,7 +145,7 @@ def handle(self): self.request.sendall("503 Command not supported\r\n") except socket.timeout: - self.server.logger.warning('Connection timeout') + self.server.logger.debug('Connection timeout') except socket.error as msg: self.server.logger.error('Error: %s', msg.strerror or msg) diff --git a/fakenet/listeners/TFTPListener.py b/fakenet/listeners/TFTPListener.py index c209800..b850d72 100644 --- a/fakenet/listeners/TFTPListener.py +++ b/fakenet/listeners/TFTPListener.py @@ -95,7 +95,7 @@ def __init__(self, self.tftp_file_prefix = self.config.get('tftpfileprefix', 'tftp') def start(self): - self.logger.info('Starting...') + self.logger.debug('Starting...') # Start listener self.server = ThreadedUDPServer((self.local_ip, int(self.config['port'])), ThreadedUDPRequestHandler) From 93c300793d5d92087d27c5eea6bc7c53bbec38bc Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Fri, 5 Oct 2018 14:26:39 -0400 Subject: [PATCH 2/9] reduced additional output in Windows --- fakenet/diverters/diverterbase.py | 2 +- fakenet/diverters/winutil.py | 138 +++++++++++++++--------------- 2 files changed, 71 insertions(+), 69 deletions(-) diff --git a/fakenet/diverters/diverterbase.py b/fakenet/diverters/diverterbase.py index e4cba6d..4d2b320 100644 --- a/fakenet/diverters/diverterbase.py +++ b/fakenet/diverters/diverterbase.py @@ -626,7 +626,7 @@ def __init__(self, diverter_config, listeners_config, ip_addrs, # Check configured DNS servers dns_ok = self.check_dns_servers() if not dns_ok: - self.logger.warning('WARNING: No DNS servers configured!') + self.logger.debug('WARNING: No DNS servers configured!') if self.is_set('fixdns'): dns_ok = self.fix_dns() if not dns_ok: diff --git a/fakenet/diverters/winutil.py b/fakenet/diverters/winutil.py index ed3c22f..82fedd3 100644 --- a/fakenet/diverters/winutil.py +++ b/fakenet/diverters/winutil.py @@ -380,11 +380,13 @@ def fix_gateway(self): stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error(" Failed to set gateway %s on interface %s." % ( - gw_address, interface_name)) + self.logger.debug(" Failed to set gateway %s" + + "on interface %s." % (gw_address, + interface_name)) else: - self.logger.info(" Setting gateway %s on interface %s" % ( - gw_address, interface_name)) + self.logger.debug(" Setting gateway %s on "+ + "interface %s" % (gw_address, + interface_name)) fixed = True return fixed @@ -421,11 +423,11 @@ def fix_dns(self): stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error(" Failed to set DNS %s on interface %s." % ( - dns_address, interface_name)) + self.logger.debug(" Failed to set DNS %s on interface %s." + % (dns_address, interface_name)) else: - self.logger.info(" Setting DNS %s on interface %s" % ( - dns_address, interface_name)) + self.logger.debug(" Setting DNS %s on interface %s" + % (dns_address, interface_name)) fixed = True return fixed @@ -491,7 +493,7 @@ def open_sc_manager(self): sc_handle = windll.advapi32.OpenSCManagerA(0, 0, SC_MANAGER_ALL_ACCESS) if sc_handle == 0: - self.logger.error("Failed to call OpenSCManager") + self.logger.debug("Failed to call OpenSCManager") return return sc_handle @@ -506,7 +508,7 @@ def open_sc_manager(self): def close_service_handle(self, sc_handle): if windll.advapi32.CloseServiceHandle(sc_handle) == 0: - self.logger.error('Failed to call CloseServiceHandle') + self.logger.debug('Failed to call CloseServiceHandle') return False return True @@ -530,7 +532,7 @@ def open_service(self, sc_handle, service_name, dwDesiredAccess) if service_handle == 0: - self.logger.error('Failed to call OpenService') + self.logger.debug('Failed to call OpenService') return return service_handle @@ -553,7 +555,7 @@ def query_service_status_ex(self, service_handle): pcbBytesNeeded = DWORD() if windll.advapi32.QueryServiceStatusEx(service_handle, SC_STATUS_PROCESS_INFO, byref(lpBuffer), cbBufSize, byref(pcbBytesNeeded)) == 0: - self.logger.error('Failed to call QueryServiceStatusEx') + self.logger.debug('Failed to call QueryServiceStatusEx') return return lpBuffer @@ -572,7 +574,7 @@ def control_service(self, service_handle, dwControl): lpServiceStatus = SERVICE_STATUS_PROCESS() if windll.advapi32.ControlService(service_handle, dwControl, byref(lpServiceStatus)) == 0: - self.logger.error('Failed to call ControlService') + self.logger.debug('Failed to call ControlService') return return lpServiceStatus @@ -616,7 +618,7 @@ def change_service_config(self, service_handle, dwStartType=SERVICE_DISABLED): if windll.advapi32.ChangeServiceConfigA(service_handle, SERVICE_NO_CHANGE, dwStartType, SERVICE_NO_CHANGE, 0, 0, 0, 0, 0, 0, 0) == 0: - self.logger.error('Failed to call ChangeServiceConfig') + self.logger.debug('Failed to call ChangeServiceConfig') raise WinError(get_last_error()) return False @@ -651,7 +653,7 @@ def start_service_helper(self, service_name='Dnscache'): stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error( + self.logger.debug( 'Failed to enable the service %s. (sc config)', service_name) else: self.logger.debug( @@ -678,17 +680,17 @@ def start_service_helper(self, service_name='Dnscache'): service_status = self.query_service_status_ex( service_handle) if service_status.dwCurrentState == SERVICE_RUNNING: - self.logger.info( + self.logger.debug( 'Successfully started the service %s.', service_name) break else: - self.logger.error( + self.logger.debug( 'Timed out while trying to start the service %s.', service_name) else: - self.logger.error( + self.logger.debug( 'Failed to start the service %s.', service_name) else: - self.logger.error( + self.logger.debug( 'Service %s is already running.', service_name) # As a backup call net stop @@ -699,10 +701,10 @@ def start_service_helper(self, service_name='Dnscache'): shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error( + self.logger.debug( 'Failed to start the service %s. (net stop)', service_name) else: - self.logger.info('Successfully started the service %s.', + self.logger.debug('Successfully started the service %s.', service_name) self.close_service_handle(service_handle) @@ -738,14 +740,14 @@ def stop_service_helper(self, service_name='Dnscache'): stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error( + self.logger.debug( 'Failed to disable the service %s. (sc config)', service_name) else: - self.logger.info( + self.logger.debug( 'Successfully disabled the service %s. (sc config)', service_name) else: - self.logger.info( + self.logger.debug( 'Successfully disabled the service %s.', service_name) service_status = self.query_service_status_ex(service_handle) @@ -765,18 +767,18 @@ def stop_service_helper(self, service_name='Dnscache'): service_status = self.query_service_status_ex( service_handle) if service_status.dwCurrentState == SERVICE_STOPPED: - self.logger.info( + self.logger.debug( 'Successfully stopped the service %s.', service_name) break else: - self.logger.error( + self.logger.debug( 'Timed out while trying to stop the service %s.', service_name) else: - self.logger.error( + self.logger.debug( 'Failed to stop the service %s.', service_name) else: - self.logger.error( + self.logger.debug( 'Service %s is already stopped.', service_name) # As a backup call net stop @@ -787,10 +789,10 @@ def stop_service_helper(self, service_name='Dnscache'): shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error( + self.logger.debug( 'Failed to stop the service %s. (net stop)', service_name) else: - self.logger.info( + self.logger.debug( 'Successfully stopped the service %s.', service_name) self.close_service_handle(service_handle) @@ -819,7 +821,7 @@ def get_extended_tcp_table(self): TcpTable = MIB_TCPTABLE_OWNER_PID() if windll.iphlpapi.GetExtendedTcpTable(byref(TcpTable), byref(dwSize), False, AF_INET, TCP_TABLE_OWNER_PID_ALL, 0) != NO_ERROR: - self.logger.error("Failed to call GetExtendedTcpTable") + self.logger.debug("Failed to call GetExtendedTcpTable") return for item in TcpTable.table[:TcpTable.dwNumEntries]: @@ -857,7 +859,7 @@ def get_extended_udp_table(self): UdpTable = MIB_UDPTABLE_OWNER_PID() if windll.iphlpapi.GetExtendedUdpTable(byref(UdpTable), byref(dwSize), False, AF_INET, UDP_TABLE_OWNER_PID, 0) != NO_ERROR: - self.logger.error("Failed to call GetExtendedUdpTable") + self.logger.debug("Failed to call GetExtendedUdpTable") return for item in UdpTable.table[:UdpTable.dwNumEntries]: @@ -902,7 +904,7 @@ def get_process_image_filename(self, pid): if windll.psapi.GetProcessImageFileNameA(hProcess, lpImageFileName, MAX_PATH) > 0: process_name = os.path.basename(lpImageFileName.value) else: - self.logger.error('Failed to call GetProcessImageFileNameA, %d' % + self.logger.debug('Failed to call GetProcessImageFileNameA, %d' % (ctypes.GetLastError())) windll.kernel32.CloseHandle(hProcess) @@ -954,7 +956,7 @@ def get_adapters_addresses(self): POINTER(IP_ADAPTER_ADDRESSES)) if not windll.iphlpapi.GetAdaptersAddresses(AF_INET, 0, None, pAdapterAddresses, byref(Size)) == NO_ERROR: - self.logger.error('Failed calling GetAdaptersAddresses') + self.logger.debug('Failed calling GetAdaptersAddresses') return while pAdapterAddresses: @@ -1008,7 +1010,7 @@ def get_adapters_info(self): pAdapterInfo = cast(AdapterInfo, POINTER(IP_ADAPTER_INFO)) if not windll.iphlpapi.GetAdaptersInfo(byref(AdapterInfo), byref(OutBufLen)) == NO_ERROR: - self.logger.error('Failed calling GetAdaptersInfo') + self.logger.debug('Failed calling GetAdaptersInfo') return while pAdapterInfo: @@ -1080,7 +1082,7 @@ def get_network_params(self): FixedInfo = FIXED_INFO() if not windll.iphlpapi.GetNetworkParams(byref(FixedInfo), byref(OutBufLen)) == NO_ERROR: - self.logger.error('Failed calling GetNetworkParams') + self.logger.debug('Failed calling GetNetworkParams') return None return FixedInfo @@ -1112,7 +1114,7 @@ def get_best_interface(self, ip='8.8.8.8'): DestAddr = socket.inet_aton(ip) if not windll.iphlpapi.GetBestInterface(DestAddr, byref(BestIfIndex)) == NO_ERROR: - self.logger.error('Failed calling GetBestInterface') + self.logger.debug('Failed calling GetBestInterface') return None return BestIfIndex.value @@ -1159,13 +1161,13 @@ def convert_interface_index_to_name(self, index): InterfaceLuid = ULONG64() if not windll.iphlpapi.ConvertInterfaceIndexToLuid(index, byref(InterfaceLuid)) == NO_ERROR: - self.logger.error('Failed calling ConvertInterfaceIndexToLuid') + self.logger.debug('Failed calling ConvertInterfaceIndexToLuid') return None InterfaceName = create_string_buffer(NDIS_IF_MAX_STRING_SIZE + 1) if not windll.iphlpapi.ConvertInterfaceLuidToNameA(byref(InterfaceLuid), InterfaceName, NDIS_IF_MAX_STRING_SIZE + 1) == NO_ERROR: - self.logger.error('Failed calling ConvertInterfaceLuidToName') + self.logger.debug('Failed calling ConvertInterfaceLuidToName') return None return InterfaceName.value @@ -1188,7 +1190,7 @@ def notify_ip_change(self, adapter_name): self.logger.debug( 'Successfully performed adapter change notification on %s', adapter_name) else: - self.logger.error('Failed to notify adapter change on %s', + self.logger.debug('Failed to notify adapter change on %s', adapter_name) ########################################################################### @@ -1199,10 +1201,10 @@ def flush_dns(self): subprocess.check_call( 'ipconfig /flushdns', shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE) except subprocess.CalledProcessError, e: - self.logger.error("Failed to flush DNS cache. Local machine may " + self.logger.debug("Failed to flush DNS cache. Local machine may " "use cached DNS results.") else: - self.logger.info('Flushed DNS cache.') + self.logger.debug('Flushed DNS cache.') def get_reg_value(self, key, sub_key, value, sam=KEY_READ): @@ -1216,7 +1218,7 @@ def get_reg_value(self, key, sub_key, value, sam=KEY_READ): return data except WindowsError: - self.logger.error('Failed getting registry value %s.', value) + self.logger.debug('Failed getting registry value %s.', value) return None def set_reg_value(self, key, sub_key, value, data, type=REG_SZ, sam=KEY_WRITE): @@ -1229,7 +1231,7 @@ def set_reg_value(self, key, sub_key, value, data, type=REG_SZ, sam=KEY_WRITE): return True except WindowsError: - self.logger.error('Failed setting registry value %s', value) + self.logger.debug('Failed setting registry value %s', value) return False ########################################################################### @@ -1258,11 +1260,11 @@ def set_dns_server(self, dns_server='127.0.0.1'): # Set new dns server value if self.set_reg_value(key, sub_key % adapter.AdapterName, value, dns_server): - self.logger.info('Set DNS server %s on the adapter: %s', + self.logger.debug('Set DNS server %s on the adapter: %s', dns_server, adapter.FriendlyName) self.notify_ip_change(adapter.AdapterName) else: - self.logger.error( + self.logger.debug( 'Failed to set DNS server %s on the adapter: %s', dns_server, adapter.FriendlyName) def restore_dns_server(self): @@ -1278,10 +1280,10 @@ def restore_dns_server(self): # Restore dns server value if self.set_reg_value(key, sub_key % adapter_name, value, dns_server): - self.logger.info('Restored DNS server %s on the adapter: %s', + self.logger.debug('Restored DNS server %s on the adapter: %s', dns_server, adapter_friendlyname) else: - self.logger.error( + self.logger.debug( 'Failed to restore DNS server %s on the adapter: %s', dns_server, adapter_friendlyname) @@ -1295,26 +1297,26 @@ def __init__(self, name='WinUtil'): pid = self._get_pid_port_tcp(135) if pid: - self.logger.info('pid: %d name: %s', pid, + self.logger.debug('pid: %d name: %s', pid, self.get_process_image_filename(pid)) else: - self.logger.error('failed to get pid for tcp port 135') + self.logger.debug('failed to get pid for tcp port 135') pid = self._get_pid_port_udp(123) if pid: - self.logger.info('pid: %d name: %s', pid, + self.logger.debug('pid: %d name: %s', pid, self.get_process_image_filename(pid)) else: - self.logger.error('failed to get pid for udp port 123') + self.logger.debug('failed to get pid for udp port 123') pid = self._get_pid_port_tcp(1234) if not pid: - self.logger.info('successfully returned None for unknown tcp port ' + self.logger.debug('successfully returned None for unknown tcp port ' '1234') pid = self._get_pid_port_udp(1234) if not pid: - self.logger.info('successfully returned None for unknown udp port ' + self.logger.debug('successfully returned None for unknown udp port ' '1234') @@ -1330,13 +1332,13 @@ def __init__(self, name='WinUtil'): # self.logger.info('ethernet: %s enabled: %s index: %d friendlyname: %s name: %s', adapter.IfType == MIB_IF_TYPE_ETHERNET, adapter.OperStatus == IFOPERSTATUSUP, adapter.IfIndex, adapter.FriendlyName, adapter.AdapterName) for dns_server in self.get_dns_servers(): - self.logger.info('dns: %s', dns_server) + self.logger.debug('dns: %s', dns_server) for gateway in self.get_gateways(): - self.logger.info('gateway: %s', gateway) + self.logger.debug('gateway: %s', gateway) for adapter in self.get_active_ethernet_adapters(): - self.logger.info('active ethernet index: %s friendlyname: %s name: %s', + self.logger.debug('active ethernet index: %s friendlyname: %s name: %s', adapter.IfIndex, adapter.FriendlyName, adapter.AdapterName) @@ -1354,15 +1356,15 @@ def __init__(self, name='WinUtil'): data = '127.0.0.1' data_tmp = self.get_reg_value(key, sub_key, value) - self.logger.info('NameServer: %s', data_tmp) + self.logger.debug('NameServer: %s', data_tmp) if self.set_reg_value(key, sub_key, value, data): - self.logger.info('Successfully set value %s to data %s', value, data) + self.logger.debug('Successfully set value %s to data %s', value, data) data_tmp = self.get_reg_value(key, sub_key, value) - self.logger.info('Nameserver: %s', data_tmp) + self.logger.debug('Nameserver: %s', data_tmp) else: - self.logger.info('Failed to set value %s to data %s', value, data) + self.logger.debug('Failed to set value %s to data %s', value, data) self.notify_ip_change('{cd17d5b5-bf83-44f5-8de7-d988e3db5451}') @@ -1383,7 +1385,7 @@ def __init__(self, name='WinUtil'): #data = '127.0.0.1' if self.get_reg_value(key, sub_key, 'DhcpDefaultGateway'): - self.logger.info('DefaultGateway is set') + self.logger.debug('DefaultGateway is set') else: ip = self.get_reg_value(key, sub_key, 'Dhcp') @@ -1403,22 +1405,22 @@ def __init__(self, name='WinUtil'): if not self.check_gateways(): self.logger.warning('No gateways found.') else: - self.logger.info('Gateways PASS') + self.logger.debug('Gateways PASS') if not self.check_active_ethernet_adapters(): self.logger.warning('No active ethernet adapters found') else: - self.logger.info('Active ethernet PASS') + self.logger.debug('Active ethernet PASS') if not self.get_best_interface(): self.logger.warning('No routable interface found.') else: - self.logger.info('Routable interface PASS') + self.logger.debug('Routable interface PASS') if not self.check_dns_servers(): self.logger.warning('No DNS servers configured') else: - self.logger.info('DNS server PASS') + self.logger.debug('DNS server PASS') def test_stop_service(): @@ -1450,10 +1452,10 @@ def __init__(self, name='WinUtil'): self = Test() ipaddress = self.get_best_ipaddress() - self.logger.info("Best ip address: %s" % ipaddress) + self.logger.debug("Best ip address: %s" % ipaddress) ipaddress = self.get_ip_with_gateway() - self.logger.info("IP with gateway address: %s" % ipaddress) + self.logger.debug("IP with gateway address: %s" % ipaddress) def main(): From 9fb768cb6d53d65eb2a21a02b044d3ee1251d4da Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Wed, 10 Oct 2018 10:32:13 -0700 Subject: [PATCH 3/9] proxy hangs on server first connections corrected --- fakenet/listeners/ProxyListener.py | 49 ++++++++++++++++++++++++------ fakenet/listeners/SMTPListener.py | 3 +- test/test.py | 2 ++ 3 files changed, 43 insertions(+), 11 deletions(-) diff --git a/fakenet/listeners/ProxyListener.py b/fakenet/listeners/ProxyListener.py index 33b193d..c669647 100644 --- a/fakenet/listeners/ProxyListener.py +++ b/fakenet/listeners/ProxyListener.py @@ -181,22 +181,35 @@ def handle(self): sys.exit(1) ssl_version = ssl.PROTOCOL_SSLv23 + possible_srvr_first_proto = False + is_ssl = False try: + remote_sock.settimeout(1) data = remote_sock.recv(BUF_SZ, socket.MSG_PEEK) - self.server.logger.info('Received %d bytes.', len(data)) - self.server.logger.debug('%s', '-'*80,) - for line in hexdump_table(data): - self.server.logger.debug(line) - self.server.logger.debug('%s', '-'*80,) + except socket.timeout: + self.logger.debug('Socket timeout. Possible server-first protocol') + possible_srvr_first_proto = True + # prepare to send an arbitrary byte to initiate protocol + data = '\x01' except Exception as e: self.server.logger.info('recv() error: %s' % e.message) + finally: + remote_sock.settimeout(None) + if data: + if not possible_srvr_first_proto: + self.server.logger.info('Received %d bytes.', len(data)) + self.server.logger.debug('%s', '-'*80,) + for line in hexdump_table(data): + self.server.logger.debug(line) + self.server.logger.debug('%s', '-'*80,) if ssl_detector.looks_like_ssl(data): + is_ssl = True self.server.logger.debug('SSL detected') ssl_remote_sock = ssl.wrap_socket( remote_sock, @@ -205,7 +218,19 @@ def handle(self): certfile=certfile_path, ssl_version=ssl_version, keyfile=keyfile_path ) - data = ssl_remote_sock.recv(BUF_SZ) + ssl_remote_sock.settimeout(1) + try: + data = ssl_remote_sock.recv(BUF_SZ) + except ssl.SSLError as e: + self.server.logger.info( + 'SSL timeout. Possible server-first protocol') + possible_srvr_first_proto = True + + except Exception as e: + self.server.logger.info('recv() error: %s' % e.message) + + finally: + remote_sock.settimeout(None) orig_src_ip = self.client_address[0] orig_src_port = self.client_address[1] @@ -224,12 +249,16 @@ def handle(self): listener_sock.start() remote_sock.setblocking(0) - # ssl has no 'peek' option, so we need to process the first + # ssl has no 'peek' option, so we need to process the first # packet that is already consumed from the socket - if ssl_remote_sock: - ssl_remote_sock.setblocking(0) + if is_ssl and not possible_srvr_first_proto: remote_q.put(data) - + + # send the first packet to the listener twice to initiate + # server-first protocol + elif not is_ssl and possible_srvr_first_proto: + remote_q.put(data) + while True: readable, writable, exceptional = select.select( [remote_sock], [], [], .001) diff --git a/fakenet/listeners/SMTPListener.py b/fakenet/listeners/SMTPListener.py index 8c33225..e8f5d62 100644 --- a/fakenet/listeners/SMTPListener.py +++ b/fakenet/listeners/SMTPListener.py @@ -15,6 +15,7 @@ class SMTPListener(object): def taste(self, data, dport): + # Once the TCP connection has been established, the server initiates # the conversation with '220' message. However, if the client connects # to a nonstandard port there is no way for the proxy to know that @@ -24,7 +25,7 @@ def taste(self, data, dport): 'RSET', 'VRFY', 'HELP', 'QUIT', 'X-EXPS GSSAPI', 'X-EXPS=LOGIN', 'X-EXCH50', 'X-LINK2STATE'] ports = [25, 587, 465] - confidence = 1 if dport in ports else 0 + confidence = 2 if dport in ports else 0 for command in commands: if data.lstrip().startswith(command): diff --git a/test/test.py b/test/test.py index e4a59ec..53234c9 100644 --- a/test/test.py +++ b/test/test.py @@ -508,6 +508,8 @@ def _test_smtp_ssl(self, sender, recipient, msg, hostname, port=None, timeout=5) server.sendmail(sender, recipient, msg) smtpserver.quit() + return True + def _test_smtp(self, sender, recipient, msg, hostname, port=None, timeout=5): smtpserver = smtplib.SMTP(hostname, port, 'fake.net', timeout) smtpserver.sendmail(sender, recipient, msg) From 062457e6956143baa7f5f3e5be74b04c6439dc0b Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Wed, 10 Oct 2018 13:54:30 -0400 Subject: [PATCH 4/9] fixed strange typo in test.py --- test/test.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/test.py b/test/test.py index 53234c9..5bcca30 100644 --- a/test/test.py +++ b/test/test.py @@ -505,7 +505,7 @@ def _test_ns(self, hostname, expected): def _test_smtp_ssl(self, sender, recipient, msg, hostname, port=None, timeout=5): smtpserver = smtplib.SMTP_SSL(hostname, port, 'fake.net', None, None, timeout) - server.sendmail(sender, recipient, msg) + smtpserver.sendmail(sender, recipient, msg) smtpserver.quit() return True From b912dede91b160075b1ba1ca3fea4ec0324156af Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Wed, 10 Oct 2018 13:57:55 -0400 Subject: [PATCH 5/9] removed superflous empty line --- fakenet/listeners/SMTPListener.py | 1 - 1 file changed, 1 deletion(-) diff --git a/fakenet/listeners/SMTPListener.py b/fakenet/listeners/SMTPListener.py index e8f5d62..3cef5d9 100644 --- a/fakenet/listeners/SMTPListener.py +++ b/fakenet/listeners/SMTPListener.py @@ -15,7 +15,6 @@ class SMTPListener(object): def taste(self, data, dport): - # Once the TCP connection has been established, the server initiates # the conversation with '220' message. However, if the client connects # to a nonstandard port there is no way for the proxy to know that From 8e83050067abdc2ae7f7a6fa25111abf4c5e099a Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Thu, 11 Oct 2018 06:41:06 -0700 Subject: [PATCH 6/9] added logging of all connections for http --- fakenet/listeners/HTTPListener.py | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/fakenet/listeners/HTTPListener.py b/fakenet/listeners/HTTPListener.py index 381cff5..1a52790 100644 --- a/fakenet/listeners/HTTPListener.py +++ b/fakenet/listeners/HTTPListener.py @@ -123,6 +123,12 @@ class ThreadedHTTPServer(BaseHTTPServer.HTTPServer): def handle_error(self, request, client_address): exctype, value = sys.exc_info()[:2] self.logger.error('Error: %s', value) + + # Log connections regardless of HTTP requests + def get_request(self): + conn, address = self.socket.accept() + self.logger.info('HTTP Connection received from %s:%s' % (address)) + return (conn, address) class ThreadedHTTPRequestHandler(BaseHTTPServer.BaseHTTPRequestHandler): From 783151762e9fff066bb90e2963c1cf69e6746b3a Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Thu, 11 Oct 2018 07:05:48 -0700 Subject: [PATCH 7/9] removed additional logging statement --- fakenet/listeners/ProxyListener.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/fakenet/listeners/ProxyListener.py b/fakenet/listeners/ProxyListener.py index 6f633e0..7de15dc 100644 --- a/fakenet/listeners/ProxyListener.py +++ b/fakenet/listeners/ProxyListener.py @@ -192,7 +192,7 @@ def handle(self): self.server.logger.debug('%s', '-'*80,) except Exception as e: - self.server.logger.info('recv() error: %s' % e.message) + self.server.logger.warning('recv() error: %s' % e.message) if data: @@ -316,7 +316,7 @@ def main(): TCP_server_thread.daemon = True TCP_server_thread.start() tcp_server_ip, tcp_server_port = TCP_server.server_address - logger.info("TCP Server(%s:%d) thread: %s" % (tcp_server_ip, + logger.debug("TCP Server(%s:%d) thread: %s" % (tcp_server_ip, tcp_server_port, TCP_server_thread.name)) try: @@ -326,9 +326,9 @@ def main(): logger.info(e) TCP_server.shutdown() finally: - logger.info('Closing ProxyListener') + logger.debug('Closing ProxyListener') exit(1) - logger.info('Exiting') + logger.debug('Exiting') TCP_server.shutdown() if __name__ == '__main__': From 7e9761f3b3b8c9e5f2cf74810999874917b3fd0a Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Thu, 11 Oct 2018 08:06:42 -0700 Subject: [PATCH 8/9] unraveling strange inclusion of unrelated branch --- fakenet/listeners/ProxyListener.py | 49 ++++++------------------------ 1 file changed, 10 insertions(+), 39 deletions(-) diff --git a/fakenet/listeners/ProxyListener.py b/fakenet/listeners/ProxyListener.py index 69448ff..7de15dc 100644 --- a/fakenet/listeners/ProxyListener.py +++ b/fakenet/listeners/ProxyListener.py @@ -181,35 +181,22 @@ def handle(self): sys.exit(1) ssl_version = ssl.PROTOCOL_SSLv23 - possible_srvr_first_proto = False - is_ssl = False try: - remote_sock.settimeout(1) data = remote_sock.recv(BUF_SZ, socket.MSG_PEEK) - except socket.timeout: - self.server.logger.debug('Socket timeout. Possible server-first protocol') - possible_srvr_first_proto = True - # prepare to send an arbitrary byte to initiate protocol - data = '\x01' + self.server.logger.debug('Received %d bytes.', len(data)) + self.server.logger.debug('%s', '-'*80,) + for line in hexdump_table(data): + self.server.logger.debug(line) + self.server.logger.debug('%s', '-'*80,) except Exception as e: self.server.logger.warning('recv() error: %s' % e.message) - finally: - remote_sock.settimeout(None) - if data: - if not possible_srvr_first_proto: - self.server.logger.info('Received %d bytes.', len(data)) - self.server.logger.debug('%s', '-'*80,) - for line in hexdump_table(data): - self.server.logger.debug(line) - self.server.logger.debug('%s', '-'*80,) if ssl_detector.looks_like_ssl(data): - is_ssl = True self.server.logger.debug('SSL detected') ssl_remote_sock = ssl.wrap_socket( remote_sock, @@ -218,19 +205,7 @@ def handle(self): certfile=certfile_path, ssl_version=ssl_version, keyfile=keyfile_path ) - ssl_remote_sock.settimeout(1) - try: - data = ssl_remote_sock.recv(BUF_SZ) - except ssl.SSLError as e: - self.server.logger.info( - 'SSL timeout. Possible server-first protocol') - possible_srvr_first_proto = True - - except Exception as e: - self.server.logger.info('recv() error: %s' % e.message) - - finally: - remote_sock.settimeout(None) + data = ssl_remote_sock.recv(BUF_SZ) orig_src_ip = self.client_address[0] orig_src_port = self.client_address[1] @@ -249,16 +224,12 @@ def handle(self): listener_sock.start() remote_sock.setblocking(0) - # ssl has no 'peek' option, so we need to process the first + # ssl has no 'peek' option, so we need to process the first # packet that is already consumed from the socket - if is_ssl and not possible_srvr_first_proto: - remote_q.put(data) - - # send the first packet to the listener twice to initiate - # server-first protocol - elif not is_ssl and possible_srvr_first_proto: + if ssl_remote_sock: + ssl_remote_sock.setblocking(0) remote_q.put(data) - + while True: readable, writable, exceptional = select.select( [remote_sock], [], [], .001) From 78fac4c4176b478fe5a24a26f9da96ab013be3d8 Mon Sep 17 00:00:00 2001 From: Matthew Haigh Date: Thu, 11 Oct 2018 08:54:24 -0700 Subject: [PATCH 9/9] added logging to proxy listener for all connections --- fakenet/listeners/HTTPListener.py | 2 +- fakenet/listeners/ProxyListener.py | 7 +++++++ 2 files changed, 8 insertions(+), 1 deletion(-) diff --git a/fakenet/listeners/HTTPListener.py b/fakenet/listeners/HTTPListener.py index 35186db..cf9ddba 100644 --- a/fakenet/listeners/HTTPListener.py +++ b/fakenet/listeners/HTTPListener.py @@ -127,7 +127,7 @@ def handle_error(self, request, client_address): # Log connections regardless of HTTP requests def get_request(self): conn, address = self.socket.accept() - self.logger.info('HTTP Connection received from %s:%s' % (address)) + self.logger.info('HTTP connection received from %s:%s' % (address)) return (conn, address) class ThreadedHTTPRequestHandler(BaseHTTPServer.BaseHTTPRequestHandler): diff --git a/fakenet/listeners/ProxyListener.py b/fakenet/listeners/ProxyListener.py index 7de15dc..a432ae1 100644 --- a/fakenet/listeners/ProxyListener.py +++ b/fakenet/listeners/ProxyListener.py @@ -130,6 +130,13 @@ def run(self): class ThreadedTCPServer(SocketServer.ThreadingMixIn, SocketServer.TCPServer): daemon_threads = True + # Log all connections regardless if data received + def get_request(self): + conn, address = self.socket.accept() + self.logger.info('Proxy connection (non-standard port) received ' + + 'from %s:%s' % (address)) + return (conn, address) + class ThreadedUDPServer(SocketServer.ThreadingMixIn, SocketServer.UDPServer): daemon_threads = True