Implement graceful shutdown on Mac

Question

Implement graceful shutdown on Mac

altanbgn opened this issue 9 months ago · 40 comments

I usually unconsciously do Ctrl-C and I found this what I consider a bug or maybe it could just because of my code. I'm not really sure. So when the server is up and running and everything goes perfect right? and when I exit with Ctrl-C it does not finish the exiting process causing port already in use on next start.

2024/02/23 10:50:34 ⇨ MongoDB Connected!

   ____    __
  / __/___/ /  ___
 / _// __/ _ \/ _ \
/___/\__/_//_/\___/ v4.11.4
High performance, minimalist Go web framework
https://echo.labstack.com
____________________________________O/_______
                                    O\
⇨ http server started on [::]:1323
^Ccleaning...
see you again~
❯ air

  __    _   ___
 / /\  | | | |_)
/_/--\ |_| |_| \_ v1.50.0, built with Go go1.22.0

watching .
watching cmd
watching cmd/aion
watching internal
watching internal/cmd
watching internal/db
watching internal/handlers
watching internal/middlewares
watching internal/models
watching internal/routes
watching internal/utils
!exclude tmp
building...
running...
2024/02/23 10:50:38 ⇨ MongoDB Connected!

   ____    __
  / __/___/ /  ___
 / _// __/ _ \/ _ \
/___/\__/_//_/\___/ v4.11.4
High performance, minimalist Go web framework
https://echo.labstack.com
____________________________________O/_______
                                    O\
{"time":"2024-02-23T10:50:38.557171+08:00","level":"FATAL","prefix":"echo","file":"api.go","line":"38","message":"listen tcp :1323: bind: address already in use"}
Process Exit with Code: 1

My code on graceful shutdown

	// Wait for interrupt signal to gracefully shutdown the server with a timeout of 10 seconds.
	// Use a buffered channel to avoid missing signals as recommended for signal.Notify
	quit := make(chan os.Signal, 1)
	signal.Notify(quit, os.Interrupt)
	<-quit
	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
	defer cancel()

	// Shutdown server
	if err := e.Shutdown(ctx); err != nil {
		e.Logger.Fatal(err)
	}

	// Disconnect from MongoDB
	if err := db.Client.Disconnect(context.Background()); err != nil {
		log.Fatal("⇨ Error disconnecting to MongoDB: ", err)
		log.Fatal(err)
	}

Answer 1 · 2024-02-23T02:54:55.000Z

I am fairly new to the language with 3 months experience and I diagnosed that the context.WithTimeout is causing it. I tried it with context.TODO() and it works fine now

Answer 2 · 2024-02-24T11:01:06.000Z

Had similar issue, just use pkill and update your .air.toml like this.

root = "."
testdata_dir = "testdata"
tmp_dir = "tmp"

[build]
  bin = "./tmp/my-api-go"
  cmd = "pkill my-api-go; go build -o ./tmp/my-api-go ."
  delay = 1000
  exclude_dir = ["assets", "tmp", "vendor", "testdata", "node_modules"]
  exclude_file = []
  exclude_regex = ["_test.go"]
  exclude_unchanged = false
  follow_symlink = false
  full_bin = ""
  include_dir = []
  include_ext = ["go", "tpl", "tmpl", "html"]
  kill_delay = "0s"
  log = "build-errors.log"
  send_interrupt = false
  stop_on_error = true

[color]
  app = ""
  build = "yellow"
  main = "magenta"
  runner = "green"
  watcher = "cyan"

[log]
  time = false

[misc]
  clean_on_exit = false

[screen]
  clear_on_rebuild = false

Answer 3 · 2024-03-04T17:56:00.000Z

@hamza72x I have similar settings but I'm seeing different behavior (the ^C is being ignored on MacOS).

When I run my server locally I see it exit from an interrupt as expected:

I0304 12:51:10.617018   47315 server.go:142] updating pod info
I0304 12:51:10.617172   47315 server.go:108] starting server at port 7442
^C
I0304 12:51:14.062000   47315 server.go:67] quitting server
E0304 12:51:14.062116   47315 server.go:59] http: Server closed

Doing the same thing with air i see:

 / /\  | | | |_) 
/_/--\ |_| |_| \_ v1.51.0, built with Go go1.22.0

watching .
watching cmd
watching cmd/web
!exclude dist
watching internal
watching internal/api
!exclude node_modules
watching pkg
!exclude public
!exclude src
!exclude tmp
building...
running...
I0304 12:52:50.795311   48146 server.go:142] updating pod info
I0304 12:52:50.795335   48146 server.go:108] starting server at port 7442
^C
cleaning...
see you again~

but when I check lsof i still see the process running and bound to a port (and it still logs to my local terminal):

