diff --git a/src/fs/auth.go b/src/fs/auth.go index f398ec0..b89e822 100644 --- a/src/fs/auth.go +++ b/src/fs/auth.go @@ -37,6 +37,7 @@ func (service *MercuryFsService) authenticate(writer http.ResponseWriter, reques err := decoder.Decode(&data) if err != nil { writer.WriteHeader(http.StatusBadRequest) + logHttp(service, request, http.StatusBadRequest, 0) return } // read pin from the json body @@ -44,18 +45,23 @@ func (service *MercuryFsService) authenticate(writer http.ResponseWriter, reques if !ok { // pin is not a string, send 400 Bad Request writer.WriteHeader(http.StatusBadRequest) + logHttp(service, request, http.StatusBadRequest, 0) return } // query user for the given pin from the list of all users authToken, err := service.Users.queryUser(pin) switch { case err == sql.ErrNoRows: // if no such user exits, send 401 Unauthorized - log("No user with pin: %s", pin) - http.Error(writer, "Authentication Failed", http.StatusUnauthorized) + logInfo("No user with pin: %s", pin) + errMsg := "Authentication Failed" + http.Error(writer, errMsg, http.StatusUnauthorized) + logHttp(service, request, http.StatusUnauthorized, len(errMsg)) break case err != nil: // if some other error, send 500 Internal Server Error - http.Error(writer, "Internal Server Error", http.StatusInternalServerError) - log(err.Error()) + logError(err.Error()) + errMsg := "Internal Server Error" + http.Error(writer, errMsg, http.StatusInternalServerError) + logHttp(service, request, http.StatusInternalServerError, len(errMsg)) break default: // if no error, send proper auth token for that user respJson := fmt.Sprintf("{\"auth_token\": \"%s\"}", *authToken) @@ -64,13 +70,15 @@ func (service *MercuryFsService) authenticate(writer http.ResponseWriter, reques writer.Header().Set("Content-Length", strconv.FormatInt(size, 10)) writer.Header().Set("Content-Type", "application/json") writer.Write([]byte(respJson)) + logHttp(service, request, http.StatusOK, int(size)) } } -func (service *MercuryFsService) logout(w http.ResponseWriter, r *http.Request) { - authToken := parseAuthToken(r) +func (service *MercuryFsService) logout(writer http.ResponseWriter, request *http.Request) { + authToken := parseAuthToken(request) service.Users.remove(authToken) - w.WriteHeader(http.StatusOK) + writer.WriteHeader(http.StatusOK) + logHttp(service, request, http.StatusOK, 0) } func (service *MercuryFsService) checkAuthHeader(w http.ResponseWriter, r *http.Request) (user *HdaUser) { @@ -78,9 +86,11 @@ func (service *MercuryFsService) checkAuthHeader(w http.ResponseWriter, r *http. user = service.Users.find(authToken) // if user is nil, respond with 401 Unauthorized if user == nil { - http.Error(w, "Authentication Failed", http.StatusUnauthorized) + errMsg := "Authentication Failed" + http.Error(w, errMsg, http.StatusUnauthorized) + logHttp(service, r, http.StatusUnauthorized, len(errMsg)) } - return + return user } func (service *MercuryFsService) authMiddleware(pass http.HandlerFunc) http.HandlerFunc { @@ -115,9 +125,13 @@ func (service *MercuryFsService) shareReadAccess(pass http.HandlerFunc) http.Han shareName := r.URL.Query().Get("s") if access, err := user.HasReadAccess(shareName); !access { if err == nil { - http.Error(w, "Access Forbidden", http.StatusForbidden) + errMsg := "Access Forbidden" + http.Error(w, errMsg, http.StatusForbidden) + logHttp(service, r, http.StatusForbidden, len(errMsg)) } else { - http.Error(w, "Internal Server Error", http.StatusInternalServerError) + errMsg := "Internal Server Error" + http.Error(w, errMsg, http.StatusInternalServerError) + logHttp(service, r, http.StatusInternalServerError, len(errMsg)) } return } @@ -133,7 +147,9 @@ func (service *MercuryFsService) restrictCache(pass http.HandlerFunc) http.Handl fullPath, _ := service.fullPathToFile(share, path) if strings.Contains(fullPath, ".fscache") { - http.Error(w, "Cannot access cache via /files", http.StatusForbidden) + errMsg := "Cannot access cache via /files" + http.Error(w, errMsg, http.StatusForbidden) + logHttp(service, r, http.StatusForbidden, len(errMsg)) return } @@ -158,9 +174,13 @@ func (service *MercuryFsService) shareWriteAccess(pass http.HandlerFunc) http.Ha shareName := r.URL.Query().Get("s") if access, err := user.HasWriteAccess(shareName); !access { if err == nil { - http.Error(w, "Access Forbidden", http.StatusForbidden) + errMsg := "Access Forbidden" + http.Error(w, errMsg, http.StatusForbidden) + logHttp(service, r, http.StatusForbidden, len(errMsg)) } else { - http.Error(w, "Internal Server Error", http.StatusInternalServerError) + errMsg := "Internal Server Error" + http.Error(w, errMsg, http.StatusInternalServerError) + logHttp(service, r, http.StatusForbidden, len(errMsg)) } return } diff --git a/src/fs/cache.go b/src/fs/cache.go index 0574940..9cac869 100644 --- a/src/fs/cache.go +++ b/src/fs/cache.go @@ -1,7 +1,6 @@ package main import ( - "fmt" "github.com/disintegration/imaging" "os" "path/filepath" @@ -11,7 +10,7 @@ import ( func thumbnailer(imagePath string, savePath string) error { img, err := imaging.Open(imagePath) if err != nil { - log(`Error opening file at location: "%s" as image. Error is: "%s"`, imagePath, err.Error()) + logError(`Error opening file at location: "%s" as image. Error is: "%s"`, imagePath, err.Error()) return err } imgX := img.Bounds().Max.X @@ -25,7 +24,7 @@ func thumbnailer(imagePath string, savePath string) error { os.MkdirAll(filepath.Dir(savePath), os.ModePerm) err = imaging.Save(thumb, savePath) if err != nil { - log(`Error saving image thumbnail for file at location: "%s". Error is: "%s"`, imagePath, err.Error()) + logError(`Error saving image thumbnail for file at location: "%s". Error is: "%s"`, imagePath, err.Error()) return err } @@ -40,7 +39,7 @@ func fillCache(root string) error { func fillCacheWalkFunc(path string, info os.FileInfo, err error) error { defer func() { if v := recover(); v != nil { - log(fmt.Sprintf("Panic while creating thumbnail: %s", v)) + logError("Panic while creating thumbnail: %s", v) } }() @@ -84,12 +83,12 @@ func removeCacheWalkFunc(path string, info os.FileInfo, err error) error { if ! os.IsNotExist(err) { err := os.Remove(thumbnailPath) if err != nil { - log(`Error while deleting cache file. Error: "%s"`, err.Error()) + logError(`Error while deleting cache file. Error: "%s"`, err.Error()) } } err = watcher.Remove(path) if err != nil { - log(fmt.Sprintf("Error while removing file from watcher: %s", err)) + logError("Error while removing file from watcher: %s", err) } return nil } diff --git a/src/fs/file_utils.go b/src/fs/file_utils.go new file mode 100644 index 0000000..224ce61 --- /dev/null +++ b/src/fs/file_utils.go @@ -0,0 +1,25 @@ +package main + +import ( + "errors" + "fmt" + "os/exec" +) + +func Sed(offset, lines int) ([]byte, error) { + out, err := exec.Command("sed", "-n", fmt.Sprintf("%d,%dp", offset, offset+lines), LOGFILE).Output() + if err != nil { + logError(err.Error()) + return nil, errors.New("cannot read from logs") + } + return out, nil +} + +func Tail(lines int) ([]byte, error) { + out, err := exec.Command("tail", "-n", fmt.Sprintf("%d", lines), LOGFILE).Output() + if err != nil { + logError(err.Error()) + return nil, errors.New("cannot read from logs") + } + return out, nil +} diff --git a/src/fs/fs.go b/src/fs/fs.go index edc1f9a..3568a66 100644 --- a/src/fs/fs.go +++ b/src/fs/fs.go @@ -19,6 +19,7 @@ import ( "errors" "flag" "fmt" + log "github.com/Sirupsen/logrus" "github.com/amahi/go-metadata" "golang.org/x/net/http2" "hda_api_key" @@ -100,20 +101,23 @@ func main() { flag.PrintDefaults() return } - debugLevel(dbg) + + setLogLevel(log.Level(dbg)) if noDelete { - fmt.Printf("NOTICE: running without deleting content!\n") + fmt.Println("Running without deleting content!") + logWarn("Running without deleting content!") } if noUpload { - fmt.Printf("NOTICE: running without uploading content!\n") + fmt.Println("Running without uploading content!") + logWarn("Running without uploading content!") } initializeLogging() - metadata, err := metadata.Init(100000, METADATA_FILE, TMDB_API_KEY, TVRAGE_API_KEY, TVDB_API_KEY) + meta, err := metadata.Init(100000, METADATA_FILE, TMDB_API_KEY, TVRAGE_API_KEY, TVDB_API_KEY) if err != nil { - fmt.Printf("Error initializing metadata library\n") + fmt.Println("Error initializing metadata library") os.Remove(PID_FILE) os.Exit(1) } @@ -125,17 +129,16 @@ func main() { os.Exit(1) } // start ONE delayed, background metadata prefill of the cache - service.metadata = metadata + service.metadata = meta - go service.Shares.startMetadataPrefill(metadata) + go service.Shares.startMetadataPrefill(meta) watcher, _ = fsnotify.NewWatcher() defer watcher.Close() go service.Shares.createThumbnailCache() - log("Amahi Anywhere service v%s", VERSION) - + logInfo("Amahi Anywhere service v%s", VERSION) debug(4, "using api-key %s", apiKey) if http2Debug { @@ -150,17 +153,15 @@ func main() { for { conn, err := contactPfe(relayHost, relayPort, apiKey, service) if err != nil { - log("Error contacting the proxy.") - debug(2, "Error contacting the proxy: %s", err) + logError("Error contacting the proxy: %s", err) } else { err = service.StartServing(conn) if err != nil { - log("Error serving requests") - debug(2, "Error in StartServing: %s", err) + logError("Error in StartServing: %s", err) } } // reconnect fairly quickly, with some randomness - sleepTime := time.Duration(2000 + rand.Intn(2000)) + sleepTime := time.Duration(20000 + rand.Intn(2000)) time.Sleep(sleepTime * time.Millisecond) } os.Remove(PID_FILE) @@ -168,18 +169,17 @@ func main() { // connect to the proxy and send a POST request with the api-key func contactPfe(relayHost, relayPort, apiKey string, service *MercuryFsService) (net.Conn, error) { - relayLocation := relayHost + ":" + relayPort - log("Contacting Relay at: " + relayLocation) + logInfo("Contacting Relay at: " + relayLocation) addr, err := net.ResolveTCPAddr("tcp", relayLocation) if err != nil { - debug(2, "Error with ResolveTCPAddr: %s", err) + logError("Error with ResolveTCPAddr: %s", err) return nil, err } tcpConn, err := net.DialTCP("tcp", nil, addr) if err != nil { - debug(2, "Error with initial DialTCP: %s", err) + logError("Error with initial DialTCP: %s", err) return nil, err } @@ -191,12 +191,13 @@ func contactPfe(relayHost, relayPort, apiKey string, service *MercuryFsService) if DisableCertChecking { warning := "WARNING WARNING WARNING: running without checking TLS certs!!" - log(warning) - log(warning) - log(warning) + logWarn(warning) + logWarn(warning) + logWarn(warning) fmt.Println(warning) fmt.Println(warning) fmt.Println(warning) + service.TLSConfig = &tls.Config{InsecureSkipVerify: true} } @@ -211,13 +212,13 @@ func contactPfe(relayHost, relayPort, apiKey string, service *MercuryFsService) request.Header.Add("Api-Key", apiKey) request.Header.Add("Authorization", fmt.Sprintf("Token %s", SECRET_TOKEN)) rawRequest, _ := httputil.DumpRequest(request, true) - debug(5, "%s", rawRequest) + debug(5, "Raw API-key request: %s", rawRequest) var client *httputil.ClientConn if DisableHttps { warning := "WARNING WARNING: running without TLS!!" - log(warning) + logWarn(warning) fmt.Println(warning) conn := tcpConn client = httputil.NewClientConn(conn, nil) @@ -234,11 +235,11 @@ func contactPfe(relayHost, relayPort, apiKey string, service *MercuryFsService) if response.StatusCode != 200 { msg := fmt.Sprintf("Got an error response: %s", response.Status) - log(msg) + logInfo(msg) return nil, errors.New(msg) } - log("Connected to the proxy") + logInfo("Connected to the proxy") netCon, _ := client.Hijack() @@ -248,12 +249,14 @@ func contactPfe(relayHost, relayPort, apiKey string, service *MercuryFsService) // Clean up and quit func cleanQuit(exitCode int, message string) { fmt.Println("FATAL:", message) + log.Println("FATAL:", message) os.Exit(exitCode) } func panicHandler() { if v := recover(); v != nil { fmt.Println("PANIC:", v) + log.Println("PANIC:", v) } os.Remove(PID_FILE) } @@ -266,7 +269,8 @@ func setup() error { signal.Notify(c, os.Interrupt) go func() { for sig := range c { - log("Exiting with %v", sig) + fmt.Printf("Exiting with %v\n", sig) + log.Printf("Exiting with %v\n", sig) os.Remove(PID_FILE) os.Exit(1) } @@ -298,9 +302,9 @@ func checkPidFile() { } } if stale { - fmt.Printf("PID file exists, but it's stale. Continuing.\n") + fmt.Println("PID file exists, but it's stale. Continuing.") } else { - fmt.Printf("PID file exists and process is running. Exiting.\n") + fmt.Println("PID file exists and process is running. Exiting.") os.Exit(1) } } diff --git a/src/fs/hda_apps.go b/src/fs/hda_apps.go index 3d7cc1e..a41e904 100644 --- a/src/fs/hda_apps.go +++ b/src/fs/hda_apps.go @@ -37,14 +37,14 @@ func newHdaApps() (*HdaApps, error) { func (apps *HdaApps) list() error { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return err } defer dbconn.Close() q := SQL_SELECT_APPS rows, err := dbconn.Query(q) if err != nil { - log(err.Error()) + logError(err.Error()) return err } newApps := make([]*HdaApp, 0) diff --git a/src/fs/hda_shares.go b/src/fs/hda_shares.go index 8991eb1..4fa39bb 100644 --- a/src/fs/hda_shares.go +++ b/src/fs/hda_shares.go @@ -57,7 +57,7 @@ func (shares *HdaShares) updateShares() error { func (shares *HdaShares) updateSqlShares() error { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return err } defer dbconn.Close() @@ -65,7 +65,7 @@ func (shares *HdaShares) updateSqlShares() error { debug(5, "share query: %s\n", q) rows, err := dbconn.Query(q) if err != nil { - log(err.Error()) + logError(err.Error()) return err } newShares := make([]*HdaShare, 0) @@ -88,7 +88,7 @@ func (shares *HdaShares) updateDirShares() (nil error) { dir, err := os.Open(shares.rootDir) if err != nil { - log(err.Error()) + logError(err.Error()) return err } defer dir.Close() @@ -203,7 +203,7 @@ func (shares *HdaShares) createThumbnailCache() { // watch for events case event := <-watcher.Events: op := event.Op.String() - log("FSNOTIFY EVENT: `%s`, NAME: `%s`", op, event.Name) + logInfo("FSNOTIFY EVENT: `%s`, NAME: `%s`", op, event.Name) switch { case op == "CREATE" || op == "WRITE": fillCache(event.Name) @@ -218,7 +218,7 @@ func (shares *HdaShares) createThumbnailCache() { } }() - log("Starting caching") + logInfo("Starting caching") for i := range shares.Shares { // get path of the shares path := shares.Shares[i].path diff --git a/src/fs/hda_users.go b/src/fs/hda_users.go index f242e5f..dc3e091 100644 --- a/src/fs/hda_users.go +++ b/src/fs/hda_users.go @@ -1,11 +1,11 @@ package main import ( - "sync" + "crypto/rand" "database/sql" "fmt" + "sync" "time" - "crypto/rand" ) type HdaUser struct { @@ -44,7 +44,7 @@ func (users *HdaUsers) queryUser(pin string) (*string, error) { } else { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return nil, err } defer dbconn.Close() @@ -109,7 +109,7 @@ func (users *HdaUsers) remove(authToken string) { func (users *HdaUsers) revalidateSession(authToken string, user *HdaUser) (isValid bool, err error) { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return } defer dbconn.Close() @@ -130,7 +130,7 @@ func (users *HdaUsers) revalidateSession(authToken string, user *HdaUser) (isVal func (user *HdaUser) AvailableShares() ([]*HdaShare, error) { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return nil, err } defer dbconn.Close() @@ -143,7 +143,7 @@ func (user *HdaUser) AvailableShares() ([]*HdaShare, error) { "WHERE u.id = ? AND s.visible = 1 ORDER BY s.name ASC;" rows, err := dbconn.Query(q, user.id) if err != nil { - log(err.Error()) + logError(err.Error()) return nil, err } newShares := make([]*HdaShare, 0) @@ -161,7 +161,7 @@ func (user *HdaUser) HasReadAccess(shareName string) (access bool, err error) { } dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return } defer dbconn.Close() @@ -179,7 +179,7 @@ func (user *HdaUser) HasWriteAccess(shareName string) (access bool, err error) { } dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return } defer dbconn.Close() diff --git a/src/fs/local_server.go b/src/fs/local_server.go index 49dec6e..209ceb0 100644 --- a/src/fs/local_server.go +++ b/src/fs/local_server.go @@ -19,25 +19,25 @@ func (service *MercuryFsService) startLocalServer() { addr, err := net.ResolveTCPAddr("tcp", ":"+LocalServerPort) if err != nil { - log("Could not resolve local address") + logError("Could not resolve local address") debug(2, "Error resolving local address: %s", err.Error()) return } listener, err := net.ListenTCP("tcp", addr) if err != nil { - log("Local server could not be started") + logError("Local server could not be started") debug(2, "Error on ListenTCP: %s", err.Error()) return } defer listener.Close() for { - log("Starting local file server") + logInfo("Starting local file server") debug(2, "Starting local file server at: %s", LocalServerPort) err = service.server.Serve(listener) if err != nil { - log("An error occurred in the local file server") + logWarn("An error occurred in the local file server") debug(2, "local file server: %s", err.Error()) } } diff --git a/src/fs/logging.go b/src/fs/logging.go index 0af7004..ad48814 100644 --- a/src/fs/logging.go +++ b/src/fs/logging.go @@ -11,39 +11,92 @@ package main import ( "fmt" - logging "log" + log "github.com/Sirupsen/logrus" + "net/http" "os" ) const LOGFILE = "/var/log/amahi-anywhere.log" -var currentDebugLevel = 3 - -var logger *logging.Logger - func initializeLogging() { - logFile, err := os.OpenFile(LOGFILE, os.O_APPEND|os.O_CREATE|os.O_RDWR, 0644) + logFile, err := os.OpenFile(LOGFILE, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) if err != nil { fmt.Println("WARNING: failed to open ", LOGFILE, " defaulting to standard output") logFile = os.Stdout } - logger = logging.New(logFile, "", logging.LstdFlags) + Formatter := new(log.TextFormatter) + Formatter.TimestampFormat = "02-01-2006 15:04:05.000" + Formatter.FullTimestamp = true + Formatter.DisableColors = true + log.SetFormatter(Formatter) + log.SetOutput(logFile) +} + +func setLogLevel(level log.Level) { + log.SetLevel(level) +} + +func getLogLevel() log.Level { + return log.GetLevel() } -func log(f string, args ...interface{}) { - logger.Printf(f, args...) +func logTrace(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Trace(msg) } -func debugLevel(level int) { - currentDebugLevel = level +func logDebug(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Debug(msg) +} + +func logInfo(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Info(msg) +} + +func logWarn(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Warn(msg) +} + +func logError(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Error(msg) +} + +func logFatal(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Fatal(msg) +} + +func logPanic(f string, args ...interface{}) { + msg := fmt.Sprintf(f, args...) + log.Panic(msg) +} + +func logHttp(service *MercuryFsService, r *http.Request, responseCode,responseSize int) { + //having a separate method for logging will help easily modify the log statements if required + + var origin string + switch r.Host { + case service.info.local_addr: + origin = "local" + case service.info.relay_addr: + origin = "remote" + default: + origin = "unknown" + } + + logInfo("\"%s %s\" %d %d \"%s\" origin:%s", r.Method, pathForLog(r.URL), responseCode, responseSize, r.Header.Get("User-Agent"), origin) } func debug(level int, f string, args ...interface{}) { if PRODUCTION { return } - if level <= currentDebugLevel { - log(f, args...) + if level <= int(getLogLevel()) { + logDebug(f, args...) } } diff --git a/src/fs/service.go b/src/fs/service.go index ccc3039..d235cd5 100644 --- a/src/fs/service.go +++ b/src/fs/service.go @@ -62,7 +62,7 @@ func NewMercuryFSService(rootDir, localAddr string, isDemo bool) (service *Mercu service.Users = NewHdaUsers(isDemo) service.Shares, err = NewHdaShares(rootDir) if err != nil { - debug(3, "Error making HdaShares: %s", err.Error()) + logError("Error making HdaShares: %s", err.Error()) return nil, err } service.debugInfo = new(debugInfo) @@ -79,6 +79,10 @@ func NewMercuryFSService(rootDir, localAddr string, isDemo bool) (service *Mercu apiRouter.HandleFunc("/apps", service.appsList).Methods("GET") apiRouter.HandleFunc("/md", service.getMetadata).Methods("GET") apiRouter.HandleFunc("/hda_debug", service.hdaDebug).Methods("GET") + apiRouter.HandleFunc("/logs", service.serveLogs).Methods("GET") + + apiRouter.MethodNotAllowedHandler = http.HandlerFunc(service.methodNotAllowedHandler) + apiRouter.NotFoundHandler = http.HandlerFunc(service.notFoundHandler) service.apiRouter = apiRouter @@ -92,7 +96,6 @@ func NewMercuryFSService(rootDir, localAddr string, isDemo bool) (service *Mercu if localAddr != "" { service.info.local_addr = localAddr } else { - actualAddr, err := GetLocalAddr(rootDir) if err != nil { debug(2, "Error getting local address: %s", err.Error()) @@ -115,6 +118,22 @@ func (service *MercuryFsService) String() string { return SharesJson(service.Shares.Shares) } +//type notFoundHandler struct {} +func (service *MercuryFsService) notFoundHandler(writer http.ResponseWriter, request *http.Request) { + errMsg := "404 page not found" + writer.WriteHeader(http.StatusNotFound) + writer.Write([]byte(errMsg)) + logHttp(service, request, http.StatusNotFound, len(errMsg)) +} + +//type methodNotAllowedHandler struct{} +func (service *MercuryFsService) methodNotAllowedHandler(writer http.ResponseWriter, request *http.Request) { + errMsg := "405 method not allowed" + writer.WriteHeader(http.StatusMethodNotAllowed) + writer.Write([]byte(errMsg)) + logHttp(service, request, http.StatusMethodNotAllowed, len(errMsg)) +} + func (service *MercuryFsService) hdaDebug(writer http.ResponseWriter, request *http.Request) { // I am purposely not calling any of the update methods of debugInfo to actually provide valuable info result := "{\n" @@ -143,7 +162,8 @@ func (service *MercuryFsService) hdaDebug(writer http.ResponseWriter, request *h result += "}" writer.WriteHeader(200) - writer.Write([]byte(result)) + size, _ := writer.Write([]byte(result)) + logHttp(service, request, 200, size) } func directory(fi os.FileInfo, js string, w http.ResponseWriter, request *http.Request) (status, size int64) { @@ -174,7 +194,6 @@ func directory(fi os.FileInfo, js string, w http.ResponseWriter, request *http.R // there aren't any '..' to prevent unauthorized access func (service *MercuryFsService) fullPathToFile(shareName, relativePath string) (string, error) { share := service.Shares.Get(shareName) - if share == nil { return "", errors.New(fmt.Sprintf("Share %s not found", shareName)) } else if strings.Contains(relativePath, "../") { @@ -182,59 +201,48 @@ func (service *MercuryFsService) fullPathToFile(shareName, relativePath string) } path := share.GetPath() + relativePath - debug(3, "Full path: %s", path) return path, nil } // serve requests with the ServeConn function over HTTP/2, in goroutines, until we get some error func (service *MercuryFsService) StartServing(conn net.Conn) error { - log("Connection to the proxy established.") + logInfo("Connection to the proxy established.") service.info.relay_addr = conn.RemoteAddr().String() - serveConnOpts := &http2.ServeConnOpts{BaseConfig: service.server} server2 := new(http2.Server) // start serving over http2 on provided conn and block until connection is lost server2.ServeConn(conn, serveConnOpts) - log("Lost connection to the proxy.") + logWarn("Lost connection to the proxy.") service.info.relay_addr = "" - return errors.New("connection is no longer readable") } -func (service *MercuryFsService) serveCache(writer http.ResponseWriter, request *http.Request) { +func (service *MercuryFsService) serveFile(writer http.ResponseWriter, request *http.Request) { q := request.URL path := q.Query().Get("p") share := q.Query().Get("s") - ua := request.Header.Get("User-Agent") - query := pathForLog(request.URL) debug(2, "serve_file GET request") service.printRequest(request) fullPath, err := service.fullPathToFile(share, path) - - parentDir := filepath.Dir(fullPath) - filename := filepath.Base(fullPath) - thumbnailDirPath := filepath.Join(parentDir, ".fscache/thumbnails") - thumbnailPath := filepath.Join(thumbnailDirPath, filename) - if err != nil { debug(2, "File not found: %s", err) http.NotFound(writer, request) service.debugInfo.requestServed(int64(0)) - log("\"GET %s\" 404 0 \"%s\"", query, ua) + logHttp(service, request, 404, 0) return } - osFile, err := os.Open(thumbnailPath) + osFile, err := os.Open(fullPath) if err != nil { - debug(2, "Error opening cache file: %s", err.Error()) + debug(2, "Error opening file: %s", err.Error()) http.NotFound(writer, request) service.debugInfo.requestServed(int64(0)) - log("\"GET %s\" 404 0 \"%s\"", query, ua) + logHttp(service, request, 404, 0) return } defer osFile.Close() @@ -242,12 +250,20 @@ func (service *MercuryFsService) serveCache(writer http.ResponseWriter, request // This shouldn't return an error since we just opened the file fi, _ := osFile.Stat() - // If the file is a directory, return 404 as cache file doesn't exist for directory + // If the file is a directory, return the all the files within the directory... if fi.IsDir() || isSymlinkDir(fi, fullPath) { - debug(2, "Cache for directory not available") - http.NotFound(writer, request) - service.debugInfo.requestServed(int64(0)) - log("\"GET %s\" 404 0 \"%s\"", query, ua) + jsonDir, err := dirToJSON(osFile, fullPath, share, path) + if err != nil { + debug(2, "Error converting dir to JSON: %s", err.Error()) + http.NotFound(writer, request) + service.debugInfo.requestServed(int64(0)) + logHttp(service, request, 404, 0) + return + } + debug(5, "%s", jsonDir) + status, size := directory(fi, jsonDir, writer, request) + service.debugInfo.requestServed(size) + logHttp(service, request, int(status), int(size)) return } @@ -258,47 +274,48 @@ func (service *MercuryFsService) serveCache(writer http.ResponseWriter, request if inm == etag { debug(4, "If-None-Match match found for %s", etag) writer.WriteHeader(http.StatusNotModified) - log("\"GET %s\" %d \"%s\"", query, 304, ua) + logHttp(service, request, 304, 0) } else { writer.Header().Set("Last-Modified", mtime) writer.Header().Set("ETag", etag) writer.Header().Set("Cache-Control", "max-age=0, private, must-revalidate") debug(4, "Etag sent: %s", etag) - - http.ServeContent(writer, request, thumbnailPath, fi.ModTime(), osFile) - log("\"GET %s\" %d %d \"%s\"", query, 200, fi.Size(), ua) + http.ServeContent(writer, request, fullPath, fi.ModTime(), osFile) service.debugInfo.requestServed(fi.Size()) + logHttp(service, request, 200, int(fi.Size())) } - return - } -func (service *MercuryFsService) serveFile(writer http.ResponseWriter, request *http.Request) { +func (service *MercuryFsService) serveCache(writer http.ResponseWriter, request *http.Request) { q := request.URL path := q.Query().Get("p") share := q.Query().Get("s") - ua := request.Header.Get("User-Agent") - query := pathForLog(request.URL) debug(2, "serve_file GET request") service.printRequest(request) fullPath, err := service.fullPathToFile(share, path) + + parentDir := filepath.Dir(fullPath) + filename := filepath.Base(fullPath) + thumbnailDirPath := filepath.Join(parentDir, ".fscache/thumbnails") + thumbnailPath := filepath.Join(thumbnailDirPath, filename) + if err != nil { debug(2, "File not found: %s", err) http.NotFound(writer, request) service.debugInfo.requestServed(int64(0)) - log("\"GET %s\" 404 0 \"%s\"", query, ua) + logHttp(service, request, 404, 0) return } - osFile, err := os.Open(fullPath) + osFile, err := os.Open(thumbnailPath) if err != nil { - debug(2, "Error opening file: %s", err.Error()) + debug(2, "Error opening cache file: %s", err.Error()) http.NotFound(writer, request) service.debugInfo.requestServed(int64(0)) - log("\"GET %s\" 404 0 \"%s\"", query, ua) + logHttp(service, request, 404, 0) return } defer osFile.Close() @@ -306,20 +323,12 @@ func (service *MercuryFsService) serveFile(writer http.ResponseWriter, request * // This shouldn't return an error since we just opened the file fi, _ := osFile.Stat() - // If the file is a directory, return the all the files within the directory... + // If the file is a directory, return 404 as cache file doesn't exist for directory if fi.IsDir() || isSymlinkDir(fi, fullPath) { - jsonDir, err := dirToJSON(osFile, fullPath, share, path) - if err != nil { - debug(2, "Error converting dir to JSON: %s", err.Error()) - log("\"GET %s\" 404 0 \"%s\"", query, ua) - http.NotFound(writer, request) - service.debugInfo.requestServed(int64(0)) - return - } - debug(5, "%s", jsonDir) - status, size := directory(fi, jsonDir, writer, request) - service.debugInfo.requestServed(size) - log("\"GET %s\" %d %d \"%s\"", query, status, size, ua) + debug(2, "Cache for directory not available") + http.NotFound(writer, request) + service.debugInfo.requestServed(int64(0)) + logHttp(service, request, 404, 0) return } @@ -330,18 +339,20 @@ func (service *MercuryFsService) serveFile(writer http.ResponseWriter, request * if inm == etag { debug(4, "If-None-Match match found for %s", etag) writer.WriteHeader(http.StatusNotModified) - log("\"GET %s\" %d \"%s\"", query, 304, ua) + logHttp(service, request, 304, 0) } else { writer.Header().Set("Last-Modified", mtime) writer.Header().Set("ETag", etag) writer.Header().Set("Cache-Control", "max-age=0, private, must-revalidate") debug(4, "Etag sent: %s", etag) - http.ServeContent(writer, request, fullPath, fi.ModTime(), osFile) - log("\"GET %s\" %d %d \"%s\"", query, 200, fi.Size(), ua) + + http.ServeContent(writer, request, thumbnailPath, fi.ModTime(), osFile) service.debugInfo.requestServed(fi.Size()) + logHttp(service, request, 200, int(fi.Size())) } return + } func (service *MercuryFsService) serveShares(writer http.ResponseWriter, request *http.Request) { @@ -372,6 +383,7 @@ func (service *MercuryFsService) serveShares(writer http.ResponseWriter, request debug(4, "If-None-Match match found for %s", etag) writer.WriteHeader(http.StatusNotModified) service.debugInfo.requestServed(int64(0)) + logHttp(service, request, http.StatusNotModified, 0) } else { debug(4, "If-None-Match (%s) match NOT found for Etag %s", inm, etag) size := int64(len(json)) @@ -383,6 +395,7 @@ func (service *MercuryFsService) serveShares(writer http.ResponseWriter, request writer.WriteHeader(http.StatusOK) writer.Write([]byte(json)) service.debugInfo.requestServed(size) + logHttp(service, request, http.StatusOK, int(size)) } } @@ -394,7 +407,7 @@ func GetLocalAddr(rootDir string) (string, error) { dbconn, err := sql.Open("mysql", MYSQL_CREDENTIALS) if err != nil { - log(err.Error()) + logError(err.Error()) return "", err } defer dbconn.Close() @@ -404,13 +417,13 @@ func GetLocalAddr(rootDir string) (string, error) { row := dbconn.QueryRow(q, "net") err = row.Scan(&prefix) if err != nil { - log(err.Error()) + logInfo(err.Error()) return "", err } row = dbconn.QueryRow(q, "self-address") err = row.Scan(&addr) if err != nil { - log("Error scanning self-address: %s\n", err.Error()) + logError("Error scanning self-address: %s\n", err.Error()) return "", err } @@ -486,6 +499,7 @@ func (service *MercuryFsService) appsList(writer http.ResponseWriter, request *h debug(4, "If-None-Match match found for %s", etag) writer.WriteHeader(http.StatusNotModified) service.debugInfo.requestServed(int64(0)) + logHttp(service, request, http.StatusNotModified, 0) } else { debug(4, "If-None-Match (%s) match NOT found for Etag %s", inm, etag) size := int64(len(json)) @@ -496,22 +510,26 @@ func (service *MercuryFsService) appsList(writer http.ResponseWriter, request *h writer.WriteHeader(http.StatusOK) writer.Write([]byte(json)) service.debugInfo.requestServed(size) + logHttp(service, request, http.StatusOK, int(size)) } } func (service *MercuryFsService) getMetadata(writer http.ResponseWriter, request *http.Request) { // get the filename and the hint q := request.URL + filename, err := url.QueryUnescape(q.Query().Get("f")) if err != nil { debug(3, "get_metadata error parsing file: %s", err) http.NotFound(writer, request) + logHttp(service, request, 404, 0) return } hint, err := url.QueryUnescape(q.Query().Get("h")) if err != nil { debug(3, "get_metadata error parsing hint: %s", err) http.NotFound(writer, request) + logHttp(service, request, 404, 0) return } debug(5, "metadata filename: %s", filename) @@ -521,6 +539,7 @@ func (service *MercuryFsService) getMetadata(writer http.ResponseWriter, request if err != nil { debug(3, "metadata error: %s", err) http.NotFound(writer, request) + logHttp(service, request, 404, 0) return } debug(5, "========= DEBUG get_metadata request: %d", len(service.Shares.Shares)) @@ -531,6 +550,7 @@ func (service *MercuryFsService) getMetadata(writer http.ResponseWriter, request debug(4, "If-None-Match match found for %s", etag) writer.WriteHeader(http.StatusNotModified) service.debugInfo.requestServed(int64(0)) + logHttp(service, request, http.StatusUnauthorized, 0) } else { debug(4, "If-None-Match (%s) match NOT found for Etag %s", inm, etag) size := int64(len(json)) @@ -541,6 +561,7 @@ func (service *MercuryFsService) getMetadata(writer http.ResponseWriter, request writer.WriteHeader(http.StatusOK) writer.Write([]byte(json)) service.debugInfo.requestServed(size) + logHttp(service, request, http.StatusOK, int(size)) } } @@ -556,9 +577,7 @@ func (service *MercuryFsService) printRequest(request *http.Request) { } func (service *MercuryFsService) topVhostFilter(writer http.ResponseWriter, request *http.Request) { - header := writer.Header() - ua := request.Header.Get("User-Agent") // since data will change with the session, we should indicate that to keep caching! header.Add("Vary", "Session") @@ -615,8 +634,6 @@ func (service *MercuryFsService) deleteFile(writer http.ResponseWriter, request q := request.URL path := q.Query().Get("p") share := q.Query().Get("s") - ua := request.Header.Get("User-Agent") - query := pathForLog(request.URL) debug(2, "deleteFile DELETE request") @@ -630,7 +647,7 @@ func (service *MercuryFsService) deleteFile(writer http.ResponseWriter, request debug(2, "File not found: %s", err) http.NotFound(writer, request) service.debugInfo.requestServed(int64(0)) - log("\"DELETE %s\" 404 0 \"%s\"", query, ua) + logHttp(service, request, 404, 0) return } err = os.Remove(fullPath) @@ -638,7 +655,7 @@ func (service *MercuryFsService) deleteFile(writer http.ResponseWriter, request debug(2, "Error removing file: %s", err.Error()) writer.WriteHeader(http.StatusExpectationFailed) service.debugInfo.requestServed(int64(0)) - log("\"DELETE %s\" 417 0 \"%s\"", query, ua) + logHttp(service, request, 417, 0) return } } else { @@ -646,6 +663,7 @@ func (service *MercuryFsService) deleteFile(writer http.ResponseWriter, request } writer.WriteHeader(http.StatusOK) + logHttp(service, request, http.StatusOK, 0) return } @@ -655,8 +673,6 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request q := request.URL path := q.Query().Get("p") share := q.Query().Get("s") - ua := request.Header.Get("User-Agent") - query := pathForLog(request.URL) debug(2, "upload_file POST request") @@ -683,7 +699,7 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request debug(2, "Error parsing image: %s", err.Error()) writer.WriteHeader(http.StatusPreconditionFailed) service.debugInfo.requestServed(int64(0)) - log("\"POST %s\" 412 0 \"%s\"", query, ua) + logHttp(service, request, 412, 0) return } @@ -693,7 +709,7 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request debug(2, "Error finding uploaded file: %s", err.Error()) writer.WriteHeader(http.StatusExpectationFailed) service.debugInfo.requestServed(int64(0)) - log("\"POST %s\" 417 0 \"%s\"", query, ua) + logHttp(service, request, 417, 0) return } defer file.Close() @@ -704,7 +720,7 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request debug(2, "invalid filename") writer.WriteHeader(http.StatusUnsupportedMediaType) service.debugInfo.requestServed(int64(0)) - log("\"POST %s\" 415 0 \"%s\"", query, ua) + logHttp(service, request, 415, 0) return } @@ -726,7 +742,7 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request debug(2, "Error creating uploaded file: %s", err.Error()) writer.WriteHeader(http.StatusServiceUnavailable) service.debugInfo.requestServed(int64(0)) - log("\"POST %s\" 503 0 \"%s\"", query, ua) + logHttp(service, request, 503, 0) return } // status == FILE_SAME_MD5, ignore it @@ -740,6 +756,45 @@ func (service *MercuryFsService) uploadFile(writer http.ResponseWriter, request } writer.WriteHeader(http.StatusOK) + logHttp(service, request, 200, 0) return } + +func (service *MercuryFsService) serveLogs(writer http.ResponseWriter, request *http.Request) { + q := request.URL + amt := q.Query().Get("mode") + + mode := 100 // determines the numbers of lines to serve (from last). -1 will cause serving complete log file + + if n, err := strconv.Atoi(amt); err == nil { + mode = n + } else { + if strings.ToLower(amt) == "all" { + mode = -1 + } + } + + osFile, err := os.Open(LOGFILE) + if err != nil { + debug(2, "Error opening log file: %s", err.Error()) + http.NotFound(writer, request) + service.debugInfo.requestServed(int64(0)) + logHttp(service, request, 404, 0) + return + } + defer osFile.Close() + + fi, _ := osFile.Stat() + if mode == -1 { + http.ServeContent(writer, request, osFile.Name(), fi.ModTime(), osFile) + logHttp(service, request, 200, int(fi.Size())) + } else { + data, err := Tail(mode) + if err != nil { + writer.WriteHeader(http.StatusNotFound) + } + size, _ := writer.Write(data) + logHttp(service, request, 200, size) + } +}