def assertLogged(self, regexp):
r = re.compile(regexp)
for event in self._logEvents:
msg = log.textFromEventDict(event)
if msg is not None:
assert not msg.startswith("Unable to format event"), msg
if msg is not None and r.search(msg):
return
self.fail(
"%r not matched in log output.\n%s " % (
regexp, [log.textFromEventDict(e) for e in self._logEvents]))
def assertLogged(self, regexp):
r = re.compile(regexp)
for event in self._logEvents:
msg = log.textFromEventDict(event)
if msg is not None:
assert not msg.startswith("Unable to format event"), msg
if msg is not None and r.search(msg):
return
self.fail(
"%r not matched in log output.\n%s " % (
regexp, [log.textFromEventDict(e) for e in self._logEvents]))
def emit(self, eventDict):
if not eventDict.has_key('level'):
if eventDict.has_key('isError') and eventDict['isError']:
eventDict['level'] = ERROR
else:
eventDict['level'] = TRACE
if eventDict['level'] < self.level:
return
text = log.textFromEventDict(eventDict)
if text is None:
return
text = text.rstrip()
text = text.expandtabs()
text += '\n'
text = text.encode('utf-8')
util.untilConcludes(self.write, text)
util.untilConcludes(self.flush)
if eventDict['level'] >= CRITICAL:
self.reactor.stop()
def twistedLogObserver(eventDict):
"""Forward twisted logs to the python stdlib logger.
Primary differences from t.p.log.PythonLoggingObserver:
* Default level of DEBUG for non-error messages
* Picks a logger based on the module of the caller. This way the output
shows which part of twisted generated the message.
"""
n = 2
module = 'twisted'
while True:
try:
caller = sys._getframe(n)
except ValueError:
break
name = caller.f_globals.get('__name__')
if name not in (None, 'twisted.python.log'):
module = name
break
n += 1
logger = logging.getLogger(module)
if 'logLevel' in eventDict:
level = eventDict['logLevel']
elif eventDict['isError']:
level = logging.ERROR
else:
level = logging.DEBUG
text = twlog.textFromEventDict(eventDict)
if text is None:
return
logger.log(level, text)
def emit(self, eventDict):
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
if GLLogObserver.suppressed == GLLogObserver.limit_suppressed:
# This code path flush the status of the broken log, in the case a flood is happen
# for few moment or in the case something goes wrong when logging below.
log.info("!! has been suppressed %d log lines due to error flood (last error %s)" %
(GLLogObserver.limit_suppressed, GLLogObserver.last_exception_msg) )
GLLogObserver.suppressed = 0
GLLogObserver.limit_suppressed += 5
GLLogObserver.last_exception_msg = ""
try:
# in addition to escape sequence removal on logfiles we also quote html chars
util.untilConcludes(self.write, timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush) # Hoorj!
except Exception as excep:
GLLogObserver.suppressed += 1
GLLogObserver.last_exception_msg = str(excep)
def emit(self, eventDict):
if 'debug' in eventDict and eventDict['debug']:
if not self.debug:
return # skip this message if we do not want debug
if 'payload' in eventDict and eventDict['payload']:
if not self.dump_payload:
return # skip this message if we do not want debug
text = log.textFromEventDict(eventDict)
if text is None:
return
# skip annoying twisted messages
if text in ['Log opened.', 'Main loop terminated.']:
return
if text.startswith('twisted.web.server.Site starting on') or \
text.startswith('Starting factory <twisted.web.server.Site instance') or \
text.startswith('Stopping factory <twisted.web.server.Site instance'):
return
text += "\n"
self.write(text)
self.flush()
def emit(self, eventDict):
if eventDict["isError"]:
level = logging.ERROR
elif "level" in eventDict:
level = eventDict["level"]
else:
level = logging.INFO
if level < self.logLevel:
return
message = log.textFromEventDict(eventDict)
if not message:
return
logElements = {
"timestamp": self.formatTime(eventDict["time"]),
"level": logging.getLevelName(level),
"system": eventDict["system"],
"text": message.replace("\n", "\n\t")
}
messageString = "{} {}".format(logElements["timestamp"],
log._safeFormat("%(level)7s:[%(system)s]: %(text)s\n", logElements))
print messageString.replace("\n", "")
util.untilConcludes(self.write, messageString)
util.untilConcludes(self.flush)
def emit(self, event):
if event.has_key('PRIORITY'):
if event['PRIORITY'] is None:
event['PRIORITY'] = DEBUG
elif event['PRIORITY'] not in range(8):
event['PRIORITY'] = DEBUG
elif event.get('isError'):
event['PRIORITY'] = ERROR
else:
event['PRIORITY'] = DEBUG
if 'SYSLOG_IDENTIFIER' not in event and self.appname is not None:
event['SYSLOG_IDENTIFIER'] = self.appname
text = _log.textFromEventDict(event)
if text is None:
return
text = text.rstrip()
text = text.expandtabs()
for transport in self.transports:
transport.send(event, text)
if eventDict['PRIORITY'] <= CRITICAL:
self.reactor.stop()
def assertLogged(self, regexp):
r = re.compile(regexp)
for event in self._logEvents:
msg = log.textFromEventDict(event)
if msg is not None and r.search(msg):
return
self.fail("%r not matched in log output" % regexp)
def emit(self, eventDict):
if 'logLevel' in eventDict:
level = eventDict['logLevel']
elif eventDict['isError']:
level = logging.ERROR
else:
level = logging.INFO
text = log.textFromEventDict(eventDict)
if text is None:
return
if text == "Unhandled error in Deferred:":
# This annoying error message is just a pre-cursor to an actual
# error message, so filter it out.
return None
if level >= logging.ERROR:
try:
self.event_recorder.emit_critical("crash", msg=text)
self.emailer.send(text)
except Exception:
logger.exception("Error sending notification")
self.event_recorder.emit_critical("email_failure", msg=text)
def emit(self, eventDict):
"""
Handles formatting system log messages along with incrementing the objs
error counters. The eventDict is generated by the arguments passed to each
log level call. See the unittests for an example.
"""
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {
'system': eventDict['system'],
'text': text.replace("\n", "\n\t")
}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
util.untilConcludes(self.write,
timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush)
def test_format(self) -> None:
"""
Formatting is translated such that text is rendered correctly, even
though old-style logging doesn't use PEP 3101 formatting.
"""
event = self.forwardAndVerify(dict(log_format="Hello, {who}!", who="world"))
self.assertEqual(legacyLog.textFromEventDict(event), "Hello, world!")
def my_log_observer(d):
if d.get("isError", 0):
import sys
text = log.textFromEventDict(d)
sys.stderr.write("\nUnhandled error while refreshing twisted plugins cache: \n")
sys.stderr.write(" " + text.replace("\n", "\n "))
def test_newPluginsOnReadOnlyPath(self):
"""
Verify that a failure to write the dropin.cache file on a read-only
path will not affect the list of plugins returned.
Note: this test should pass on both Linux and Windows, but may not
provide useful coverage on Windows due to the different meaning of
"read-only directory".
"""
self.unlockSystem()
self.sysplug.child('newstuff.py').setContent(pluginFileContents('one'))
self.lockSystem()
# Take the developer path out, so that the system plugins are actually
# examined.
sys.path.remove(self.devPath.path)
# Start observing log events to see the warning
events = []
addObserver(events.append)
self.addCleanup(removeObserver, events.append)
self.assertIn('one', self.getAllPlugins())
# Make sure something was logged about the cache.
expected = "Unable to write to plugin cache %s: error number %d" % (
self.syscache.path, errno.EPERM)
for event in events:
if expected in textFromEventDict(event):
break
else:
self.fail("Did not observe unwriteable cache warning in log "
"events: %r" % (events, ))
def test_format(self):
"""
The C{"format"} value, when specified, is used to format the message.
"""
eventDict = dict(message=(), isError=0, format="Hello, %(foo)s!", foo="dude")
text = log.textFromEventDict(eventDict)
self.assertEqual(text, "Hello, dude!")
def emit(self, eventDict):
"""
Extends method of the base class by providing support for log level.
"""
if eventDict['isError']:
level = logging.ERROR
elif 'level' in eventDict:
level = eventDict['level']
else:
level = logging.INFO
if level < self.log_level:
return
text = log.textFromEventDict(eventDict)
if text is None:
return
time_str = self.formatTime(eventDict['time'])
fmt_dict = {
'level': logging.getLevelName(level),
'system': eventDict['system'],
'text': text.replace("\n", "\n\t")
}
msg_str = log._safeFormat(
"%(level)8s:[%(system)s]: %(text)s\n", fmt_dict)
util.untilConcludes(self.write, "{0} {1}".format(time_str, msg_str))
util.untilConcludes(self.flush)
def __call__(self, eventDict):
"""被 twisted.python.log 模块调用
"""
if 'LEVEL' in eventDict:
level = eventDict['LEVEL']
elif eventDict['isError']:
level = logging.ERROR
else:
level = logging.NOTSET
if level < Logger.level:
return
text = log.textFromEventDict(eventDict)
if text is None:
return
text = text.replace('\n', ' ')
trace = ""
if 'TRACE' in eventDict:
trace = eventDict['TRACE']
#trace = traceback.extract_stack()
message = "%s : %s" % (trace, text)
self._log_to_file(level, message)
def emit(self, eventDict):
text = txlog.textFromEventDict(eventDict)
if text is None:
return
util.untilConcludes(self.write, "%s\n" % text)
util.untilConcludes(self.flush) # Hoorj!
def emit(self, eventDict):
if not eventDict.has_key('level'):
if eventDict.has_key('isError') and eventDict['isError']:
eventDict['level'] = ERROR
else:
eventDict['level'] = TRACE
if eventDict['level'] < self.level:
return
text = log.textFromEventDict(eventDict)
if text is None:
return
text = text.rstrip()
text = text.expandtabs()
text += '\n'
text = text.encode('utf-8')
util.untilConcludes(self.write, text)
util.untilConcludes(self.flush)
if eventDict['level'] >= CRITICAL:
self.reactor.stop()
def emit(self, eventDict):
text = txlog.textFromEventDict(eventDict)
if text is None:
return
util.untilConcludes(self.write, "%s\n" % text)
util.untilConcludes(self.flush) # Hoorj!
def __call__(self, eventDict):
if "_structlog" not in eventDict:
eventDict["message"] = (
json.dumps({"event": textFromEventDict(eventDict), "system": eventDict.get("system")}),
)
eventDict["_structlog"] = True
return self._observer(eventDict)
def emit(self, eventDict):
"""Changing the default log format.
Base method that writes cis log. Here we can access the log
message and manipulate it as we need. For example, define
the log format and filter out password from the message.
This can be configured per service in cisconf with LOG_FORMATTERS
tuple of pairs (pattern, replacement).
TODO: This is a hack, twisted should have a better way of modifying
its log format"""
text = log.textFromEventDict(eventDict)
if text is None:
return
if isinstance(self.log_formatters, (list, tuple)):
for pattern, replacement in self.log_formatters:
text = re.sub(pattern, replacement, text)
timeStr = self.formatTime(eventDict['time'])
fmtDict = {
'system': eventDict['system'],
'text': text.replace("\n", "\n\t")
}
msgStr = log._safeFormat("[%(system)s] %(text)s\n", fmtDict)
util.untilConcludes(self.write,
'%s %s %s' % (timeStr, self.log_prefix, msgStr))
util.untilConcludes(self.flush) # Hoorj!
def emit(self, eventDict):
"""
Handles formatting system log messages along with incrementing the objs
error counters. The eventDict is generated by the arguments passed to each
log level call. See the unittests for an example.
"""
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
if GLLogObserver.suppressed == GLLogObserver.limit_suppressed:
GLLogObserver.suppressed = 0
GLLogObserver.limit_suppressed += 5
GLLogObserver.last_exception_msg = ""
try:
# in addition to escape sequence removal on logfiles we also quote html chars
util.untilConcludes(self.write, timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush) # Hoorj!
except Exception as excep:
GLLogObserver.suppressed += 1
GLLogObserver.last_exception_msg = str(excep)
def my_log_observer(d):
if d.get("isError", 0):
import sys
text = log.textFromEventDict(d)
sys.stderr.write("\nUnhandled error while refreshing twisted plugins cache: \n")
sys.stderr.write(" " + text.replace("\n", "\n "))
def koj_watcher(eventDict):
"""Custom emit for FileLogObserver"""
text = log.textFromEventDict(eventDict)
if text is None:
return
fmtDict = {'text': text.replace("\n", "\n\t")}
msgStr = log._safeFormat("%(text)s\n", fmtDict)
def emit(self, eventDict):
"""Changing the default log format.
Base method that writes cis log. Here we can access the log
message and manipulate it as we need. For example, define
the log format and filter out password from the message.
This can be configured per service in cisconf with LOG_FORMATTERS
tuple of pairs (pattern, replacement).
TODO: This is a hack, twisted should have a better way of modifying
its log format"""
text = log.textFromEventDict(eventDict)
if text is None:
return
if isinstance(self.log_formatters, (list,tuple)):
for pattern, replacement in self.log_formatters:
text = re.sub(pattern, replacement, text)
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = log._safeFormat("[%(system)s] %(text)s\n", fmtDict)
util.untilConcludes(self.write, '%s %s %s' % (timeStr, self.log_prefix, msgStr))
util.untilConcludes(self.flush) # Hoorj!
def koj_watcher(eventDict):
"""Custom emit for FileLogObserver"""
text = log.textFromEventDict(eventDict)
if text is None:
return
fmtDict = {'text': text.replace("\n", "\n\t")}
msgStr = log._safeFormat("%(text)s\n", fmtDict)
def emit(self, eventDict):
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
if GLLogObserver.suppressed == GLLogObserver.limit_suppressed:
# This code path flush the status of the broken log, in the case a flood is happen
# for few moment or in the case something goes wrong when logging below.
log.info("!! has been suppressed %d log lines due to error flood (last error %s)" %
(GLLogObserver.limit_suppressed, GLLogObserver.last_exception_msg) )
GLLogObserver.suppressed = 0
GLLogObserver.limit_suppressed += 5
GLLogObserver.last_exception_msg = ""
try:
# in addition to escape sequence removal on logfiles we also quote html chars
util.untilConcludes(self.write, timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush) # Hoorj!
except Exception as excep:
GLLogObserver.suppressed += 1
GLLogObserver.last_exception_msg = str(excep)
def emit(self, eventDict):
text = textFromEventDict(eventDict)
if text is None:
return
timeStr = self._colorize(self.formatTime(eventDict["time"]), ColoredFileLogObserver.GREY_NORMAL)
fmtDict = {"system": eventDict["system"], "text": text.replace("\n", "\n\t")}
systemStr = ""
systemStr = self._colorize(_safeFormat("[%(system)s]", fmtDict), ColoredFileLogObserver.GREY_NORMAL)
textStr = _safeFormat("%(text)s", fmtDict)
if textStr.startswith("SSH"):
t = textStr.find("STDERR:")
if t != -1:
textStr = self._colorize(textStr[t + 8 :], ColoredFileLogObserver.RED_BOLD)
else:
textStr = self._colorize(textStr[textStr.find("STDOUT:") + 8 :], ColoredFileLogObserver.GREEN_BOLD)
# only text for incoming data
msgStr = textStr + "\n"
else:
# add system to the local logs
# TODO: Make system more useful, not just "SSHChannel...".
msgStr = systemStr + " " + textStr + "\n"
util.untilConcludes(self.write, timeStr + " " + msgStr)
util.untilConcludes(self.flush) # Hoorj!
def emit(self, eventDict):
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
if GLLogObserver.suppressed == GLLogObserver.limit_suppressed:
GLLogObserver.suppressed = 0
GLLogObserver.limit_suppressed += 5
GLLogObserver.last_exception_msg = ""
try:
# in addition to escape sequence removal on logfiles we also quote html chars
util.untilConcludes(self.write, timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush) # Hoorj!
except Exception as excep:
GLLogObserver.suppressed += 1
GLLogObserver.last_exception_msg = str(excep)
def emit(self, eventDict):
if 'failure' in eventDict:
vf = eventDict['failure']
e_t, e_v, e_tb = vf.type, vf.value, vf.getTracebackObject()
sys.excepthook(e_t, e_v, e_tb)
text = twlog.textFromEventDict(eventDict)
if text is None:
return
timeStr = self.formatTime(eventDict['time'])
fmtDict = {'system': eventDict['system'], 'text': text.replace("\n", "\n\t")}
msgStr = twlog._safeFormat("[%(system)s] %(text)s\n", fmtDict)
if GLLogObserver.suppressed == GLLogObserver.limit_suppressed:
GLLogObserver.suppressed = 0
GLLogObserver.limit_suppressed += 5
GLLogObserver.last_exception_msg = ""
try:
# in addition to escape sequence removal on logfiles we also quote html chars
util.untilConcludes(self.write, timeStr + " " + log_encode_html(msgStr))
util.untilConcludes(self.flush) # Hoorj!
except Exception as excep:
GLLogObserver.suppressed += 1
GLLogObserver.last_exception_msg = str(excep)
def _logger(event):
# This is a twisted log observer
# Attempt to report all exceptions to stderr since they will be lost
try:
level = event.get('log_level', 'INFO')
if level in LEVELS and _log_level < LEVELS.index(level):
return
# Use the smarter function if available
if hasattr(log, 'textFromEventDict'):
text = log.textFromEventDict(event)
else:
text = "\n".join(event['message'])
if not text:
text = str(event.get('failure', ''))
prefix = event.get('prefix', event.get('system', '-'))
date = time.strftime("%b %d %H:%M:%S",
time.localtime(event.get('time', None)))
line = "%s %s %s: %s\n" % (date, level, prefix, text)
util.untilConcludes(_log_file.write, line)
util.untilConcludes(_log_file.flush)
if _loud_init and level in ('ERROR', 'WARN'):
util.untilConcludes(sys.stderr.write, line)
util.untilConcludes(sys.stderr.flush)
except:
_log_fallback.write("%s" % failure.Failure())
def emit(self, eventDict):
"""
Extended base class' 'emit' method by log level support.
"""
if eventDict['isError']:
level = logging.ERROR
elif 'level' in eventDict:
level = eventDict['level']
else:
level = logging.INFO
if level < self.log_level:
return
text = tx_log.textFromEventDict(eventDict)
if text is None:
return
time_str = self.formatTime(eventDict['time'])
fmt_dict = {
'level': logging.getLevelName(level),
'system': eventDict['system'],
'text': text.replace("\n", "\n\t")
}
msg_str = tx_log._safeFormat("%(level)s:[%(system)s]:%(text)s\n",
fmt_dict)
tx_util.untilConcludes(self.write, time_str + " " + msg_str)
tx_util.untilConcludes(self.flush)
def emit(self, event):
text = log.textFromEventDict(event)
if text is None:
return
if event['isError']:
level = logging.ERROR
elif 'level' in event:
level = event['level']
else:
level = logging.INFO
# Format
line = "{time} [{system}] {text}\n".format(
time=self.formatTime(event['time']),
system=event['system'],
text=text.replace('\n', '\n\t'),
)
# Print to the terminal
try:
color = LOG_LEVEL_COLORS[level]
except KeyError:
color = LOG_LEVEL_COLORS[logging.INFO]
self.shell_service.add_log_line(line, color)
def test_formatAlreadySet(self) -> None:
"""
Formatting is not altered if the old-style C{"format"} key already
exists.
"""
event = self.forwardAndVerify(dict(log_format="Hello!", format="Howdy!"))
self.assertEqual(legacyLog.textFromEventDict(event), "Howdy!")
def test_newPluginsOnReadOnlyPath(self):
"""
Verify that a failure to write the dropin.cache file on a read-only
path will not affect the list of plugins returned.
Note: this test should pass on both Linux and Windows, but may not
provide useful coverage on Windows due to the different meaning of
"read-only directory".
"""
self.unlockSystem()
self.sysplug.child('newstuff.py').setContent(pluginFileContents('one'))
self.lockSystem()
# Take the developer path out, so that the system plugins are actually
# examined.
sys.path.remove(self.devPath.path)
# Start observing log events to see the warning
events = []
addObserver(events.append)
self.addCleanup(removeObserver, events.append)
self.assertIn('one', self.getAllPlugins())
# Make sure something was logged about the cache.
expected = "Unable to write to plugin cache %s: error number %d" % (
self.syscache.path, errno.EPERM)
for event in events:
if expected in textFromEventDict(event):
break
else:
self.fail(
"Did not observe unwriteable cache warning in log "
"events: %r" % (events,))
def emit(self, eventDict):
text = textFromEventDict(eventDict)
if text is None:
return
timeStr = self._colorize(self.formatTime(eventDict['time']),
ColoredFileLogObserver.GREY_NORMAL)
fmtDict = {
'system': eventDict['system'],
'text': text.replace("\n", "\n\t")
}
systemStr = ""
systemStr = self._colorize(_safeFormat("[%(system)s]", fmtDict),
ColoredFileLogObserver.GREY_NORMAL)
textStr = _safeFormat("%(text)s", fmtDict)
if textStr.startswith("SSH"):
t = textStr.find("STDERR:")
if t != -1:
textStr = self._colorize(textStr[t + 8:],
ColoredFileLogObserver.RED_BOLD)
else:
textStr = self._colorize(textStr[textStr.find("STDOUT:") + 8:],
ColoredFileLogObserver.GREEN_BOLD)
# only text for incoming data
msgStr = textStr + "\n"
else:
# add system to the local logs
# TODO: Make system more useful, not just "SSHChannel...".
msgStr = systemStr + " " + textStr + "\n"
util.untilConcludes(self.write, timeStr + " " + msgStr)
util.untilConcludes(self.flush) # Hoorj!
def emit(self, eventDict):
if "debug" in eventDict and eventDict["debug"]:
if not self.debug:
return # skip this message if we do not want debug
if "payload" in eventDict and eventDict["payload"]:
if not self.dump_payload:
return # skip this message if we do not want debug
text = log.textFromEventDict(eventDict)
if text is None:
return
# skip annoying twisted messages
if text in ["Log opened.", "Main loop terminated."]:
return
if (
text.startswith("twisted.web.server.Site starting on")
or text.startswith("Starting factory <twisted.web.server.Site instance")
or text.startswith("Stopping factory <twisted.web.server.Site instance")
):
return
text += "\n"
self.write(text)
self.flush()
def formatCef(logentry):
"""
Take logentry and turn into CEF string
"""
# Jan 18 11:07:53 host CEF:Version|Device Vendor|Device Product|Device Version|Signature ID|Name|Severity|[Extension]
cefVendor = "Cowrie"
cefProduct = "Cowrie"
cefVersion = "1.0"
cefSignature = logentry["eventid"]
cefName = logentry["eventid"]
cefSeverity = "5"
cefExtensions = {
'app': 'SSHv2',
'destinationServicename': 'sshd',
'deviceExternalId': logentry['sensor'],
'msg': log.textFromEventDict(logentry),
'src': logentry['src_ip'],
'proto': 'tcp'
}
if logentry['eventid'] == 'cowrie.session.connect':
cefExtensions['spt'] = logentry['src_port']
cefExtensions['dpt'] = logentry['dst_port']
cefExtensions['src'] = logentry['src_ip']
cefExtensions['dst'] = logentry['dst_ip']
elif logentry['eventid'] == 'cowrie.login.success':
cefExtensions['duser'] = logentry['username']
cefExtensions['outcome'] = 'success'
elif logentry['eventid'] == 'cowrie.login.failed':
cefExtensions['duser'] = logentry['username']
cefExtensions['outcome'] = 'failed'
elif logentry['eventid'] == 'cowrie.file.file_download':
cefExtensions['filehash'] = logentry['filehash']
cefExtensions['filePath'] = logentry['filename']
cefExtensions['fsize'] = logentry['size']
elif logentry['eventid'] == 'cowrie.file.file_upload':
cefExtensions['filehash'] = logentry['filehash']
cefExtensions['filePath'] = logentry['filename']
cefExtensions['fsize'] = logentry['size']
# 'out' 'outcome' request, rt
cefList = []
for key in cefExtensions.keys():
value = str(cefExtensions[key]).replace(' ', r'\ ')
cefList.append(key + "=" + value)
cefExtension = ' '.join(cefList)
cefString = "CEF:0|" + \
cefVendor + "|" + \
cefProduct + "|" + \
cefVersion + "|" + \
cefSignature + "|" + \
cefName + "|" + \
cefSeverity + "|" + \
cefExtension
return cefString
def formatCef(logentry):
"""
Take logentry and turn into CEF string
"""
# Jan 18 11:07:53 host CEF:Version|Device Vendor|Device Product|Device Version|Signature ID|Name|Severity|[Extension]
cefVendor = "Cowrie"
cefProduct = "Cowrie"
cefVersion = "1.0"
cefSignature = logentry["eventid"]
cefName = logentry["eventid"]
cefSeverity = "5"
cefExtensions = {
'app': 'SSHv2',
'destinationServicename': 'sshd',
'deviceExternalId': logentry['sensor'],
'msg': log.textFromEventDict(logentry),
'src' : logentry['src_ip'],
'proto': 'tcp'
}
if logentry['eventid'] == 'cowrie.session.connect':
cefExtensions['spt'] = logentry['src_port']
cefExtensions['dpt'] = logentry['dst_port']
cefExtensions['src'] = logentry['src_ip']
cefExtensions['dst'] = logentry['dst_ip']
elif logentry['eventid'] == 'cowrie.login.success':
cefExtensions['duser'] = logentry['username']
cefExtensions['outcome'] = 'success'
elif logentry['eventid'] == 'cowrie.login.failed':
cefExtensions['duser'] = logentry['username']
cefExtensions['outcome'] = 'failed'
elif logentry['eventid'] == 'cowrie.file.file_download':
cefExtensions['filehash'] = logentry['filehash']
cefExtensions['filePath'] = logentry['filename']
cefExtensions['fsize'] = logentry['size']
elif logentry['eventid'] == 'cowrie.file.file_upload':
cefExtensions['filehash'] = logentry['filehash']
cefExtensions['filePath'] = logentry['filename']
cefExtensions['fsize'] = logentry['size']
# 'out' 'outcome' request, rt
cefList = []
for key in list(cefExtensions.keys()):
value = str(cefExtensions[key]).replace(' ', r'\ ')
cefList.append(key+"="+value)
cefExtension = ' '.join(cefList)
cefString = "CEF:0|" + \
cefVendor + "|" + \
cefProduct + "|" + \
cefVersion + "|" + \
cefSignature + "|" + \
cefName + "|" + \
cefSeverity + "|" + \
cefExtension
return cefString
def test_noMessageNoFormat(self):
"""
If C{"format"} is unspecified and C{"message"} is empty, return
L{None}.
"""
eventDict = dict(message=(), isError=0)
text = log.textFromEventDict(eventDict)
self.assertIsNone(text)
def test_message(self):
"""
The C{"message"} value, when specified, is concatenated to generate the
message.
"""
eventDict = dict(message=("a", "b", "c"))
text = log.textFromEventDict(eventDict)
self.assertEqual(text, "a b c")
def myFloEmit(self, eventDict):
text = log.textFromEventDict(eventDict)
if text is None:
return None
self.timeFormat = "%Y%m%d-%H:%M:%S.%f %z"
timeStr = self.formatTime(eventDict["time"])
util.untilConcludes(self.write, timeStr + " " + text + "\n")
util.untilConcludes(self.flush)
def emit(self, eventDict):
text = txlog.textFromEventDict(eventDict)
if text is None:
return
if eventDict['isError'] and 'failure' in eventDict:
self.error(text)
else:
self.info(text)
def __call__(self, msg):
error = bool(msg.get("isError"))
# Twisted log messages on Python 2 are bytes. We don't know the
# encoding, but assume it's ASCII superset. Charmap will translate
# ASCII correctly, and higher-bit characters just map to
# corresponding Unicode code points, and will never fail at decoding.
message = unicode(textFromEventDict(msg), "charmap")
TWISTED_LOG_MESSAGE(error=error, message=message).write(self.logger)
def _emit(self, eventDict):
text = log.textFromEventDict(eventDict)
if not text: return
timeStr = self.formatTime(eventDict['time'])
log.util.untilConcludes(self.write,
"%s %s\n" % (timeStr, text.replace("\n", "\n\t")))
log.util.untilConcludes(self.flush)
def myFloEmit(self, eventDict):
text = log.textFromEventDict(eventDict)
if text is None:
return
self.timeFormat = "%Y%m%d-%H:%M:%S.%f %z"
timeStr = self.formatTime(eventDict["time"])
util.untilConcludes(self.write, timeStr + " " + text + "\n")
util.untilConcludes(self.flush)
def __call__(self, msg):
error = bool(msg.get("isError"))
# Twisted log messages on Python 2 are bytes. We don't know the
# encoding, but assume it's ASCII superset. Charmap will translate
# ASCII correctly, and higher-bit characters just map to
# corresponding Unicode code points, and will never fail at decoding.
message = unicode(textFromEventDict(msg), "charmap")
TWISTED_LOG_MESSAGE(error=error, message=message).write(self.logger)
def test_noMessageNoFormat(self):
"""
If C{"format"} is unspecified and C{"message"} is empty, return
L{None}.
"""
eventDict = dict(message=(), isError=0)
text = log.textFromEventDict(eventDict)
self.assertIsNone(text)
def emit(self, eventDict):
"""ah, logs should be pretty much as the app intended"""
text = textFromEventDict(eventDict)
if text is None:
return
text.replace("\n", "\n\t")
untilConcludes(self.write, text)
untilConcludes(self.flush) # Hoorj!
def __call__(self, eventDict):
if '_structlog' not in eventDict:
eventDict['message'] = (json.dumps({
'event': textFromEventDict(eventDict),
'system': eventDict.get('system'),
}),)
eventDict['_structlog'] = True
return self._observer(eventDict)
def test_message(self):
"""
The C{"message"} value, when specified, is concatenated to generate the
message.
"""
eventDict = dict(message=("a", "b", "c"))
text = log.textFromEventDict(eventDict)
self.assertEqual(text, "a b c")
def emit(self, eventDict):
text = txlog.textFromEventDict(eventDict)
if text is None:
return
if eventDict['isError'] and 'failure' in eventDict:
self.error(text)
else:
self.info(text)
def __call__(self, eventDict):
if '_structlog' not in eventDict:
eventDict['message'] = (json.dumps({
'event': textFromEventDict(eventDict),
'system': eventDict.get('system'),
}),)
eventDict['_structlog'] = True
return self._observer(eventDict)
def test_format(self):
"""
Formatting is translated properly.
"""
event = self.forwardAndVerify(
dict(log_format="Hello, {who}!", who="world"))
self.assertEquals(twistedLogging.textFromEventDict(event),
b"Hello, world!")
def write(self, logentry):
"""
"""
if self.format == 'cef':
self.outfile.write(cowrie.core.cef.formatCef(logentry)+'\n')
else:
self.outfile.write(log.textFromEventDict(logentry)+'\n')
self.outfile.flush()
def test_formatMessage(self):
"""
Using the message key, which is special in old-style, works for
new-style formatting.
"""
event = self.forwardAndVerify(
dict(log_format="Hello, {message}!", message="world"))
self.assertEqual(legacyLog.textFromEventDict(event), "Hello, world!")
def test_noTracebackForYou(self):
"""
If unable to obtain a traceback due to an exception, catch it and note
the error.
"""
# Invalid failure object doesn't implement .getTraceback()
eventDict = dict(message=(), isError=1, failure=object())
text = log.textFromEventDict(eventDict)
self.assertIn("\n(unable to obtain traceback)", text)
def emit(self, eventDict):
"""
Produce a log output.
"""
from twisted.trial._dist import managercommands
text = textFromEventDict(eventDict)
if text is None:
return
self.protocol.callRemote(managercommands.TestWrite, out=text)