COMMAND   PID     USER   FD   TYPE             DEVICE SIZE/OFF NODE NAME
web     48146 me    3u  IPv6 0xba380d8c0d1589c5      0t0  TCP *:7442 (LISTEN)

here is my config

testdata_dir = "testdata"
tmp_dir = "tmp"

[build]
  args_bin = []
  bin = "./web"
  cmd = "go build -o ./web ./cmd/web/main.go"
  delay = 1000
  exclude_dir = ["dist", "assets", "tmp", "vendor", "testdata", "node_modules", "src", "public"]
  exclude_file = []
  exclude_regex = ["_test.go"]
  exclude_unchanged = false
  follow_symlink = false
  full_bin = ""
  include_dir = []
  include_ext = ["go", "tpl", "tmpl", "html"]
  include_file = []
  kill_delay = "0s"
  log = "build-errors.log"
  poll = false
  poll_interval = 0
  post_cmd = []
  pre_cmd = []
  rerun = false
  rerun_delay = 500
  send_interrupt = true
  stop_on_error = true

[color]
  app = ""
  build = "yellow"
  main = "magenta"
  runner = "green"
  watcher = "cyan"

[log]
  main_only = false
  time = false

[misc]
  clean_on_exit = false

[screen]
  clear_on_rebuild = false
  keep_scroll = true

Answer 4 · 2024-03-06T15:20:46.000Z

The key here is to set send_interrupt to true in your air.toml. only then will Ctrl+c behave as expected.

Answer 5 · 2024-03-06T17:28:38.000Z

I'm able to reproduce this error even when send_interrupt is set to true. There seems to be a race condition when shutting down air using Ctrl+c.

When air is running the bin and a ctrl+c comes in cleanup() is executed. At this line in cleanup we call to have the bin stopped. When this call happens we aren't waiting for it to finish. https://github.com/cosmtrek/air/blob/master/runner/engine.go#L582-L586

The air program typically exits before it has the chance to stop the bin and get to https://github.com/cosmtrek/air/blob/master/runner/engine.go#L521-L522

Answer 6 · 2024-03-13T08:36:51.000Z

I can confirm that the server is not killed even when send_interrupt is set to true

Answer 7 · 2024-03-18T15:13:02.000Z

This is also happening to me using ZSH. I have send_interrupt set to true and have tried a variety of configs but am still left with the process running after see you again~.

As a bit of a work around until this is resolved, I have set the following config to automatically kill the process using a specific port:

post_cmd = ["lsof -i tcp:8080 | awk 'NR==2{print $2}' | xargs kill"]

Answer 8 · 2024-03-27T21:48:34.000Z

I have a 5 second delay for connections to close on graceful shutdown. If you're listening for an interrupt then be sure to set a kill_delay as well otherwise air will close faster than your cleanup process.

# Send Interrupt signal before killing process (windows does not support this feature)
send_interrupt = true
# Delay after sending Interrupt signal
kill_delay = 5000000000 # nanosecond

Answer 9 · 2024-03-28T17:59:39.000Z

@altanbgn

signal.Notify(quit, os.Interrupt)

Be sure to capture syscall.SIGTERM also. systemd/docker uses that signal for stop and restart. Save yourself some headaches on deployment.

signal.Notify(quit, os.Interrupt, syscall.SIGTERM)

Answer 10 · 2024-03-29T16:09:25.000Z

@taylow Improved on your solution a little bit.

I ensure I reap the process with a given listening port before every reload and when you quit air.

post_cmd = [
  "lsof -i :8080 -sTCP:LISTEN | sed 1d | awk '{print $2}' | xargs kill -9"
]
pre_cmd = [
  "lsof -i :8080 -sTCP:LISTEN | sed 1d | awk '{print $2}' | xargs kill -9"
]

This part of the lsof command is particularly important as it prevents your browser or other tools with open or establishing connections to your server also getting reaped.

lsof -sTCP:LISTEN

Hope it helps and I hope this will be fixed soon so we don't have to use a workaround. ❤️

Answer 11 · 2024-04-23T00:45:42.000Z

I was having the same issue as you. I have a docker container running a go service where I listen for SIGINT and SIGTERM after starting the server so I can gracefully shutdown. I was able to resolve with the following:

[build]
...
send_interrupt = true
kill_delay = 1

If you don't set something for kill delay it seems like Air eats the signal.

Answer 12 · 2024-04-23T01:43:25.000Z

Just writing in to say that even with send_interrupt=true and kill_delay=1, I still see intermitten failure to send the ctrl-c interrupt to my program. I'm using the pre_cmd and post_cmd hacks shared above (thank you!) but it's annoying.

Answer 13 · 2024-04-24T20:17:01.000Z

@peterldowns @iancharters

