improved startup time (gojue#9)

* log: added function time Signed-off-by: h0x0er <jatink843@protonmail.com> * cmd_handler: loading modules in threads Signed-off-by: h0x0er <jatink843@protonmail.com> * refactor Signed-off-by: h0x0er <jatink843@protonmail.com> * refactor Signed-off-by: h0x0er <jatink843@protonmail.com> * refactor Signed-off-by: h0x0er <jatink843@protonmail.com> * refactor Signed-off-by: h0x0er <jatink843@protonmail.com> * improved daemon logging Signed-off-by: h0x0er <jatink843@protonmail.com> * refactor Signed-off-by: h0x0er <jatink843@protonmail.com> * cmd_handler: logging load times Signed-off-by: h0x0er <jatink843@protonmail.com> * fix Signed-off-by: h0x0er <jatink843@protonmail.com> * checking tracked in tls Signed-off-by: h0x0er <jatink843@protonmail.com> * improved logging function execution time Signed-off-by: h0x0er <jatink843@protonmail.com> * improvements Signed-off-by: h0x0er <jatink843@protonmail.com> --------- Signed-off-by: h0x0er <jatink843@protonmail.com>
h0x0er · Mar 20, 2024 · 2741fb7 · 2741fb7
1 parent be08c5f
commit 2741fb7
Show file tree

Hide file tree

Showing 6 changed files with 77 additions and 17 deletions.
diff --git a/pkg/daemon/cmd_handler.go b/pkg/daemon/cmd_handler.go
@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"runtime"
 	"strings"
+	"time"
 )
 
 func LoadModuleForPaths(nodePaths, goPaths string) {
@@ -41,12 +42,12 @@ func loadDefaults() {
 
 func loadTLS(lib string, kind uint8) {
 	if lib != "" {
-		getInstanceTracker().loadTLS(lib, kind)
+		go getInstanceTracker().loadTLS(lib, kind)
 	}
-
 }
 
 func SetConfigs(newConfigs map[string]interface{}) {
+	dLog("SetConfigs", fmt.Sprintf("%v", newConfigs))
 	for k, v := range newConfigs {
 		switch k {
 		case "bufferSize":
@@ -65,7 +66,11 @@ func SetConfigs(newConfigs map[string]interface{}) {
 		case "loadDefaults":
 			shouldLoad := v.(bool)
 			if shouldLoad {
+				startLoadDefaults := time.Now()
 				loadDefaults()
+				endLoadDefaults := time.Now()
+				LogTime("loadDefaults", startLoadDefaults, endLoadDefaults)
+
 			}
 
 		}

diff --git a/pkg/daemon/instances.go b/pkg/daemon/instances.go
@@ -6,6 +6,7 @@ import (
 	"log"
 	"runtime"
 	"sync"
+	"time"
 
 	"ecapture/user/config"
 	"ecapture/user/module"
@@ -43,16 +44,17 @@ func getInstanceTracker() *instancesTracker {
 
 func (it *instancesTracker) track(kind uint8, lib string, mod module.IModule) {
 
-	log.Printf("[track] kind: %d, lib: %s", kind, lib)
+	dLog("track", fmt.Sprintf("kind: %d, lib: %s", kind, lib))
+
+	it.Lock()
+	defer it.Unlock()
 
 	_, ok := it.runningInstances[lib]
 	if ok {
 		return
 	}
 
-	it.Lock()
 	it.runningInstances[lib] = newInstance(kind, mod)
-	it.Unlock()
 
 }
 
@@ -86,6 +88,9 @@ func (it *instancesTracker) untrack(includedDefaults bool) {
 }
 
 func (it *instancesTracker) getRunningModules(showDefaults bool) []string {
+	it.Lock()
+	defer it.Unlock()
+
 	out := []string{}
 
 	for lib, ins := range it.runningInstances {
@@ -102,7 +107,8 @@ func (it *instancesTracker) getRunningModules(showDefaults bool) []string {
 }
 
 func (it *instancesTracker) loadTLS(lib string, kind uint8) {
-
+	start := time.Now()
+	defer logExecutionTime(fmt.Sprintf("loadTLS:%s", lib), start)
 	if it.isTracked(lib) {
 		log.Printf("[loadTLS] Already tracked: %s", lib)
 		return
@@ -156,13 +162,13 @@ func (it *instancesTracker) loadTLS(lib string, kind uint8) {
 	err = mod.Init(ctx, logger, conf)
 
 	if err != nil {
-		log.Printf("[loadTLS] error while mod Init for '%s' : %v", lib, err)
+		dLog("loadTLS", fmt.Sprintf("error while mod Init for '%s' : %v", lib, err))
 		return
 	}
 
 	err = mod.Run()
 	if err != nil {
-		log.Printf("[loadTLS] error while Run for '%s' : %v", lib, err)
+		dLog("loadTLS", fmt.Sprintf("error while Run for '%s' : %v", lib, err))
 		mod.Close()
 		return
 	}
@@ -174,6 +180,8 @@ func (it *instancesTracker) loadTLS(lib string, kind uint8) {
 }
 
 func (it *instancesTracker) isTracked(lib string) bool {
+	it.Lock()
+	defer it.Unlock()
 	_, ok := it.runningInstances[lib]
 	return ok
 

diff --git a/pkg/daemon/load_gobins.go b/pkg/daemon/load_gobins.go
@@ -5,16 +5,20 @@ import (
 	"ecapture/user/config"
 	"ecapture/user/module"
 	"fmt"
+	"time"
 )
 
 func loadGoBin(binPath string, kind uint8) {
+
 	if binPath != "" {
-		getInstanceTracker().loadGoBin(binPath, kind)
+		go getInstanceTracker().loadGoBin(binPath, kind)
 	}
-
 }
 
 func (it *instancesTracker) loadGoBin(binPath string, kind uint8) {
+	start := time.Now()
+	defer logExecutionTime(fmt.Sprintf("loadGoBin:%s", binPath), start)
+
 	if it.isTracked(binPath) {
 		dLog("loadGoBin", fmt.Sprintf("Already tracked: %s", binPath))
 		return
@@ -56,7 +60,6 @@ func (it *instancesTracker) loadGoBin(binPath string, kind uint8) {
 	}
 
 	dLog("loadGoBin", fmt.Sprintf("Module Dispatched: %s", binPath))
-
 	it.track(kind, binPath, mod)
 
 }
diff --git a/pkg/daemon/log.go b/pkg/daemon/log.go
@@ -0,0 +1,38 @@
+package daemon
+
+import (
+	"fmt"
+	"log"
+	"os"
+	"sync"
+	"time"
+)
+
+var logMutex sync.Mutex
+
+func writeLog(message string) {
+	logMutex.Lock()
+	defer logMutex.Unlock()
+
+	f, _ := os.OpenFile("/home/agent/daemon.log",
+		os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+
+	defer f.Close()
+
+	//This is to prevent printing time for a newline
+	if message == "\n" {
+		f.WriteString(fmt.Sprintf("\n"))
+	} else {
+		location, _ := time.LoadLocation("Etc/GMT")
+		f.WriteString(fmt.Sprintf("%s:%s\n", time.Now().In(location).Format("Mon, 02 Jan 2006 15:04:05 MST"), message))
+	}
+}
+
+func dLog(kind string, what string) {
+	logStr := fmt.Sprintf("[%s] %s", kind, what)
+	log.Print(logStr)
+}
+
+func LogTime(flag string, start time.Time, end time.Time) {
+	go writeLog(fmt.Sprintf("[%s] Took %f seconds", flag, end.Sub(start).Seconds()))
+}
diff --git a/pkg/daemon/mux.go b/pkg/daemon/mux.go
@@ -39,12 +39,12 @@ type requestHandler struct{}
 func (handler *requestHandler) tls(w http.ResponseWriter, r *http.Request) {
 
 	lib := r.URL.Query().Get("lib")
-	if len(lib) > 0 {
+	if len(lib) > 0 && !IsAlreadyTracked(lib) {
 		go loadTLS(lib, 1)
 	}
 
 	gobin := r.URL.Query().Get("gobin")
-	if len(gobin) > 0 {
+	if len(gobin) > 0 && !IsAlreadyTracked(gobin) {
 		go loadGoBin(gobin, 1)
 	}
 

diff --git a/pkg/daemon/utils.go b/pkg/daemon/utils.go
@@ -5,6 +5,7 @@ import (
 	"log"
 	"os"
 	"strings"
+	"time"
 )
 
 func makeLogger(kind string) *log.Logger {
@@ -19,10 +20,6 @@ func makeLogger(kind string) *log.Logger {
 	return log.New(whereFile, fmt.Sprintf("[%s] ", kind), log.LstdFlags)
 }
 
-func dLog(kind string, what string) {
-	log.Printf("[%s] %s", kind, what)
-}
-
 func isValidHost(host string) bool {
 
 	validHosts := make(map[string]bool)
@@ -41,3 +38,12 @@ func isHostPkgRegistry(host string) bool {
 func isReadMethod(method string) bool {
 	return strings.EqualFold(method, "GET") || strings.EqualFold(method, "HEAD")
 }
+
+func IsAlreadyTracked(what string) bool {
+	return getInstanceTracker().isTracked(what)
+}
+
+func logExecutionTime(what string, start time.Time) {
+	end := time.Now()
+	LogTime(what, start, end)
+}