Whoa! That's really a nice and elegant solution of deadlock preventions. Hmm something went wrong. 1.1-dev-1906
First it is seems that lock not working at all. It always get lock() no matter if it is locked in another process. 2012-02-02 11:55:47,759 DEBUG 11788 pid: 11788 request started 2012-02-02 11:55:48,031 DEBUG 11787 pid: 11787 request started 2012-02-02 11:55:52,761 DEBUG 11788 pid: 11788 going to lock 2012-02-02 11:55:52,761 DEBUG 11788 pid: 11788 locked aquire time: 0.000323. 2012-02-02 11:55:52,761 DEBUG 11788 pid: 11788 going to sleep: 8.00 2012-02-02 11:55:53,037 DEBUG 11787 pid: 11787 going to lock 2012-02-02 11:55:53,038 DEBUG 11787 pid: 11787 locked aquire time: 0.000322. 2012-02-02 11:55:53,038 DEBUG 11787 pid: 11787 going to sleep: 8.00 *** HARAKIRI ON WORKER 2 (pid: 11788) *** HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffddc948f0 0x1ffff 0x7fffddc93930 0x7f01062ae123 HARAKIRI: -- wchan> poll_schedule_timeout HARAKIRI: --- uWSGI worker 2 (pid: 11788) WAS managing request /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 11:55:47 2012 --- 2012-02-02 11:55:58,837 DEBUG 11788 pid: 11788 going again to sleep: 8.00 *** HARAKIRI ON WORKER 1 (pid: 11787) *** HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffddc948f0 0x1ffff 0x7fffddc93930 0x7f01062ae123 HARAKIRI: -- wchan> poll_schedule_timeout HARAKIRI: --- uWSGI worker 1 (pid: 11787) WAS managing request /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 11:55:48 2012 --- 2012-02-02 11:56:00,838 DEBUG 11787 pid: 11787 going again to sleep: 8.00 DAMN ! worker 2 (pid: 11788) died :( trying respawn ... Respawned uWSGI worker 2 (new pid: 11790) DAMN ! worker 1 (pid: 11787) died :( trying respawn ... Respawned uWSGI worker 1 (new pid: 11791) Assert error sudo uwsgi -s /var/run/uwsgi_hypernova.sock -M -p 2 --harakiri 10 --harakiri-verbose -w uwsgi_test4_lock_in_def -C 777 --locks=2 pid: 11320 request started pid: 11329 request started pid: 11320 going to lock pid: 11320 locked aquire time: 0.000075. pid: 11320 going to sleep: 8.00 pid: 11329 going to lock pid: 11329 locked aquire time: 0.000075. pid: 11329 going to sleep: 8.00 *** HARAKIRI ON WORKER 1 (pid: 11320) *** HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fff689efc00 0x1ffff 0x7fff689ef890 0x7fb586654123 HARAKIRI: -- wchan> poll_schedule_timeout HARAKIRI: --- uWSGI worker 1 (pid: 11320) WAS managing request /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 11:44:32 2012 --- pid: 11320 going again to sleep: 8.00 *** HARAKIRI ON WORKER 2 (pid: 11329) *** HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fff689efc00 0x1ffff 0x7fff689ef970 0x7fb586654123 HARAKIRI: -- wchan> poll_schedule_timeout HARAKIRI: --- uWSGI worker 2 (pid: 11329) WAS managing request /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 11:44:32 2012 --- pid: 11329 going again to sleep: 8.00 uwsgi: tpp.c:63: __pthread_tpp_change_priority: Assertion `new_prio == -1 || (new_prio >= __sched_fifo_min_prio && new_prio <= __sched_fifo_max_prio)' failed. Another backtrace (after ctrl+c): run as: sudo uwsgi -s /var/run/uwsgi_hypernova.sock -M -p 2 --harakiri 10 --harakiri-verbose -w uwsgi_test4_lock_in_def -C 777 --locks=2 2012-02-02 11:52:25,530 DEBUG 11628 pid: 11628 request started 2012-02-02 11:52:26,031 DEBUG 11629 pid: 11629 request started 2012-02-02 11:52:30,532 DEBUG 11628 pid: 11628 going to lock 2012-02-02 11:52:30,533 DEBUG 11628 pid: 11628 locked aquire time: 0.000369. 2012-02-02 11:52:30,533 DEBUG 11628 pid: 11628 going to sleep: 8.00 2012-02-02 11:52:31,032 DEBUG 11629 pid: 11629 going to lock 2012-02-02 11:52:31,033 DEBUG 11629 pid: 11629 locked aquire time: 0.000327. 2012-02-02 11:52:31,033 DEBUG 11629 pid: 11629 going to sleep: 8.00 ^C!!! uWSGI process 11629 got Segmentation Fault !!! SIGINT/SIGQUIT received...killing workers... !!! uWSGI process 11628 got Segmentation Fault !!! *** backtrace *** uwsgi(uwsgi_backtrace+0x30) [0x42e960] /lib/x86_64-linux-gnu/libc.so.6(+0x33d80) [0x7fc807ca8d80] /usr/lib/libpython2.7.so.1.0(+0x122280) [0x7fc80812b280] /usr/lib/libpython2.7.so.1.0(PyEval_GetGlobals+0x9) [0x7fc808103429] /usr/lib/libpython2.7.so.1.0(PyImport_Import+0x33) [0x7fc808123d93] /usr/lib/libpython2.7.so.1.0(PyImport_ImportModule+0x1c) [0x7fc808123fdc] uwsgi(get_uwsgi_pydict+0x9) [0x43de49] uwsgi(uwsgi_python_atexit+0x46) [0x43c2c6] uwsgi(uwsgi_plugins_atexit+0x75) [0x42e415] /lib/x86_64-linux-gnu/libc.so.6(exit+0xe1) [0x7fc807cae961] uwsgi() [0x42dc4e] /lib/x86_64-linux-gnu/libpthread.so.0(+0xfc60) [0x7fc8095bbc60] /lib/x86_64-linux-gnu/libc.so.6(__select+0x13) [0x7fc807d53123] /usr/lib/libpython2.7.so.1.0(+0x153478) [0x7fc80815c478] /usr/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5a40) [0x7fc808109630] /usr/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x639c) [0x7fc808109f8c] /usr/lib/libpython2.7.so.1.0(+0x75759) [0x7fc80807e759] /usr/lib/libpython2.7.so.1.0(PyIter_Next+0xb) [0x7fc80805f15b] uwsgi(uwsgi_response_subhandler_wsgi+0x5b) [0x44118b] uwsgi(uwsgi_request_wsgi+0x19d) [0x43fe1d] uwsgi(wsgi_req_recv+0x7c) [0x410b7c] uwsgi(simple_loop+0x123) [0x42b2a3] uwsgi(uwsgi_ignition+0x1a5) [0x430005] uwsgi(uwsgi_start+0x1f07) [0x432647] uwsgi(main+0xefa) [0x433faa] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xff) [0x7fc807c93eff] uwsgi() [0x410629] *** end of backtrace *** *** backtrace *** uwsgi(uwsgi_backtrace+0x30) [0x42e960] /lib/x86_64-linux-gnu/libc.so.6(+0x33d80) [0x7fc807ca8d80] /usr/lib/libpython2.7.so.1.0(+0x122280) [0x7fc80812b280] /usr/lib/libpython2.7.so.1.0(PyEval_GetGlobals+0x9) [0x7fc808103429] /usr/lib/libpython2.7.so.1.0(PyImport_Import+0x33) [0x7fc808123d93] /usr/lib/libpython2.7.so.1.0(PyImport_ImportModule+0x1c) [0x7fc808123fdc] uwsgi(get_uwsgi_pydict+0x9) [0x43de49] uwsgi(uwsgi_python_atexit+0x46) [0x43c2c6] uwsgi(uwsgi_plugins_atexit+0x75) [0x42e415] /lib/x86_64-linux-gnu/libc.so.6(exit+0xe1) [0x7fc807cae961] uwsgi() [0x42dc4e] /lib/x86_64-linux-gnu/libpthread.so.0(+0xfc60) [0x7fc8095bbc60] /lib/x86_64-linux-gnu/libc.so.6(__select+0x13) [0x7fc807d53123] /usr/lib/libpython2.7.so.1.0(+0x153478) [0x7fc80815c478] /usr/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x5a40) [0x7fc808109630] /usr/lib/libpython2.7.so.1.0(PyEval_EvalFrameEx+0x639c) [0x7fc808109f8c] /usr/lib/libpython2.7.so.1.0(+0x75759) [0x7fc80807e759] /usr/lib/libpython2.7.so.1.0(PyIter_Next+0xb) [0x7fc80805f15b] uwsgi(uwsgi_response_subhandler_wsgi+0x5b) [0x44118b] uwsgi(uwsgi_request_wsgi+0x19d) [0x43fe1d] uwsgi(wsgi_req_recv+0x7c) [0x410b7c] uwsgi(simple_loop+0x123) [0x42b2a3] uwsgi(uwsgi_ignition+0x1a5) [0x430005] uwsgi(uwsgi_start+0x1f07) [0x432647] uwsgi(main+0xefa) [0x433faa] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xff) [0x7fc807c93eff] uwsgi() [0x410629] *** end of backtrace *** goodbye to uWSGI. Another thing to note: i still think continuing request execution after usr2 is a bug. It is better to exit(1) in usr2 handler in worker. I think it is better to make harakiri 2 step: 1) usr2 is sent to worker and master marks pid as harakiri first step. A worker should do exit(1) when receives usr2. This will make sleep(1) and kill(kill) unnessessary in 99% cases. Also removing 1 sec delay in possible lock deadlock. 2) Master should periodically check for harakiki pids and if it is in harakiki state for > 1 sec kill(kill) it. Never-less continuing request handler after usr2 is a bug. 2012/2/1 Roberto De Ioris <[email protected]>: > >> This is great that a new locking implementation will be soon :) Many >> thanks. But looking at behavior it is seems more like a harakiri bug >> to me. Locks works as expected in usual. (if you kill a process owning >> lock others deadlock). Harakiri system seems to be based on fact that >> usr2 will iterrupt blocking call and after C level usr2 callback >> execution of request handler continues. (which is a bug) >> As for the master-governed locking system: anything like that will > > > SIGUSR2 is only sent to get the current handling request. It is mainly a > hack (as we have no other ways to know what a process is doing). After a > bit (just to give time to the signal handler to end) SIGKILL is sent. > > By the way, after a bit of investigation, i came to the conclusion that is > better to improve the current code to add a deadlock-detector. Having a > user-space logging subsystem would be too slow (up to 200 times in my > tests). > > The new implementation > > https://projects.unbit.it/uwsgi/browser/master.c#L1548 > > should get rid of locks retained by dead processes...and should cover all > use cases. It has an ultra-tiny race condition if the process dies during > pthread_mutex_lock (pretty hard to reach), so it should be pretty solid > too. > > > -- > Roberto De Ioris > http://unbit.it > _______________________________________________ > uWSGI mailing list > [email protected] > http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi -- -------------------------------------------- Турнаев Евгений Викторович +7 906 875 09 43 -------------------------------------------- _______________________________________________ uWSGI mailing list [email protected] http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi
