Support for securely logging unredacted messages to sublogmon via new com.subgraph.sublogmon.Logger DBus method.

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
+}

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))
 			}
 		}
 
@@ -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))
 		}
 	}
 }
@@ -183,6 +191,9 @@ func (dc *dnsCache) Lookup(ip net.IP, pid int) string {
 				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)
+				} 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))
 				}
 			}
 		}
@@ -198,6 +209,9 @@ func (dc *dnsCache) Lookup(ip net.IP, pid int) string {
 			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)
+			} 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))
 			}
 		}
 	}

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()

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()
@@ -477,7 +485,12 @@ func (p *Policy) filterPending(rule *Rule) {
 				dests := STR_REDACTED
 				if !FirewallConfig.LogRedact {
 					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()

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,
+					pinfo.ExePath, r.proto, srcStr, dstStr, dstPort)
-					srcStr,
+				if FirewallConfig.LogRedact {
-					dstStr, dstPort)
+					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

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")

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)
 			}
-			return
+
+			if FirewallConfig.LogRedact {
+				log.Error(logstrRedacted)
+			} else {
+				log.Error(logstr)
+			}
+		} else {
+			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("TLSGuard approved certificate presented for connection to: ", dest)
+				log.Notice(logstr)
+			}
 		}
+
+		if FirewallConfig.LogRedact {
+			dbLogger.logRedacted("default", logstr)
+		}
+
+		if err != nil {
+			return
+		}
+
 	}
 
 	var wg sync.WaitGroup

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...")