From d7df1655178eb646723254cc1b0d837788ce1399 Mon Sep 17 00:00:00 2001 From: Stephen Watt Date: Tue, 3 Oct 2017 19:54:33 -0400 Subject: [PATCH] Support for securely logging unredacted messages to sublogmon via new com.subgraph.sublogmon.Logger DBus method. --- sgfw/dbus.go | 34 ++++++++++++++++++++++++++++++++-- sgfw/dns.go | 22 ++++++++++++++++++---- sgfw/ipc.go | 3 +-- sgfw/policy.go | 15 ++++++++++++++- sgfw/rules.go | 8 +++++--- sgfw/sgfw.go | 8 +++++++- sgfw/socks_server_chain.go | 37 +++++++++++++++++++++++++++++-------- sgfw/virtual.go | 6 ++---- 8 files changed, 108 insertions(+), 25 deletions(-) diff --git a/sgfw/dbus.go b/sgfw/dbus.go index 1e40396..0f7a2ad 100644 --- a/sgfw/dbus.go +++ b/sgfw/dbus.go @@ -2,9 +2,10 @@ package sgfw import ( "errors" + "fmt" + "net" "path" "strconv" - "net" "time" "github.com/godbus/dbus" @@ -61,9 +62,19 @@ func newDbusObjectPrompt() (*dbusObjectP, error) { if err != nil { return nil, err } + return &dbusObjectP{conn.Object("com.subgraph.fwprompt.EventNotifier", "/com/subgraph/fwprompt/EventNotifier")}, nil } +func newDbusRedactedLogger() (*dbusObjectP, error) { + conn, err := dbus.SystemBus() + if err != nil { + return nil, err + } + + return &dbusObjectP{conn.Object("com.subgraph.sublogmon", "/com/subgraph/sublogmon")}, nil +} + type dbusServer struct { fw *Firewall conn *dbus.Conn @@ -155,7 +166,7 @@ func createDbusRule(r *Rule) DbusRule { } else if r.gid >= 0 { pstr += ":" + strconv.Itoa(r.gid) } - log.Debugf("SANDBOX SANDBOX SANDBOX: %s", r.sandbox) + return DbusRule{ ID: uint32(r.id), Net: netstr, @@ -382,3 +393,22 @@ func (ds *dbusServer) SetConfig(key string, val dbus.Variant) *dbus.Error { func (ob *dbusObjectP) alertRule(data string) { ob.Call("com.subgraph.fwprompt.EventNotifier.Alert", 0, data) } + +func (ob *dbusObjectP) logRedacted(level string, logline string) bool { + var dres bool + timestamp := time.Now() + id := "fw-daemon" + + log.Noticef("logRedacted(level=%s, timestamp=%v, logline=%s)\n", level, timestamp, logline) + + call := ob.Call("com.subgraph.sublogmon.Logger", 0, + id, level, uint64(timestamp.UnixNano()), logline) + + err := call.Store(&dres) + if err != nil { + fmt.Println("Error sending redacted log message to sublogmon:", err) + return false + } + + return true +} diff --git a/sgfw/dns.go b/sgfw/dns.go index 974ed22..335bac9 100644 --- a/sgfw/dns.go +++ b/sgfw/dns.go @@ -2,6 +2,7 @@ package sgfw import ( "encoding/binary" + "fmt" "net" "strings" "sync" @@ -71,7 +72,10 @@ func (dc *dnsCache) processDNS(pkt *nfqueue.NFQPacket) { if pinfo == nil { if !FirewallConfig.LogRedact { log.Warningf("Skipping attempted DNS cache entry for process that can't be found: %v -> %v\n", q.Name, dns.answer) + } else { + dbLogger.logRedacted("default", fmt.Sprintf("Skipping attempted DNS cache entry for process that can't be found: %v -> %v\n", q.Name, dns.answer)) } + return } } @@ -82,7 +86,8 @@ func (dc *dnsCache) processDNS(pkt *nfqueue.NFQPacket) { if !FirewallConfig.LogRedact { log.Infof("Unhandled DNS message: %v", dns) } else { - log.Infof("Unhandled DNS message [redacted]") + log.Infof("Unhandled DNS message: %s", STR_REDACTED) + dbLogger.logRedacted("default", fmt.Sprintf("Unhandled DNS message: %v", dns)) } } @@ -128,6 +133,7 @@ func (dc *dnsCache) processRecordAddress(name string, answers []dnsRR, pid int) log.Warningf("Unexpected RR type in answer section of A response: %v", rec) } else { log.Warningf("Unexpected RR type in answer section of A response: [redacted]") + dbLogger.logRedacted("default", fmt.Sprintf("Unexpected RR type in answer section of A response: %v", rec)) } } @@ -145,7 +151,7 @@ func (dc *dnsCache) processRecordAddress(name string, answers []dnsRR, pid int) pid = 0 } -// log.Noticef("______ Adding to dns map: %s: %s -> pid %d", name, ip, pid) + // log.Noticef("______ Adding to dns map: %s: %s -> pid %d", name, ip, pid) _, ok := dc.ipMap[pid] if !ok { @@ -159,6 +165,8 @@ func (dc *dnsCache) processRecordAddress(name string, answers []dnsRR, pid int) } if !FirewallConfig.LogRedact { log.Infof("Adding %s: %s", name, ip) + } else { + dbLogger.logRedacted("default", fmt.Sprintf("Adding %s: %s", name, ip)) } } } @@ -182,7 +190,10 @@ func (dc *dnsCache) Lookup(ip net.IP, pid int) string { } else { if !FirewallConfig.LogRedact { log.Warningf("Skipping expired per-pid (%d) DNS cache entry: %s -> %s / exp. %v (%ds)\n", - pid, ip.String(), entry.name, entry.exp, entry.ttl) + pid, ip.String(), entry.name, entry.exp, entry.ttl) + } else { + dbLogger.logRedacted("default", fmt.Sprintf("Skipping expired per-pid (%d) DNS cache entry: %s -> %s / exp. %v (%ds)\n", + pid, ip.String(), entry.name, entry.exp, entry.ttl)) } } } @@ -197,7 +208,10 @@ func (dc *dnsCache) Lookup(ip net.IP, pid int) string { } else { if !FirewallConfig.LogRedact { log.Warningf("Skipping expired global DNS cache entry: %s -> %s / exp. %v (%ds)\n", - ip.String(), entry.name, entry.exp, entry.ttl) + ip.String(), entry.name, entry.exp, entry.ttl) + } else { + dbLogger.logRedacted("default", fmt.Sprintf("Skipping expired global DNS cache entry: %s -> %s / exp. %v (%ds)\n", + ip.String(), entry.name, entry.exp, entry.ttl)) } } } diff --git a/sgfw/ipc.go b/sgfw/ipc.go index 18c5441..7a20bee 100644 --- a/sgfw/ipc.go +++ b/sgfw/ipc.go @@ -5,10 +5,10 @@ import ( "errors" "fmt" "net" - "sync" "os" "strconv" "strings" + "sync" "github.com/subgraph/oz/ipc" ) @@ -24,7 +24,6 @@ type OzInitProc struct { var OzInitPids []OzInitProc = []OzInitProc{} var OzInitPidsLock = sync.Mutex{} - func addInitPid(pid int, name string, sboxid int) { fmt.Println("::::::::::: init pid added: ", pid, " -> ", name) OzInitPidsLock.Lock() diff --git a/sgfw/policy.go b/sgfw/policy.go index 2fbb486..5bfb77f 100644 --- a/sgfw/policy.go +++ b/sgfw/policy.go @@ -301,6 +301,8 @@ func (p *Policy) processPacket(pkt *nfqueue.NFQPacket, timestamp time.Time, pinf if !FirewallConfig.LogRedact { log.Infof("Lookup(%s): %s", dstip.String(), name) + } else { + dbLogger.logRedacted("default", fmt.Sprintf("Lookup(%s): %s", dstip.String(), name)) } result := p.rules.filterPacket(pkt, pinfo, srcip, name, optstr) @@ -431,6 +433,9 @@ func (p *Policy) filterPendingOne(rule *Rule, guid string) { } log.Infof("Adding rule for: %s", rule.getString(FirewallConfig.LogRedact)) + if FirewallConfig.LogRedact { + dbLogger.logRedacted("default", fmt.Sprintf("Adding rule for: %s", rule.getString(false))) + } // log.Noticef("%s > %s", rule.getString(FirewallConfig.LogRedact), pc.print()) if rule.rtype == RULE_ACTION_ALLOW { pc.accept() @@ -467,6 +472,9 @@ func (p *Policy) filterPending(rule *Rule) { } log.Infof("Adding rule for: %s", rule.getString(FirewallConfig.LogRedact)) + if FirewallConfig.LogRedact { + dbLogger.logRedacted("default", fmt.Sprintf("Adding rule for: %s", rule.getString(false))) + } // log.Noticef("%s > %s", rule.getString(FirewallConfig.LogRedact), pc.print()) if rule.rtype == RULE_ACTION_ALLOW { pc.accept() @@ -476,8 +484,13 @@ func (p *Policy) filterPending(rule *Rule) { srcs := pc.src().String() + ":" + strconv.Itoa(int(pc.srcPort())) dests := STR_REDACTED if !FirewallConfig.LogRedact { - dests = fmt.Sprintf("%s%d",pc.dst(), pc.dstPort) + dests = fmt.Sprintf("%s%d", pc.dst(), pc.dstPort) + } else { + dbLogger.logRedacted("default", + fmt.Sprintf("DENIED outgoing connection attempt by %s from %s %s -> %s:%d (user prompt) %v", + pc.procInfo().ExePath, pc.proto(), srcs, pc.dst(), pc.dstPort, rule.rtype)) } + log.Warningf("DENIED outgoing connection attempt by %s from %s %s -> %s (user prompt) %v", pc.procInfo().ExePath, pc.proto(), srcs, dests, rule.rtype) pc.drop() diff --git a/sgfw/rules.go b/sgfw/rules.go index a3e1623..8de9293 100644 --- a/sgfw/rules.go +++ b/sgfw/rules.go @@ -214,9 +214,11 @@ func (rl *RuleList) filter(pkt *nfqueue.NFQPacket, src, dst net.IP, dstPort uint if r.rtype == RULE_ACTION_DENY { //TODO: Optionally redact below log entry log.Warningf("DENIED outgoing connection attempt by %s from %s %s -> %s:%d", - pinfo.ExePath, r.proto, - srcStr, - dstStr, dstPort) + pinfo.ExePath, r.proto, srcStr, dstStr, dstPort) + if FirewallConfig.LogRedact { + dbLogger.logRedacted("default", fmt.Sprintf("DENIED outgoing connection attempt by %s from %s %s -> %s:%d", + pinfo.ExePath, r.proto, srcStr, dst.String(), dstPort)) + } return FILTER_DENY } else if r.rtype == RULE_ACTION_ALLOW { result = FILTER_ALLOW diff --git a/sgfw/sgfw.go b/sgfw/sgfw.go index fe6a428..98779d1 100644 --- a/sgfw/sgfw.go +++ b/sgfw/sgfw.go @@ -22,6 +22,7 @@ import ( ) var dbusp *dbusObjectP = nil +var dbLogger *dbusObjectP = nil type Firewall struct { dbus *dbusServer @@ -263,7 +264,12 @@ func Main() { dbusp, err = newDbusObjectPrompt() if err != nil { - panic(fmt.Sprintf("Failed to connect to dbus system bus for sgfw prompt events: %v", err)) + panic(fmt.Sprintf("Failed to connect to DBus system bus for SGFW prompt events: %v", err)) + } + + dbLogger, err = newDbusRedactedLogger() + if err != nil { + panic(fmt.Sprintf("Failed to connect to DBus system bus for redacted logger: %v", err)) } dbusp.alertRule("fw-daemon initialization") diff --git a/sgfw/socks_server_chain.go b/sgfw/socks_server_chain.go index 5c1483f..e4fbf58 100644 --- a/sgfw/socks_server_chain.go +++ b/sgfw/socks_server_chain.go @@ -1,6 +1,7 @@ package sgfw import ( + "fmt" "io" "net" "os" @@ -444,22 +445,42 @@ func (c *socksChainSession) handleConnect(tls bool) { func (c *socksChainSession) forwardTraffic(tls bool) { if tls == true { + logstr, logstrRedacted := "", "" err := TLSGuard(c.clientConn, c.upstreamConn, c.req.Addr.addrStr) - dest := STR_REDACTED - if !FirewallConfig.LogRedact { - dest = c.req.Addr.addrStr - } if err != nil { if c.pinfo.Sandbox != "" { - log.Errorf("TLSGuard violation: Dropping traffic from %s (sandbox: %s) to %s: %v", c.pinfo.ExePath, c.pinfo.Sandbox, dest, err) + logstr = fmt.Sprintf("TLSGuard violation: Dropping traffic from %s (sandbox: %s) to %s: %v", c.pinfo.ExePath, c.pinfo.Sandbox, c.req.Addr.addrStr, err) + logstrRedacted = fmt.Sprintf("TLSGuard violation: Dropping traffic from %s (sandbox: %s) to %s: %v", c.pinfo.ExePath, c.pinfo.Sandbox, STR_REDACTED, err) } else { - log.Errorf("TLSGuard violation: Dropping traffic from %s (unsandboxed) to %s: %v", c.pinfo.ExePath, dest, err) + logstr = fmt.Sprintf("TLSGuard violation: Dropping traffic from %s (unsandboxed) to %s: %v", c.pinfo.ExePath, c.req.Addr.addrStr, err) + logstrRedacted = fmt.Sprintf("TLSGuard violation: Dropping traffic from %s (unsandboxed) to %s: %v", c.pinfo.ExePath, STR_REDACTED, err) + } + + if FirewallConfig.LogRedact { + log.Error(logstrRedacted) + } else { + log.Error(logstr) } - return } else { - log.Notice("TLSGuard approved certificate presented for connection to: ", dest) + logstr = fmt.Sprintf("TLSGuard approved certificate presented for connection to: ", c.req.Addr.addrStr) + logstrRedacted = fmt.Sprintf("TLSGuard approved certificate presented for connection to: ", STR_REDACTED) + + if FirewallConfig.LogRedact { + log.Notice(logstrRedacted) + } else { + log.Notice(logstr) + } } + + if FirewallConfig.LogRedact { + dbLogger.logRedacted("default", logstr) + } + + if err != nil { + return + } + } var wg sync.WaitGroup diff --git a/sgfw/virtual.go b/sgfw/virtual.go index 7754fed..3f1d16a 100644 --- a/sgfw/virtual.go +++ b/sgfw/virtual.go @@ -3,11 +3,11 @@ package sgfw import ( "fmt" "net" - "time" "sync" + "time" - "github.com/subgraph/go-procsnitch" "github.com/godbus/dbus" + "github.com/subgraph/go-procsnitch" ) type virtualPkt struct { @@ -27,12 +27,10 @@ type virtualPkt struct { dport uint16 } - var tdb *dbusObjectP var tdbMutex = &sync.Mutex{} var tdbInit = false - func init() { fmt.Println("Initializing virtual packet test subsystem...")