when a process can't start in the beginning,supervisorctl update will hang

[young001]

In a case,when a process can't start in the beginning,eg the binary defined in the conf doesn't exist or conf error,the program can't start to running state,still stay in backoff state.

ex_sample_1.1.1.0.223817.486782  BACKOFF    can't find command '/home/admin/ex_sample_1.1.1.0.223817.486782/ex_sample'

then if we remove the supervisor conf,run sudo supervisorctl update,the commnad will hang forever。

I have read the supervisor code,but still have a little confused,maybe I sitll doesnt' catch the point.
when I input sudo supervisorctl update after I remove the BACKOFF program supervisor conf,supervisorctl will call stopPorcessGroup,send this rpc all to supervisord http server,
results = supervisor.stopProcessGroup(gname)
and it hang,why stopProcessGroup has no timeout?
when the rpc all to supervisord service,supervisord service will call killall function,I thought it shoud be call once,if killall function failed,it will return to supervisorctl,why hang here?

killall = make_allfunc(processes, isRunning, self.stopProcess,
                               wait=wait)
killall.delay = 0.05
killall.rpcinterface = self
return killall # deferred

In the supervisord log,I found the killall function is called repeated,and no return to supervisorctl that the reason supervisorctl update hang,but I didn't find the code which call the killall function repeatedly,pls show me how and why killall function called repeatedly,and how to solve it,thx

[mnaberez]

In a case,when a process can't start in the beginning,eg the binary defined in the conf doesn't exist or conf error,the program can't start to running state,still stay in backoff state.

ex_sample_1.1.1.0.223817.486782  BACKOFF    can't find command '/home/admin/ex_sample_1.1.1.0.223817.486782/ex_sample'

then if we remove the supervisor conf,run sudo supervisorctl update,the commnad will hang forever。

I was not able to duplicate this on Supervisor 3.2.3. Here is what I tried.

Minimal supervisord.conf:

[supervisord]
logfile = /tmp/supervisord.log

[inet_http_server]
port = 127.0.0.1:9001

[supervisorctl]
serverurl = http://127.0.0.1:9001

[rpcinterface:supervisor]
supervisor.rpcinterface_factory = supervisor.rpcinterface:make_main_rpcinterface

[program:badcommand]
command = /notfound
startretries = 1000000   ;keeps process in BACKOFF state, otherwise transitions to FATAL
autorestart = false

Start supervisord in the foreground with that config:

$ supervisord --version
3.2.3
$ supervisord -n -c /path/to/supervisord.conf
2016-04-23 21:04:43,222 INFO Increased RLIMIT_NOFILE limit to 1024
2016-04-23 21:04:43,255 INFO RPC interface 'supervisor' initialized
2016-04-23 21:04:43,255 CRIT Server 'inet_http_server' running without any HTTP authentication checking
2016-04-23 21:04:43,255 INFO supervisord started with pid 17690
2016-04-23 21:04:44,258 INFO spawnerr: can't find command '/notfound'
2016-04-23 21:04:45,261 INFO spawnerr: can't find command '/notfound'
2016-04-23 21:04:47,267 INFO spawnerr: can't find command '/notfound'
2016-04-23 21:04:50,276 INFO spawnerr: can't find command '/notfound'
2016-04-23 21:04:54,288 INFO spawnerr: can't find command '/notfound'
2016-04-23 21:04:59,299 INFO spawnerr: can't find command '/notfound'
...

Edit supervisord.conf to change command=/notfound to command=/bin/cat.

Run supervisorctl:

$ supervisorctl -c /path/to/supervisord.conf 
badcommand                       BACKOFF   can't find command '/notfound'
supervisor> update
badcommand: stopped
badcommand: updated process group
supervisor> status
badcommand                       RUNNING   pid 17711, uptime 0:00:25
supervisor>

I was not able to see the update command hang as you described. Can you provide instructions similar to the above that will reproduce it?

[young001]

hi,mnaberez,thx for your replay, in my case,I use include in supervisord.conf

;[include]
;files = relative/directory/*.ini
[include]
files = /etc/supervisor/conf.d/*.conf

if you put the following in badcommnad.conf to a include path

[program:badcommand]
command = /notfound
startretries = 1000000   ;keeps process in BACKOFF state, otherwise transitions to FATAL
autorestart = false

when start supervisord,it will be backoff state,then you remove the badcommnad.conf file,not update but remove the conf,then run supervisorctl update,it will hang.

I use supervisord 3.0,but after I look the source code,3.0 and 3.2.3 are same in such situation.

[mnaberez]

I use supervisord 3.0

On Supervisor 3.0, update hangs as you describe when the process is in the BACKOFF state. On Supervisor 3.1.0 (changelog) or later versions, it does not hang. It was fixed in 780f121.

[young001]

@mnaberez thx,can u tell how to hang happens?I didn't know how the hang happens,when no pid exists,it just return the error message,why the hang happened,how it works,just show me where such the code in.

[mnaberez]

This was patched about two years ago so I haven't looked at it in a while, but I think the hang when the process is in BACKOFF on versions prior to 3.1.0 is probably in rpcinterface.py:

if process.get_state() not in STOPPED_STATES:
    return NOT_DONE_YET

This is because BACKOFF is not part of STOPPED_STATES in states.py:

STOPPED_STATES = (ProcessStates.STOPPED,
                  ProcessStates.EXITED,
                  ProcessStates.FATAL,
                  ProcessStates.UNKNOWN)

The change in 780f121 moves a process in BACKOFF into the STOPPED state when stop() is called, which satisfies the if statement above.

Anyway, the instructions above shows the supervisorctl update hang on 3.0 as you reported, and shows the hang has been fixed on 3.1.0 and later. The solution is to upgrade to a newer version.

[young001]

@mnaberez why NOT_DONE_YET will hang,from the log it seems always repeat the action.I mean how that code works?I don't find how the action been repeated,when return NOT_DONE_YET,how supervisord tackle NOT_DONE_YET?I didn't find the mechanism in the code,so pls show me the source code so I can read it myself,thx

[mnaberez]

supervisord is an asynchronous program. When the XML-RPC method stopProcess is called, it may return a callback:

def onwait():
    # process will eventually enter a stopped state by
    # virtue of the supervisord.reap() method being called
    # during normal operations
    process.stop_report()
    if process.get_state() not in STOPPED_STATES:
        return NOT_DONE_YET
    return True

onwait.delay = 0
onwait.rpcinterface = self
return onwait # deferred

If the return value is a callback (in this case, onwait), the response is said to be deferred. No response will be sent to the client yet, and control will return to the event loop. The callback will be periodically called from the event loop. When the function's return value is other than NOT_DONE_YET, the request is completed and the response is sent to the client.

It starts in rpcinterface.py:

if isinstance(value, types.FunctionType):
    # returning a function from an RPC method implies that
    # this needs to be a deferred response (it needs to block).
    pushproducer = request.channel.push_with_producer
    pushproducer(DeferredXMLRPCResponse(request, value))

DeferredXMLRPCResponse is an asynchat producer. Its more() method will be called periodically:

try:
    value = self.callback()
    if value is NOT_DONE_YET:
        return NOT_DONE_YET
except RPCError, err:
    value = xmlrpclib.Fault(err.code, err.text)

body = xmlrpc_marshal(value)

self.finished = True

If you want to learn more, spending some time reading the asynchat and Medusa documentation should help with understanding how this code works.

[young001]

really thx,great help!