diff --git a/config/config.go b/config/config.go index 860c66005..a1662fe49 100644 --- a/config/config.go +++ b/config/config.go @@ -68,7 +68,7 @@ func InitConfig() { V2BotUrl = os.Getenv("V2_BOT_URL") V2BotToken = os.Getenv("V2_BOT_TOKEN") FfWebsocket = os.Getenv("FF_WEBSOCKET") == "true" - LogLevel = os.Getenv("LOG_LEVEL") + LogLevel = strings.ToUpper(os.Getenv("LOG_LEVEL")) // Add to super admins SuperAdmins = StripSuperAdmins(AdminStrings) diff --git a/go.mod b/go.mod index 8b0898986..3a073f373 100644 --- a/go.mod +++ b/go.mod @@ -61,6 +61,7 @@ require ( github.com/onsi/gomega v1.26.0 // indirect github.com/robfig/cron v1.2.0 github.com/urfave/negroni v1.0.0 // indirect + github.com/xhd2015/xgo/runtime v1.0.52 // indirect golang.org/x/exp v0.0.0-20230315142452-642cacee5cc0 // indirect gopkg.in/go-playground/assert.v1 v1.2.1 // indirect ) diff --git a/go.sum b/go.sum index d389d674c..d4ae95b46 100644 --- a/go.sum +++ b/go.sum @@ -2168,6 +2168,8 @@ github.com/urfave/cli v1.22.5/go.mod h1:Gos4lmkARVdJ6EkW0WaNv/tZAAMe9V7XWyB60NtX github.com/urfave/cli v1.22.9/go.mod h1:Gos4lmkARVdJ6EkW0WaNv/tZAAMe9V7XWyB60NtXRu0= github.com/urfave/negroni v1.0.0 h1:kIimOitoypq34K7TG7DUaJ9kq/N4Ofuwi1sjz0KipXc= github.com/urfave/negroni v1.0.0/go.mod h1:Meg73S6kFm/4PpbYdq35yYWoCZ9mS/YSx+lKnmiohz4= +github.com/xhd2015/xgo/runtime v1.0.52 h1:njcRzY3Xo2AFu/qQSC4ak9+JN7xFmaI3iEUyJxoErWM= +github.com/xhd2015/xgo/runtime v1.0.52/go.mod h1:9GBQ2SzJCzpD3T+HRN+2C0TUOGv7qIz4s0mad1xJ8Jo= github.com/xi2/xz v0.0.0-20171230120015-48954b6210f8 h1:nIPpBwaJSVYIxUFsDv3M8ofmx9yWTog9BfvIu0q41lo= github.com/xi2/xz v0.0.0-20171230120015-48954b6210f8/go.mod h1:HUYIGzjTL3rfEspMxjDjgmT5uz5wzYJKVo23qUhYTos= github.com/xiang90/probing v0.0.0-20190116061207-43a291ad63a2 h1:eY9dn8+vbi4tKz5Qo6v2eYzo7kUS51QINcR5jNpbZS8= diff --git a/main.go b/main.go index 58843ddf5..3c5361d00 100644 --- a/main.go +++ b/main.go @@ -7,6 +7,7 @@ import ( "os/signal" "syscall" "time" + "strings" "github.com/joho/godotenv" "github.com/robfig/cron" @@ -17,8 +18,27 @@ import ( "github.com/stakwork/sphinx-tribes/routes" "github.com/stakwork/sphinx-tribes/websocket" "gopkg.in/go-playground/validator.v9" + "github.com/xhd2015/xgo/runtime/core" + "github.com/xhd2015/xgo/runtime/trap" ) +func init() { + trap.AddInterceptor(&trap.Interceptor{ + Pre: func(ctx context.Context, f *core.FuncInfo, args core.Object, results core.Object) (interface{}, error) { + //if strings.Contains(f.Pkg, "sphinx-tribes") { + index := strings.Index(f.File, "sphinx-tribes") + trimmed := f.File + if index != -1 { + trimmed = f.File[index:] + } + fmt.Printf("%s:%d %s\n", trimmed, f.Line, f.Name) + //} + + + return nil, nil + }, + }) +} func main() { if err := godotenv.Load(); err != nil { fmt.Println("no .env file") diff --git a/routes/people.go b/routes/people.go index 1f11e5735..341987462 100644 --- a/routes/people.go +++ b/routes/people.go @@ -15,7 +15,7 @@ func PeopleRoutes() chi.Router { peopleHandler := handlers.NewPeopleHandler(db.DB) r.Group(func(r chi.Router) { - r.Get("/", utils.TraceWithLogging(peopleHandler.GetListedPeople)) + r.Get("/", peopleHandler.GetListedPeople) r.Get("/search", utils.TraceWithLogging(peopleHandler.GetPeopleBySearch)) r.Get("/posts", utils.TraceWithLogging(handlers.GetListedPosts)) r.Get("/wanteds/assigned/{uuid}", bountyHandler.GetPersonAssignedBounties) diff --git a/routes/test_routes.go b/routes/test_routes.go index 5b944adf5..bd20f2208 100644 --- a/routes/test_routes.go +++ b/routes/test_routes.go @@ -2,10 +2,10 @@ package routes import ( "net/http" - "runtime/trace" - "log" -// "os" - "bytes" +// "runtime/trace" +// "log" +//// "os" +// "bytes" "github.com/go-chi/chi" ) @@ -14,23 +14,23 @@ func TestRoutes() chi.Router { r := chi.NewRouter() r.Get("/internal-server-error", func(w http.ResponseWriter, r *http.Request) { - // Enable tracing - //f, err := os.Create("trace.out") - var buf bytes.Buffer - //if err != nil { - // log.Fatalf("Failed to create trace output file: %v", err) - //} - //defer f.Close() + // // Enable tracing + ////f, err := os.Create("trace.out") + //var buf bytes.Buffer + ////if err != nil { + //// log.Fatalf("Failed to create trace output file: %v", err) + ////} + ////defer f.Close() - if err := trace.Start(&buf); err != nil { - log.Fatalf("Failed to start trace: %v", err) - } - defer func() { - trace.Stop() - log.Println("Trace Data:") - log.Println(buf.String()) - }() - //panic("Forced internal server error") + //if err := trace.Start(&buf); err != nil { + // log.Fatalf("Failed to start trace: %v", err) + //} + //defer func() { + // trace.Stop() + // log.Println("Trace Data:") + //log.Println(buf.String()) + //}() + panic("Forced internal server error") }) return r diff --git a/trace.out b/trace.out new file mode 100644 index 000000000..83de2b6f9 Binary files /dev/null and b/trace.out differ diff --git a/utils/logger.go b/utils/logger.go index e32d9f06f..e4685b0d4 100644 --- a/utils/logger.go +++ b/utils/logger.go @@ -3,7 +3,7 @@ package utils import ( "log" "os" - "strings" + "github.com/stakwork/sphinx-tribes/config" ) type Logger struct { @@ -12,7 +12,6 @@ type Logger struct { errorLogger *log.Logger debugLogger *log.Logger machineLogger *log.Logger - logLevel string } var Log = Logger{ @@ -21,35 +20,34 @@ var Log = Logger{ errorLogger: log.New(os.Stderr, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile), debugLogger: log.New(os.Stdout, "DEBUG: ", log.Ldate|log.Ltime|log.Lshortfile), machineLogger: log.New(os.Stdout, "MACHINE: ", log.Ldate|log.Ltime|log.Lshortfile), - logLevel: strings.ToUpper(os.Getenv("LOG_LEVEL")), } func (l *Logger) Machine(format string, v ...interface{}) { - if l.logLevel == "MACHINE" { + if config.LogLevel == "MACHINE" { l.machineLogger.Printf(format, v...) } } func (l *Logger) Debug(format string, v ...interface{}) { - if l.logLevel == "MACHINE" || l.logLevel == "DEBUG" { + if config.LogLevel == "MACHINE" || config.LogLevel == "DEBUG" { l.debugLogger.Printf(format, v...) } } func (l *Logger) Info(format string, v ...interface{}) { - if l.logLevel == "MACHINE" || l.logLevel == "DEBUG" || l.logLevel == "INFO" { + if config.LogLevel == "MACHINE" || config.LogLevel == "DEBUG" || config.LogLevel == "INFO" { l.infoLogger.Printf(format, v...) } } func (l *Logger) Warning(format string, v ...interface{}) { - if l.logLevel == "MACHINE" || l.logLevel == "DEBUG" || l.logLevel == "INFO" || l.logLevel == "WARNING" { + if config.LogLevel == "MACHINE" || config.LogLevel == "DEBUG" || config.LogLevel == "INFO" || config.LogLevel == "WARNING" { l.warningLogger.Printf(format, v...) } } func (l *Logger) Error(format string, v ...interface{}) { - if l.logLevel == "MACHINE" || l.logLevel == "DEBUG" || l.logLevel == "INFO" || l.logLevel == "WARNING" || l.logLevel == "ERROR" { + if config.LogLevel == "MACHINE" || config.LogLevel == "DEBUG" || config.LogLevel == "INFO" || config.LogLevel == "WARNING" || config.LogLevel == "ERROR" { l.errorLogger.Printf(format, v...) } } diff --git a/utils/trace.go b/utils/trace.go index d7570c89c..d35c6ff8c 100644 --- a/utils/trace.go +++ b/utils/trace.go @@ -1,52 +1,86 @@ package utils import ( - "bytes" - "log" + //"bytes" +// "log" "net/http" "regexp" - "runtime/trace" +// "runtime/trace" + "runtime" + "fmt" "strings" ) +func AutoLog(fn http.HandlerFunc) http.HandlerFunc { + return func(w http.ResponseWriter, r *http.Request) { + defer logCallStack() + fn(w, r) + } +} + +func logCallStack() { + // Retrieve the stack trace + pc := make([]uintptr, 50) // Adjust size as needed + n := runtime.Callers(2, pc) + frames := runtime.CallersFrames(pc[:n]) + + fmt.Println("Call stack:") + for { + frame, more := frames.Next() + fmt.Printf("- %s (line %d)\n", frame.Function, frame.Line) + if !more { + break + } + } + fmt.Println() +} + func TraceWithLogging(next http.HandlerFunc) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - var buf bytes.Buffer + //var buf bytes.Buffer // Start trace capturing - if err := trace.Start(&buf); err != nil { - http.Error(w, "Failed to start trace", http.StatusInternalServerError) - log.Fatalf("Failed to start trace: %v", err) - return + //if err := trace.Start(&buf); err != nil { + // http.Error(w, "Failed to start trace", http.StatusInternalServerError) + // log.Fatalf("Failed to start trace: %v", err) + // return + //} + Log.Info("HI") + wrappedFn := func() { + defer func() { + buf := make([]byte, 4096) + n := runtime.Stack(buf, true) + stackTrace := string(buf[:n]) + Log.Info("%s", stackTrace) + //trace.Stop() + + //// Extract and process trace output + //traceOutput := buf.String() + ////log.Println("Raw Trace Output (for debugging):", traceOutput) + //// Split the trace output into lines + //traceLines := strings.Split(traceOutput, "\n") + //startedFormatting := false + + //// Log each trace line with a line number and format + //for _, line := range traceLines { + // if !startedFormatting && strings.Contains(line, "start trace") { + // startedFormatting = true + // } else { + // continue + // } + + // if line != "" { + // traceFormatted := formatTrace(line) + // for j, formattedLine := range traceFormatted { + // log.Printf("%03d %s", j+1, formattedLine) + // } + // } + //} + }() + next(w, r) } - defer func() { - trace.Stop() - - // Extract and process trace output - traceOutput := buf.String() - //log.Println("Raw Trace Output (for debugging):", traceOutput) - // Split the trace output into lines - traceLines := strings.Split(traceOutput, "\n") - startedFormatting := false - - // Log each trace line with a line number and format - for _, line := range traceLines { - if !startedFormatting && strings.Contains(line, "start trace") { - startedFormatting = true - } else { - continue - } - - if line != "" { - traceFormatted := formatTrace(line) - for j, formattedLine := range traceFormatted { - log.Printf("%03d %s", j+1, formattedLine) - } - } - } - }() + wrappedFn() - next(w, r) } }