Referring to the example toml https://github.com/cosmtrek/air/blob/master/air_example.toml
kill_delay operates in nanoseconds! With a value of 1 you're giving your program maybe CPU 4 clock cycles to close up your connections and program.

At least set your delay to 100 milliseconds | kill_delay = 100000000

Just timing my DB and app close takes nearly 500 microseconds so 100 milliseconds is pretty safe for Testing/Development.

EDIT: Here is my gracefull shutdown portion for reference.

...
// Server Run
go func() {
	if err := server.ListenAndServe(); err != nil {
		log.Println(err)
	}
}()
log.Println("Server Running: http://127.0.0.1" + port)

// Graceful shutdown
c := make(chan os.Signal, 1)
signal.Notify(c, os.Interrupt, syscall.SIGTERM)
<-c
start := time.Now()
log.Println("Gracefully shutting down...")
server.Shutdown(ctx)
data.Close()
log.Printf("Gracefully closed %s.", time.Since(start))

Output:
main.go has changed
building...
2024/04/24 13:39:17 Gracefully shutting down...
2024/04/24 13:39:17 http: Server closed
2024/04/24 13:39:17 Database closed
2024/04/24 13:39:17 Gracefully closed 364.905µs
running...
2024/04/24 13:39:18 Server Running: http://127.0.0.1:3000

Answer 14 · 2024-04-26T20:57:58.000Z

@figuerom16 I've tried delay values of 5000000000 as well as "5000ms" but it simply does not delay.

Answer 15 · 2024-04-26T22:49:27.000Z

@peterldowns Are you on the latest air also? My air -v is v1.51.0, built with Go go1.22.2.
Is there sample code I can try? Are you doing anything special to build?
I want to see if I can replicate the issue or if there is a service that isn't closing correctly.

Answer 16 · 2024-04-26T23:24:27.000Z

@figuerom16 I'll set up a minimal reproduction case and share it here within the next day or so. Sorry for not doing so earlier, I realize it's hard to debug without an easy way to reproduce the problem. I'm using air installed via nix, but it's 1.51.0 built with go1.22.1. I'm on macOS Monterey version 12.5.1 on a M1 pro:

❯ air -v

  __    _   ___
 / /\  | | | |_)
/_/--\ |_| |_| \_ (devel), built with Go go1.22.1


❯ which air
/nix/store/1w5403arzypxxb1s2mlaylxmnmlvwjq6-air-1.51.0/bin/air

Answer 17 · 2024-04-30T01:23:25.000Z

Could folks having this problem give this a try?

#575

Answer 18 · 2024-04-30T08:06:40.000Z

@sethbrasile I have the same problem and #575 solved the issue for me 👍

Answer 19 · 2024-05-04T17:09:32.000Z

This repo is a reproducible example, if anyone needs: https://github.com/sa-/goth-counter

Answer 20 · 2024-05-04T22:24:07.000Z

@sethbrasile I can confirm that this fixed the issue for me as well. I tested by cloning your fork, building the air binary, then updating my .air.toml to comment out the pkill shenanigans, and set kill_delay = "5000ms". Now, when I hit ctrl-c, air propagates the signal to my server, and the server has time to exist cleanly. Hooray!

One suggestion — can you make it so that if the backend server has terminated, air will stop waiting? For instance:

If the server takes ~1,000ms to exit, and kill_delay = 5,000ms, then air should exit after ~1,000ms, because the server has exited and there is no reason for air to continue waiting.
If the server takes ~20,000ms to exit, and kill_delay = 5,000ms, then air should exit after 5,000ms because that is the maximum amount of time it should wait.

Answer 21 · 2024-05-04T22:25:05.000Z

Also, thank you for the fix!

Answer 22 · 2024-05-14T09:24:07.000Z

I had some issues with this as well. I tried your branch @sethbrasile, it helps but doesn't fix it entirely for me, there were times I had to manually kill the process. This code here could be more resilient: https://github.com/cosmtrek/air/blob/master/runner/util_linux.go#L12. It's ignoring some errors, and in my opinion the delay between SIGINT and SIGKILL should be the default, now the user has to know about the kill_delay config. And as @peterldowns mentioned, this ideally shouldn't be a time.Sleep with a fixed interval being idle but rather a timeout. To implement this we could signal SIGINT and spin up a go routine checking if the PID still exists, once it doesn't we signal on the procKilledCh

Answer 23 · 2024-05-22T14:00:26.000Z

I had the same issue and was able to permanently fix it by adding:

post_cmd = ["pkill <BINARY_NAME>"]

Answer 24 · 2024-05-23T15:21:21.000Z

pkill uses SIGTERM and also Docker kills containers with SIGTERM. Maybe we can switch from SIGINT to SIGTERM, which is a signal most likely applications are handling already, and a default timeout before SIGKILL

