Fix graceful service termination and add esvm logging

cmd/enit/main.go

@@ -100,30 +100,36 @@ func stopServiceManager() {
 	if err != nil {
 		log.Println("Could not stop service manager!")
 	}
+
 	// Check if service manager has stopped gracefully, otherwise send sigkill on timeout
-	ticker := time.NewTicker(500 * time.Millisecond)
+	exit := false
-	defer ticker.Stop()
+	for timeout := time.After(60 * time.Second); ; {
-	timer := time.NewTimer(5 * time.Second)
+		if exit {
-	defer timer.Stop()
+			break
-	select {
+		}
-	case <-timer.C:
+		select {
-		log.Println("Could not stop service manager!")
+		case <-timeout:
-		err := syscall.Kill(serviceManagerPid, syscall.SIGKILL)
-		if err != nil {
 			log.Println("Could not stop service manager!")
-		}
+			err := syscall.Kill(serviceManagerPid, syscall.SIGKILL)
-	case <-ticker.C:
+			if err != nil {
-		p, err := os.FindProcess(serviceManagerPid)
+				log.Println("Could not stop service manager!")
-		if err != nil {
+			}
-			break
+			exit = true
-		}
+		default:
-		err = p.Signal(syscall.Signal(0))
+			waitZombieProcesses()
-		if err != nil {
+			p, err := os.FindProcess(serviceManagerPid)
-			break
+			if err != nil {
+				exit = true
+				break
+			}
+			err = p.Signal(syscall.Signal(0))
+			if err != nil {
+				exit = true
+			}
 		}
 	}
 
-	fmt.Print("Done.")
+	fmt.Println("Done.")
 }
 
 func waitZombieProcesses() {

cmd/esvm/main.go

@@ -48,9 +48,18 @@ var serviceConfigDir string
 
 var Services = make([]EnitService, 0)
 
+var logger *log.Logger
 var socket net.Listener
 
 func main() {
+	loggerFile, err := os.OpenFile("/var/log/esvm.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
+	if err != nil {
+		log.Fatalf("Error opening /var/log/esvm/esvm.log: %v", err)
+	}
+	logger = log.New(loggerFile, "[ESVM] ", log.Lshortfile|log.LstdFlags)
+	// Print an empty line as separator
+	logger.Println()
+
 	// Parse flags
 	printVersion := flag.Bool("version", false, "print version and exit")
 	flag.Parse()
@@ -60,18 +69,18 @@ func main() {
 		os.Exit(0)
 	}
 
-	// Set directory variables
-	runtimeServiceDir = flag.Arg(0)
-	serviceConfigDir = flag.Arg(1)
-
 	if os.Getppid() != 1 {
 		fmt.Println("Enit must be run by PID 1!")
 		os.Exit(1)
 	}
 
-	err := Init()
+	// Set directory variables
+	runtimeServiceDir = flag.Arg(0)
+	serviceConfigDir = flag.Arg(1)
+
+	Init()
 	if err != nil {
-		log.Fatalf("Could not initialize esvm! Error: %s", err)
+
 	}
 
 	sigc := make(chan os.Signal, 1)
@@ -79,6 +88,7 @@ func main() {
 	go func() {
 		<-sigc
 		Destroy()
+		loggerFile.Close()
 		os.Exit(0)
 	}()
 
@@ -87,35 +97,40 @@ func main() {
 	}
 }
 
-func Init() error {
+func Init() {
+	logger.Println("Initializing ESVM...")
+
 	if _, err := os.Stat(runtimeServiceDir); err == nil {
-		return fmt.Errorf("runtime service directory %s already exists", runtimeServiceDir)
+		logger.Fatalf("Could not initialize ESVM! Error: %s", fmt.Errorf("runtime service directory %s already exists", runtimeServiceDir))
 	}
 
 	err := os.MkdirAll(runtimeServiceDir, 0755)
 	if err != nil {
-		return err
+		logger.Fatalf("Could not initialize ESVM! Error: %s", err)
 	}
 
 	socket, err = net.Listen("unix", path.Join(runtimeServiceDir, "esvm.sock"))
 	if err != nil {
-		return err
+		logger.Fatalf("Could not initialize ESVM! Error: %s", err)
 	}
 
 	if stat, err := os.Stat(serviceConfigDir); err != nil || !stat.IsDir() {
-		return nil
+		logger.Println("ESVM initialized successfully!")
+		return
 	}
 
 	dirEntries, err := os.ReadDir(path.Join(serviceConfigDir, "services"))
 	if err != nil {
-		return err
+		logger.Fatalf("Could not initialize ESVM! Error: %s", err)
 	}
 
 	for _, entry := range dirEntries {
 		if !entry.IsDir() && strings.HasSuffix(entry.Name(), ".esv") {
+			logger.Printf("Initializing service (%s)...\n", entry.Name())
 			bytes, err := os.ReadFile(path.Join(serviceConfigDir, "services", entry.Name()))
 			if err != nil {
-				log.Printf("Could not read service file at %s!", path.Join(serviceConfigDir, "services", entry.Name()))
+				logger.Printf("Could not read service file at %s!\n", path.Join(serviceConfigDir, "services", entry.Name()))
+				continue
 			}
 
 			service := EnitService{
@@ -130,49 +145,56 @@ func Init() error {
 				stopChannel:    make(chan bool),
 			}
 			if err := yaml.Unmarshal(bytes, &service); err != nil {
-				log.Printf("Could not read service file at %s!", path.Join(serviceConfigDir, "services", entry.Name()))
+				logger.Printf("Could not read service file at %s!\n", path.Join(serviceConfigDir, "services", entry.Name()))
+				continue
 			}
 
 			switch service.Type {
 			case "simple", "background":
 			default:
-				return fmt.Errorf("unknown service type: %s", service.Type)
+				logger.Printf("Unknown service type: %s\n", service.Type)
+				continue
 			}
 
 			switch service.ExitMethod {
 			case "stop_command", "kill":
 			default:
-				return fmt.Errorf("unknown exit method: %s", service.ExitMethod)
+				logger.Printf("Unknown exit method: %s\n", service.ExitMethod)
+				continue
 			}
 
 			service.ServiceRunPath = path.Join(runtimeServiceDir, service.Name)
 			err = os.MkdirAll(path.Join(service.ServiceRunPath), 0755)
 			if err != nil {
-				return err
+				logger.Fatalf("Could not initialize ESVM! Error: %s", err)
 			}
 
 			err = service.setCurrentState(EnitServiceUnloaded)
 			if err != nil {
-				return err
+				logger.Fatalf("Could not initialize ESVM! Error: %s", err)
 			}
 
 			Services = append(Services, service)
 
 			if err := service.StartService(); err != nil {
-				log.Printf("Could not start service %s: %s\n", service.Name, err)
+				logger.Printf("Could not start service %s: %s\n", service.Name, err)
 			}
+
+			logger.Printf("Service (%s) has been initialized!\n", service.Name)
 		}
 	}
 
-	return nil
+	logger.Println("ESVM initialized successfully!")
 }
 
 func Destroy() {
+	logger.Println("Stopping all ESVM services...")
 	for _, service := range Services {
 		if err := service.StopService(); err != nil {
-			log.Printf("Error stopping service %s: %s\n", service.Name, err)
+			logger.Printf("Error stopping service %s! Error: %s\n", service.Name, err)
 		}
 	}
+	logger.Println("All ESVM services have stopped!")
 }
 
 func GetServiceByName(name string) *EnitService {
@@ -238,6 +260,8 @@ func (service *EnitService) StartService() error {
 		return nil
 	}
 
+	logger.Printf("Starting service (%s)...\n", service.Name)
+
 	cmd := exec.Command("/bin/sh", "-c", "exec "+service.StartCmd)
 	if err := cmd.Start(); err != nil {
 		return err
@@ -262,6 +286,7 @@ func (service *EnitService) StartService() error {
 			if service.Type == "simple" && err == nil {
 				_ = service.setCurrentState(EnitServiceCompleted)
 			}
+			logger.Printf("Service (%s) has crashed!\n", service.Name)
 			_ = service.setCurrentState(EnitServiceCrashed)
 
 			if service.Restart {
@@ -270,6 +295,8 @@ func (service *EnitService) StartService() error {
 		}
 	}()
 
+	logger.Printf("Service (%s) has started!\n", service.Name)
+
 	return nil
 }
 
@@ -278,10 +305,15 @@ func (service *EnitService) StopService() error {
 		return nil
 	}
 
+	logger.Printf("Stopping service (%s)...\n", service.Name)
+
 	if service.ExitMethod == "kill" {
-		if service.GetProcess() == nil {
+		process := service.GetProcess()
+		if err := process.Signal(syscall.Signal(0)); err != nil {
+			logger.Printf("Service (%s) has stopped. (Process already dead)\n", service.Name)
 			return nil
 		}
+
 		go func() { service.stopChannel <- true }()
 
 		err := service.GetProcess().Signal(syscall.SIGTERM)
@@ -289,21 +321,29 @@ func (service *EnitService) StopService() error {
 			return err
 		}
 
-		ticker := time.NewTicker(500 * time.Millisecond)
+		exit := false
-		defer ticker.Stop()
+		for timeout := time.After(5 * time.Second); ; {
-		timer := time.NewTimer(5 * time.Second)
+			if exit {
-		defer timer.Stop()
-
-		select {
-		case <-timer.C:
-			err := service.GetProcess().Kill()
-			if err != nil {
-				return err
-			}
-		case <-ticker.C:
-			if service.GetProcess() == nil {
 				break
 			}
+			select {
+			case <-timeout:
+				logger.Println("Process took too long to finish. Forcefully killing process...")
+				err := service.GetProcess().Kill()
+				if err != nil {
+					return err
+				}
+				exit = true
+			default:
+				if process == nil {
+					exit = true
+					break
+				}
+				err = process.Signal(syscall.Signal(0))
+				if err != nil {
+					exit = true
+				}
+			}
 		}
 	} else {
 		cmd := exec.Command("/bin/sh", "-c", service.StopCmd)
@@ -322,6 +362,8 @@ func (service *EnitService) StopService() error {
 		return err
 	}
 
+	logger.Printf("Service (%s) has stopped!\n", service.Name)
+
 	return nil
 }
 
@@ -340,7 +382,7 @@ func (service *EnitService) RestartService() error {
 func listenToSocket() {
 	conn, err := socket.Accept()
 	if err != nil {
-		log.Println("Could not accept socket connection!")
+		logger.Println("Could not accept socket connection!")
 		panic(err)
 	}
 
@@ -356,7 +398,7 @@ func listenToSocket() {
 			return
 		}
 		if err != nil {
-			log.Fatal(err)
+			logger.Fatal(err)
 		}
 
 		command := string(buf[:n])