DarthSim / overmind

Process manager for Procfile-based applications and tmux
MIT License
2.82k stars 79 forks source link

Overmind Crashing on MacOS big Sur #104

Closed akshay-birajdar closed 3 years ago

akshay-birajdar commented 3 years ago

After upgrading to macOS big Sur overmind started getting crashed. I tried reinstalling using brew but it still crashes.

I was not able to see any crash log/error message to further debug it.

System configuration

overmind version: 2.2.0 tmux version: 3.1c

OS Config: ProductName: macOS ProductVersion: 11.2.1 BuildVersion: 20D74

ghost commented 3 years ago

I have the same problem! E.g.

Procfile

test: sleep 5; echo "Done"

Shell

system | Tmux socket name: overmind-test-app-RanDom_String
system | Tmux session ID: test-app
system | Listening at ./.overmind.sock
test   | Started with pid 9791...
test   | Exited

System error log

syspolicyd  Unable to get certificates array: (null)
syspolicyd  Error Domain=NSOSStatusErrorDomain Code=-67062
syspolicyd  Connection 34: default TLS Trust evaluation failed(-9807)
syspolicyd  Connection 34: TLS Trust encountered error 3:-9807
syspolicyd  Connection 34: encountered error(3:-9807)
syspolicyd  Task <ID>.<74> HTTP load failed, 0/0 bytes (error code: -1202 [3:-9807])
syspolicyd  Task <ID>.<74> finished with error [-1202] Error Domain=NSURLErrorDomain Code=-1202 ...
syspolicyd  cloudkit request failed: Error Domain=NSURLErrorDomain Code=-1202 ...

System configuration

overmind version: 2.2.0 tmux version: 3.1c

OS Config: ProductName: macOS ProductVersion: 11.2.1 BuildVersion: 20D74

DarthSim commented 3 years ago

So, in fact it doesn't crash but stops processes immediately, right?

ghost commented 3 years ago

So, in fact it doesn't crash but stops processes immediately, right?

Yes, I would say that that's more accurate

akshay-birajdar commented 3 years ago

Yes, The process starts exiting immediately. Sorry should have been more clear in description.

Thank you @valterkraemer-coupa for the reproduction steps and logs.

DarthSim commented 3 years ago

I can't reproduce the issue on my machine, so I need some additional info from you:

  1. What's your user's default shell? (bash/zsh/fish)
  2. If you run something long-running like ping google.com, does the process keeps running after Overmind exits?
  3. Does the issue reproduce when overmind is run with sudo?
akshay-birajdar commented 3 years ago

Following is the info needed.

  1. What's your user's default shell? (bash/zsh/fish)

Default Shell is zsh (with oh-my-zsh).

  1. If you run something long-running like ping google.com, does the process keeps running after Overmind exits?

The ping process exits when overmind exits.

  1. Does the issue reproduce when overmind is run with sudo?

Yes, the issue is still reproducible with sudo.

ghost commented 3 years ago
  1. zsh
  2. Nope
  3. Nope

Untitled

Maybe this is the issue? 🤔

Cannot be changed because of company's policy.

DarthSim commented 3 years ago

Ok, here's a debug build. Please run it with a test Procfile and give me the whole output.

overmind.zip

ghost commented 3 years ago

Screenshot 2021-02-16 at 18 00 38

@DarthSim Thanks for trying to figure out the issue! Sorry, but I won't be able to bypass this 😕

akshay-birajdar commented 3 years ago

Logs:

system | Tmux socket name: overmind-discourse-PpXPrOfurGvRCoUWutszfV
system | Tmux session ID: discourse
system | Listening at ./.overmind.sock
%begin 1613546110 246 0
%overmind-process %0 web 14444
%end 1613546110 246 0
%begin 1613546110 247 0
%end 1613546110 247 0
%begin 1613546110 248 0
%end 1613546110 248 0
%begin 1613546110 249 0
%overmind-process %1 ping 14445
%end 1613546110 249 0
%window-add @0
%sessions-changed
%session-changed $0 discourse
%session-window-changed $0 @1
%window-add @1
ping   | Started with pid 14445...
web    | Started with pid 14444...
web    | operation not permitted
web    | operation not permitted
%output %1 PING google.com (172.217.27.206): 56 data bytes\015\012
ping   | PING google.com (172.217.27.206): 56 data bytes
%output %1 64 bytes from 172.217.27.206: icmp_seq=0 ttl=116 time=10.903 ms\015\012
ping   | 64 bytes from 172.217.27.206: icmp_seq=0 ttl=116 time=10.903 ms
%output %1 64 bytes from 172.217.27.206: icmp_seq=1 ttl=116 time=8.669 ms\015\012
ping   | 64 bytes from 172.217.27.206: icmp_seq=1 ttl=116 time=8.669 ms
ping   | Exited
web    | Interrupting...
%output %0 \033[1mTraceback\033[m (most recent call last):\015\012\01128: from /Users/akshay/.rbenv/versions/2.7.1/bin/bundle:23:in `<main>'\015\012\01127: from /Users/akshay/.rbenv/versions/2.7.1/bin/bundle:23:in `load'\015\012\01126: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:34:in `<top (required)>'\015\012\01125: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/2.7.0/bundler/friendly_errors.rb:123:in `with_friendly_errors'\015\012\01124: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:46:in `block in <top (required)>'\015\012\01123: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/2.7.0/bundler/cli.rb:24:in `start'\015\012\01122: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/base.rb:476:in `start'\015\012\01121: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/2.7.0/bundler/cli.rb:30:in `dispatch'\015\012\01120: from /Users/akshay/.rbenv/versions/2.7.1/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'\015\012\01119: from /Users/akshay/.rbenv/versions/2.7.1/
web    | Traceback (most recent call last):
....... (cutting Ruby interupt logs)
web    | os: process already finished
web    | Exited
%output %1 64 bytes from 172.217.27.206: icmp_seq=2 ttl=116 time=50.299 ms\015\012
%begin 1613546114 259 1
%end 1613546114 259 1
%sessions-changed

operation not permitted looks suspicious. I think it is coming from tmux.

DarthSim commented 3 years ago

This looks very suspicious. Looks like ping exits without any reason. @akshay-birajdar could you run the new debug build with a single ping process?

overmind.zip

akshay-birajdar commented 3 years ago

@DarthSim Logs:

❱ ./overmind start
system | Tmux socket name: overmind-discourse-RW6DSg1QgHy2Aypl0oEKMD
system | Tmux session ID: discourse
system | Listening at ./.overmind.sock
%begin 1613575203 246 0
%overmind-process %0 ping 23779
%end 1613575203 246 0
%begin 1613575203 247 0
%end 1613575203 247 0
%begin 1613575203 248 0
%end 1613575203 248 0
%window-add @0
%sessions-changed
%session-changed $0 discourse
ping   | Started with pid 23779...
%output %0 PING google.com (142.250.183.110): 56 data bytes\015\012
ping   | PING google.com (142.250.183.110): 56 data bytes
%output %0 64 bytes from 142.250.183.110: icmp_seq=0 ttl=116 time=26.479 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=0 ttl=116 time=26.479 ms
%output %0 64 bytes from 142.250.183.110: icmp_seq=1 ttl=116 time=35.516 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=1 ttl=116 time=35.516 ms
%output %0 64 bytes from 142.250.183.110: icmp_seq=2 ttl=116 time=22.160 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=2 ttl=116 time=22.160 ms
%output %0 64 bytes from 142.250.183.110: icmp_seq=3 ttl=116 time=22.297 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=3 ttl=116 time=22.297 ms
%output %0 64 bytes from 142.250.183.110: icmp_seq=4 ttl=116 time=15.713 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=4 ttl=116 time=15.713 ms
%output %0 64 bytes from 142.250.183.110: icmp_seq=5 ttl=116 time=13.963 ms\015\012
ping   | 64 bytes from 142.250.183.110: icmp_seq=5 ttl=116 time=13.963 ms
ping   | Exited
%output %0 64 bytes from 142.250.183.110: icmp_seq=6 ttl=116 time=18.841 ms\015\012
%output %0 64 bytes from 142.250.183.110: icmp_seq=7 ttl=116 time=81.441 ms\015\012
%begin 1613575210 255 1
%end 1613575210 255 1
%sessions-changed
DarthSim commented 3 years ago

Damn, I can't understand what's happening... @akshay-birajdar what about this build? overmind.zip

akshay-birajdar commented 3 years ago

New Logs:

❱ ./overmind start
system | Tmux socket name: overmind-discourse-NYr2CSBd-NRwqy3639WH4C
system | Tmux session ID: discourse
system | Listening at ./.overmind.sock
ping   | [DEBUG] Not running: PID is 0
%begin 1613576989 246 0
%overmind-process %0 ping 24655
%end 1613576989 246 0
%begin 1613576989 247 0
%end 1613576989 247 0
%begin 1613576989 248 0
%end 1613576989 248 0
%window-add @0
%sessions-changed
%session-changed $0 discourse
ping   | Started with pid 24655...
ping   | [DEBUG] Not running: operation not permitted
ping   | Exited
%output %0 PING google.com (142.250.192.14): 56 data bytes\015\012
%output %0 64 bytes from 142.250.192.14: icmp_seq=0 ttl=116 time=13.487 ms\015\012
ping   | [DEBUG] Not running: PID is 0
%output %0 64 bytes from 142.250.192.14: icmp_seq=1 ttl=116 time=13.496 ms\015\012
%begin 1613576991 255 1
%end 1613576991 255 1
%sessions-changed
DarthSim commented 3 years ago

Okay, so it is operation not permitted stuff... Keeping digging.

DarthSim commented 3 years ago

By any chance, do you guys use some kind of antivirus?

DarthSim commented 3 years ago

Ok, it looks like operation not permitted can be just ignored when checking a process status. @akshay-birajdar please check this build. I removed all the debug stuff from it, so just check how it works: start a Procfile, try to restart some processes, stop Overmind, etc. If it works fine for you, I'll commit the changes and make a release.

overmind.zip

akshay-birajdar commented 3 years ago

@DarthSim The new build is working 🎉 ! Thank you so much!!

DarthSim commented 3 years ago

Nice! Released v2.2.1