Answer 25 · 2024-05-24T13:22:58.000Z

Wild guess, but it seems that upgrading MacOS from 14.4.1 to 14.5 seems to have resolved this for me. Can anyone else confirm?

Previously I reproduced this problem of failing to kill process with SIGINT/SIGTERM with both air and modd, so I don't think air is to blame specifically.

Answer 26 · 2024-05-27T20:07:58.000Z

I temporarily workaround this by using an older version of air (v1.46.0) and the graceful shutdown on mac works for me

Answer 27 · 2024-05-28T16:06:18.000Z

Actually no, I'm again affected on latest MacOS. Will try to downgrade again, but from cursory tests before, downgrade did not help.

Answer 28 · 2024-06-09T15:38:14.000Z

Very sad. I gave up and move to CompileDaemon ... this tool fails at the most basic use case for shutting down and starting again without conflicting port.

Answer 29 · 2024-06-21T15:01:40.000Z

I have a feeling this is related to Apple Silicon, on my Intel Macbook I don't experience this issue but colleagues on the same version of air with the same air.toml who have M1/M2/etc will experience an orphaned process on exit.

Answer 30 · 2024-06-23T15:07:41.000Z

#619 try this PR, should be fix
try: go install github.com/air-verse/air@360714a021b1b77e50a5656fefc4f8bb9312d328

Answer 31 · 2024-06-24T06:06:30.000Z

can someone help me test my PR please?

Answer 32 · 2024-06-24T11:21:06.000Z

I have a feeling this is related to Apple Silicon, on my Intel Macbook I don't experience this issue but colleagues on the same version of air with the same air.toml who have M1/M2/etc will experience an orphaned process on exit.

Same experience here. I get the bug all the time on my M3 Mac, but have not heard about it on Intel Macs so far.

Answer 33 · 2024-06-24T12:09:04.000Z

I have a feeling this is related to Apple Silicon, on my Intel Macbook I don't experience this issue but colleagues on the same version of air with the same air.toml who have M1/M2/etc will experience an orphaned process on exit.

Same experience here. I get the bug all the time on my M3 Mac, but have not heard about it on Intel Macs so far.

try my PR, go install github.com/air-verse/air@360714a021b1b77e50a5656fefc4f8bb9312d328
in this PR, will ensure your binary has been killed before exit air

Answer 34 · 2024-06-24T12:59:47.000Z

Hey @xiantang, I'll try it out now

Answer 35 · 2024-06-24T13:02:07.000Z

@xiantang Yeah, that build seems to consistently work on my M2 now

Answer 36 · 2024-06-24T14:56:01.000Z

try latest version

Answer 37 · 2024-06-24T15:10:25.000Z

Looks good so far, I started and stopped my app 10 times and it cleanly terminated it every time. Holding my breath to say it is really fixed, time will tell 😉.

Answer 38 · 2024-06-24T15:24:42.000Z

Thanks @xiantang, the fixing PR looks correct to me and testing with go install github.com/air-verse/air@360714a021b1b77e50a5656fefc4f8bb9312d328 shows that everything works for me. Nice work!

Answer 39 · 2024-07-04T08:34:15.000Z

Still seems to be an issue for me unfortunately with the new version:

  __    _   ___  
 / /\  | | | |_) 
/_/--\ |_| |_| \_ v1.52.3, built with Go go1.22.5

root = "."
testdata_dir = "testdata"
tmp_dir = "tmp"

## See: https://github.com/cosmtrek/air/issues/534
## See: https://github.com/cosmtrek/air/pull/570

[build]
  args_bin = []
  bin = "./tmp/main"
  cmd = "go build -o ./tmp/main ."
  delay = 0
  exclude_dir = ["assets", "tmp", "vendor", "testdata", "node_modules", "src"]
  exclude_file = []
  exclude_regex = ["_test.go", "_templ.go"]
  exclude_unchanged = false
  follow_symlink = false
  full_bin = ""
  include_dir = []
  include_ext = ["go", "tpl", "tmpl", "templ", "html"]
  include_file = []
  kill_delay = "500ms"
  log = "build-errors.log"
  poll = false
  poll_interval = 0
  post_cmd = [
  ]
  pre_cmd = [

  ]
  rerun = false
  rerun_delay = 500
  send_interrupt = true
  stop_on_error = true

[color]
  app = ""
  build = "yellow"
  main = "magenta"
  runner = "green"
  watcher = "cyan"

[log]
  main_only = false
  time = false

[misc]
  clean_on_exit = false

[proxy]
  app_port = 0
  enabled = false
  proxy_port = 0

[screen]
  clear_on_rebuild = false
  keep_scroll = true