From 792726545e709423d6c80cdfbcb34b5e2db0735d Mon Sep 17 00:00:00 2001 From: Stephen Watt Date: Tue, 3 Oct 2017 00:28:08 -0400 Subject: [PATCH 1/4] Small changes necessary to make fw-prompt a DBus autostart service. --- fw-prompt/fw-prompt.go | 4 ++++ .../system-services/com.subgraph.FirewallPrompt.service | 4 ++++ 2 files changed, 8 insertions(+) create mode 100644 sources/usr/share/dbus-1/system-services/com.subgraph.FirewallPrompt.service diff --git a/fw-prompt/fw-prompt.go b/fw-prompt/fw-prompt.go index 8db4389..c022b2e 100644 --- a/fw-prompt/fw-prompt.go +++ b/fw-prompt/fw-prompt.go @@ -1107,6 +1107,10 @@ func buttonAction(action string) { } func main() { + if len(os.Args) == 3 && os.Args[1] == "-display" { + os.Setenv("DISPLAY", os.Args[2]) + } + _, err := newDbusServer() if err != nil { log.Fatal("Error:", err) diff --git a/sources/usr/share/dbus-1/system-services/com.subgraph.FirewallPrompt.service b/sources/usr/share/dbus-1/system-services/com.subgraph.FirewallPrompt.service new file mode 100644 index 0000000..8a71e40 --- /dev/null +++ b/sources/usr/share/dbus-1/system-services/com.subgraph.FirewallPrompt.service @@ -0,0 +1,4 @@ +[D-BUS Service] +Name=com.subgraph.FirewallPrompt +Exec=/usr/bin/fw-prompt -display :0 +User=user From d7df1655178eb646723254cc1b0d837788ce1399 Mon Sep 17 00:00:00 2001 From: Stephen Watt Date: Tue, 3 Oct 2017 19:54:33 -0400 Subject: [PATCH 2/4] 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...") From 85d7d60d76aeac4a710ab9ad3fd0facfcbb42274 Mon Sep 17 00:00:00 2001 From: Stephen Watt Date: Wed, 4 Oct 2017 00:27:06 -0400 Subject: [PATCH 3/4] Added new SGFW DBus method RunDebugCmd() for retrieving firewall state debugging information. Eliminated heavy SGFW CPU usage due to long loop condition. Implemented much more helpful print() method for pendingSocksConnection interface. testfw program updated to show use of new debugging interface. Removed lots of noisy debug print statements (and moved many to new debugging facility). --- sgfw/dbus.go | 14 +++++ sgfw/policy.go | 4 +- sgfw/prompt.go | 119 ++++++++++++++++++++++++++++--------- sgfw/socks_server_chain.go | 3 +- testfw/dbus.go | 22 ++++++- testfw/testfw.go | 22 +++++-- 6 files changed, 146 insertions(+), 38 deletions(-) diff --git a/sgfw/dbus.go b/sgfw/dbus.go index 0f7a2ad..714eedc 100644 --- a/sgfw/dbus.go +++ b/sgfw/dbus.go @@ -6,6 +6,7 @@ import ( "net" "path" "strconv" + "strings" "time" "github.com/godbus/dbus" @@ -289,6 +290,19 @@ func (ds *dbusServer) AddRuleAsync(scope uint32, rule, policy, guid string) (boo return true, nil } +func (ds *dbusServer) RunDebugCmd(cmd string, params string) (string, *dbus.Error) { + cmd = strings.ToLower(cmd) + result := "Unrecognized debug command: " + cmd + + if cmd == "monitorfds" { + result = dumpMonitoredFDs() + } else if cmd == "listpending" { + result = dumpPendingQueues() + } + + return result, nil +} + func (ds *dbusServer) AddTestVPC(proto string, srcip string, sport uint16, dstip string, dport uint16, hostname string) (bool, *dbus.Error) { log.Warningf("AddTestVPC(proto=%s, srcip=%s, sport=%v, dstip=%s, dport=%v, hostname=%s)\n", proto, srcip, sport, dstip, dport, hostname) diff --git a/sgfw/policy.go b/sgfw/policy.go index 5bfb77f..33974fa 100644 --- a/sgfw/policy.go +++ b/sgfw/policy.go @@ -279,7 +279,7 @@ func (fw *Firewall) policyForPath(path string) *Policy { } func (p *Policy) processPacket(pkt *nfqueue.NFQPacket, timestamp time.Time, pinfo *procsnitch.Info, optstr string) { - fmt.Println("policy processPacket()") + fmt.Println("policy processPacket() running against packet...") p.lock.Lock() defer p.lock.Unlock() @@ -554,7 +554,7 @@ func printPacket(pkt *nfqueue.NFQPacket, hostname string, pinfo *procsnitch.Info } func (fw *Firewall) filterPacket(pkt *nfqueue.NFQPacket, timestamp time.Time) { - fmt.Println("firewall: filterPacket()") + // fmt.Println("firewall: filterPacket()") isudp := pkt.Packet.Layer(layers.LayerTypeUDP) != nil if basicAllowPacket(pkt) { diff --git a/sgfw/prompt.go b/sgfw/prompt.go index 55c378c..8c31f64 100644 --- a/sgfw/prompt.go +++ b/sgfw/prompt.go @@ -14,11 +14,19 @@ import ( "github.com/subgraph/fw-daemon/proc-coroner" ) +var gPrompter *prompter = nil + func newPrompter(conn *dbus.Conn) *prompter { p := new(prompter) p.cond = sync.NewCond(&p.lock) p.dbusObj = conn.Object("com.subgraph.FirewallPrompt", "/com/subgraph/FirewallPrompt") p.policyMap = make(map[string]*Policy) + + if gPrompter != nil { + fmt.Println("Unexpected: global prompter variable was already set!") + } + + gPrompter = p go p.promptLoop() return p } @@ -62,12 +70,14 @@ func (p *prompter) processNextPacket() bool { pc, empty = p.nextConnection() p.lock.Unlock() if pc != nil { - fmt.Println("GOT NON NIL") + fmt.Println("Got next pending connection...") } //fmt.Println("XXX: processNextPacket() loop; empty = ", empty, " / pc = ", pc) if pc == nil && empty { + time.Sleep(100 * time.Millisecond) return false } else if pc == nil { + time.Sleep(100 * time.Millisecond) continue } else if pc != nil { break @@ -80,7 +90,6 @@ func (p *prompter) processNextPacket() bool { } pc.setPrompting(true) - fmt.Println("processConnection") go p.processConnection(pc) return true } @@ -93,9 +102,48 @@ type PC2FDMapping struct { prompter *prompter } +func dumpPendingQueues() string { + result := "" + pctotal := 0 + + if gPrompter == nil { + return "Cannot query pending connections; no prompts have been issued yet!" + } + + all_policies := make([]*Policy, 0) + gPrompter.lock.Lock() + defer gPrompter.lock.Unlock() + + for _, policy := range gPrompter.policyMap { + all_policies = append(all_policies, policy) + } + + result += fmt.Sprintf("Total policies: %d\n", len(all_policies)) + + for pind, policy := range all_policies { + policy.lock.Lock() + + if len(policy.pendingQueue) > 0 { + result += fmt.Sprintf(" Policy %d of %d (%s): #pc = %d\n", pind+1, + len(all_policies), policy.application, len(policy.pendingQueue)) + + for pcind, pc := range policy.pendingQueue { + result += fmt.Sprintf(" %d: %s\n", pcind+1, pc.print()) + pctotal++ + } + + } + + policy.lock.Unlock() + } + + result += "-----------------------------------\n" + result = fmt.Sprintf("Pending Queues / total pending connections = %d\n", pctotal) + result + return result +} + var PC2FDMap = map[string]PC2FDMapping{} var PC2FDMapLock = &sync.Mutex{} -var PC2FDMapRunning = false func monitorPromptFDs(pc pendingConnection) { guid := pc.getGUID() @@ -104,7 +152,7 @@ func monitorPromptFDs(pc pendingConnection) { fd := pc.procInfo().FD prompter := pc.getPrompter() - fmt.Printf("ADD TO MONITOR: %v | %v / %v / %v\n", pc.policy().application, guid, pid, fd) + //fmt.Printf("ADD TO MONITOR: %v | %v / %v / %v\n", pc.policy().application, guid, pid, fd) if pid == -1 || fd == -1 || prompter == nil { log.Warning("Unexpected error condition occurred while adding socket fd to monitor") @@ -119,16 +167,28 @@ func monitorPromptFDs(pc pendingConnection) { return } +func dumpMonitoredFDs() string { + PC2FDMapLock.Lock() + defer PC2FDMapLock.Unlock() + + cnt := 1 + result := fmt.Sprintf("Monitored FDs: %v total\n", len(PC2FDMap)) + for guid, fdmon := range PC2FDMap { + result += fmt.Sprintf("%d: %s -> [inode=%v, fd=%d, fdpath=%s]\n", cnt, guid, fdmon.inode, fdmon.fd, fdmon.fdpath) + cnt++ + } + + result += "-----------------------------------\n" + return result +} + func monitorPromptFDLoop() { - fmt.Println("++++++++++= monitorPromptFDLoop()") for true { delete_guids := []string{} PC2FDMapLock.Lock() - fmt.Println("++++ nentries = ", len(PC2FDMap)) for guid, fdmon := range PC2FDMap { - fmt.Println("ENTRY:", fdmon) lsb, err := os.Stat(fdmon.fdpath) if err != nil { @@ -154,7 +214,10 @@ func monitorPromptFDLoop() { } - fmt.Println("guids to delete: ", delete_guids) + if len(delete_guids) > 0 { + fmt.Println("guids to delete: ", delete_guids) + } + saved_mappings := []PC2FDMapping{} for _, guid := range delete_guids { saved_mappings = append(saved_mappings, PC2FDMap[guid]) @@ -164,9 +227,10 @@ func monitorPromptFDLoop() { PC2FDMapLock.Unlock() for _, mapping := range saved_mappings { - call := mapping.prompter.dbusObj.Call("com.subgraph.FirewallPrompt.RemovePrompt", 0, mapping.guid) - fmt.Println("DISPOSING CALL = ", call) + _ = mapping.prompter.dbusObj.Call("com.subgraph.FirewallPrompt.RemovePrompt", 0, mapping.guid) + // fmt.Println("DISPOSING CALL = ", call) prompter := mapping.prompter + found := false prompter.lock.Lock() @@ -177,8 +241,9 @@ func monitorPromptFDLoop() { for pcind < len(policy.pendingQueue) { if policy.pendingQueue[pcind].getGUID() == mapping.guid { - fmt.Println("-------------- found guid to remove") + // fmt.Println("-------------- found guid to remove") policy.pendingQueue = append(policy.pendingQueue[:pcind], policy.pendingQueue[pcind+1:]...) + found = true } else { pcind++ } @@ -188,33 +253,27 @@ func monitorPromptFDLoop() { policy.lock.Unlock() } + if !found { + fmt.Println("Warning: FD monitor could not find pending connection to map to removed GUID: %s", mapping.guid) + } + prompter.lock.Unlock() } - fmt.Println("++++++++++= monitorPromptFDLoop WAIT") time.Sleep(5 * time.Second) } } +func init() { + go monitorPromptFDLoop() +} + func (p *prompter) processConnection(pc pendingConnection) { var scope int32 var dres bool var rule string - if !PC2FDMapRunning { - PC2FDMapLock.Lock() - - if !PC2FDMapRunning { - PC2FDMapRunning = true - PC2FDMapLock.Unlock() - go monitorPromptFDLoop() - } else { - PC2FDMapLock.Unlock() - } - - } - if pc.getPrompter() == nil { pc.setPrompter(p) } @@ -338,10 +397,10 @@ func (p *prompter) nextConnection() (pendingConnection, bool) { if len(p.policyQueue) == 0 { return nil, true } - fmt.Println("policy queue len = ", len(p.policyQueue)) + //fmt.Println("policy queue len = ", len(p.policyQueue)) for pind < len(p.policyQueue) { - fmt.Printf("policy loop %d of %d\n", pind, len(p.policyQueue)) + //fmt.Printf("policy loop %d of %d\n", pind, len(p.policyQueue)) //fmt.Printf("XXX: pind = %v of %v\n", pind, len(p.policyQueue)) policy := p.policyQueue[pind] pc, qempty := policy.nextPending() @@ -362,7 +421,11 @@ func (p *prompter) nextConnection() (pendingConnection, bool) { pendingOther = append(pendingOther, r) } } - fmt.Printf("# pending once = %d, other = %d, pc = %p / policy = %p\n", len(pendingOnce), len(pendingOther), pc, policy) + + if len(pendingOnce) > 0 || len(pendingOther) > 0 { + fmt.Printf("# pending once = %d, other = %d, pc = %p / policy = %p\n", len(pendingOnce), len(pendingOther), pc, policy) + } + policy.rulesPending = pendingOther // One time filters are all applied right here, at once. diff --git a/sgfw/socks_server_chain.go b/sgfw/socks_server_chain.go index e4fbf58..1236959 100644 --- a/sgfw/socks_server_chain.go +++ b/sgfw/socks_server_chain.go @@ -161,7 +161,8 @@ func (sc *pendingSocksConnection) setPrompting(val bool) { } func (sc *pendingSocksConnection) print() string { - return "socks connection" + return fmt.Sprintf("SOCKS5 %s {%v:%v -> %v:%v (%s)}", + sc.policy().path, sc.srcIP, sc.sourcePort, sc.destIP, sc.destPort, sc.hname) } func NewSocksChain(cfg *socksChainConfig, wg *sync.WaitGroup, fw *Firewall) *socksChain { diff --git a/testfw/dbus.go b/testfw/dbus.go index 9f2fba2..9f96a0d 100644 --- a/testfw/dbus.go +++ b/testfw/dbus.go @@ -7,7 +7,6 @@ import ( "github.com/godbus/dbus" ) - const busName = "com.subgraph.FirewallTest" const objectPath = "/com/subgraph/FirewallTest" const interfaceName = "com.subgraph.FirewallTest" @@ -26,7 +25,7 @@ func newDbusObjectAdd() (*dbusObjectP, error) { } type dbusServer struct { - conn *dbus.Conn + conn *dbus.Conn } func newDbusServer() (*dbusServer, error) { @@ -58,10 +57,27 @@ func (ds *dbusServer) SGFWTestAlert(accepted int32, guid string, other string) ( return true, nil } +func CallRunDebugCmd(d *dbusObjectP, cmd string, params string) string { + var dres string + + fmt.Printf("> CallRunDebugCmd(cmd = %s, params = %s)\n", cmd, params) + + call := d.Call("RunDebugCmd", 0, + cmd, params) + + err := call.Store(&dres) + if err != nil { + fmt.Println("Error sending DBus RunDebugCmd() request:", err) + return "" + } + + return dres +} + func CallAddTestVPC(d *dbusObjectP, proto string, srcip string, sport uint16, dstip string, dport uint16, hostname string) bool { var dres bool - fmt.Printf("CallAddTestVPC(proto=%s, srcip=%s, sport=%u, dstip=%s, dport=%u, hostname=%s)\n", + fmt.Printf("> CallAddTestVPC(proto=%s, srcip=%s, sport=%u, dstip=%s, dport=%u, hostname=%s)\n", proto, srcip, sport, dstip, dport, hostname) call := d.Call("AddTestVPC", 0, diff --git a/testfw/testfw.go b/testfw/testfw.go index d972f38..40e1fd5 100644 --- a/testfw/testfw.go +++ b/testfw/testfw.go @@ -8,7 +8,6 @@ import ( var dbuso *dbusObjectP - func main() { fmt.Println("Starting up test units...") @@ -26,11 +25,26 @@ func main() { res := CallAddTestVPC(dbuso, "udp", "10.0.0.1", 61921, "8.8.8.8", 53, "dnsthing.google.com") fmt.Println("res =", res) - - fmt.Println("Waiting until interrupted...") + fmt.Println("Looping until interrupted...") for true { - time.Sleep(1 * time.Second) + result := CallRunDebugCmd(dbuso, "monitorfds", "") + + if result == "" { + fmt.Println("Error: could not read monitored FDs information from SGFW.") + } else { + fmt.Println(result) + } + + result = CallRunDebugCmd(dbuso, "listpending", "") + + if result == "" { + fmt.Println("Error: could not read pending queue(s) information from SGFW.") + } else { + fmt.Println(result) + } + + time.Sleep(5 * time.Second) } } From f616f54b2c82fc33f2b20bf99815046cce70295e Mon Sep 17 00:00:00 2001 From: Stephen Watt Date: Tue, 10 Oct 2017 23:09:59 -0400 Subject: [PATCH 4/4] Fix TLSGuard handshake timeout issue by breaking total timeout period into one second polling intervals. --- sgfw/tlsguard.go | 34 +++++++++++++++++++++++++++++----- 1 file changed, 29 insertions(+), 5 deletions(-) diff --git a/sgfw/tlsguard.go b/sgfw/tlsguard.go index 9370a06..6e2f93c 100644 --- a/sgfw/tlsguard.go +++ b/sgfw/tlsguard.go @@ -11,7 +11,7 @@ import ( "time" ) -const TLSGUARD_READ_TIMEOUT = 8 * time.Second +const TLSGUARD_READ_TIMEOUT = 8 // seconds const TLSGUARD_MIN_TLS_VER_MAJ = 3 const TLSGUARD_MIN_TLS_VER_MIN = 1 @@ -270,6 +270,7 @@ func connectionReader(conn net.Conn, is_client bool, c chan connReader, done cha mlen := 0 rtype := 0 stage := 1 + ntimeouts := 0 for { if ret_error != nil { @@ -291,11 +292,18 @@ func connectionReader(conn net.Conn, is_client bool, c chan connReader, done cha default: if stage == 1 { header := make([]byte, TLS_RECORD_HDR_LEN) - conn.SetReadDeadline(time.Now().Add(TLSGUARD_READ_TIMEOUT)) + conn.SetReadDeadline(time.Now().Add(1 * time.Second)) _, err := io.ReadFull(conn, header) conn.SetReadDeadline(time.Time{}) if err != nil { - ret_error = err + if err, ok := err.(net.Error); ok && err.Timeout() { + ret_error = err + } else { + ntimeouts++ + if ntimeouts == TLSGUARD_READ_TIMEOUT { + ret_error = err + } + } continue } @@ -323,13 +331,21 @@ func connectionReader(conn net.Conn, is_client bool, c chan connReader, done cha buffered = header stage++ + ntimeouts = 0 } else if stage == 2 { remainder := make([]byte, mlen) - conn.SetReadDeadline(time.Now().Add(TLSGUARD_READ_TIMEOUT)) + conn.SetReadDeadline(time.Now().Add(1 * time.Second)) _, err := io.ReadFull(conn, remainder) conn.SetReadDeadline(time.Time{}) if err != nil { - ret_error = err + if err, ok := err.(net.Error); ok && err.Timeout() { + ret_error = err + } else { + ntimeouts++ + if ntimeouts == TLSGUARD_READ_TIMEOUT { + ret_error = err + } + } continue } @@ -342,6 +358,7 @@ func connectionReader(conn net.Conn, is_client bool, c chan connReader, done cha rtype = 0 mlen = 0 stage = 1 + ntimeouts = 0 } } @@ -592,6 +609,8 @@ select_loop: if !cr.client && s == SSL3_MT_HELLO_REQUEST { fmt.Println("Server sent hello request") + other.Write(cr.data) + continue } if s > SSL3_MT_CERTIFICATE_STATUS { @@ -647,6 +666,11 @@ select_loop: return err } else { x509Valid = true + // Added in. + other.Write(cr.data) + dChan <- true + dChan2 <- true + break select_loop } }