Ok Another bt. tried to run real application: (gdb) run uwsgi -s /var/run/uwsgi_hypernova.sock -p 3 --pythonpath . -w hypernova.app -C 777 -O 0 --pyargv="--modules-path=../data/modules --mode=debug --log-handler=console --log-handler=numbler:console" Starting program: /usr/local/bin/uwsgi uwsgi -s /var/run/uwsgi_hypernova.sock -p 3 --pythonpath . -w hypernova.app -C 777 -O 0 --pyargv="--modules-path=../data/modules --mode=debug --log-handler=console --log-handler=numbler:console" [Thread debugging using libthread_db enabled] SYSNAME: Linux NODENAME: nostromo RELEASE: 2.6.38-8-generic VERSION: #42-Ubuntu SMP Mon Apr 11 03:31:24 UTC 2011 MACHINE: x86_64 ENVIRON: ORBIT_SOCKETDIR=/tmp/orbit-evgeny ENVIRON: SSH_AGENT_PID=1378 ENVIRON: SHELL=/bin/bash ENVIRON: TERM=xterm ENVIRON: XDG_SESSION_COOKIE=6c4b36eccfe318cdb477f1b600000006-1328091648.33575-736835906 ENVIRON: KONSOLE_DBUS_SERVICE=:1.57 ENVIRON: WINDOWID=52428825 ENVIRON: GNOME_KEYRING_CONTROL=/tmp/keyring-2o363e ENVIRON: SHELL_SESSION_ID=d616816bc0674000a86ed926eb7713b3 ENVIRON: GTK_MODULES=canberra-gtk-module ENVIRON: USER=evgeny ENVIRON: LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arj=01;31:*.taz=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lz=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.rar=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.axa=00;36:*.oga=00;36:*.spx=00;36:*.xspf=00;36: ENVIRON: DESKTOP_AUTOSTART_ID=106f7be4e75b1cf9b1132809164938942500000013420003 ENVIRON: LIBGL_DRIVERS_PATH=/usr/lib/fglrx/dri:/usr/lib32/fglrx/dri ENVIRON: SSH_AUTH_SOCK=/tmp/keyring-2o363e/ssh ENVIRON: USERNAME=evgeny ENVIRON: SESSION_MANAGER=local/nostromo:@/tmp/.ICE-unix/1342,unix/nostromo:/tmp/.ICE-unix/1342 ENVIRON: DEFAULTS_PATH=/usr/share/gconf/gnome-2d.default.path ENVIRON: COLUMNS=180 ENVIRON: XDG_CONFIG_DIRS=/etc/xdg/xdg-gnome-2d:/etc/xdg ENVIRON: MC_TMPDIR=/tmp/mc-evgeny ENVIRON: DESKTOP_SESSION=gnome-2d ENVIRON: PATH=/home/evgeny/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/opt/google/chrome:/home/evgeny/bin:/opt/google/chrome:/home/evgeny/bin ENVIRON: _=/usr/bin/gdb ENVIRON: PWD=/home/evgeny/box/trunk/frontend_new/src ENVIRON: GDM_KEYBOARD_LAYOUT=us ENVIRON: LANG=en_US.UTF-8 ENVIRON: GNOME_KEYRING_PID=1323 ENVIRON: MANDATORY_PATH=/usr/share/gconf/gnome-2d.mandatory.path ENVIRON: GDM_LANG=en_US.utf8 ENVIRON: UBUNTU_MENUPROXY=libappmenu.so ENVIRON: LINES=59 ENVIRON: KONSOLE_DBUS_SESSION=/Sessions/1 ENVIRON: GDMSESSION=gnome-2d ENVIRON: HISTCONTROL=ignoredups:ignorespace ENVIRON: SHLVL=2 ENVIRON: HOME=/home/evgeny ENVIRON: COLORFGBG=15;0 ENVIRON: LANGUAGE=en_US:en ENVIRON: GNOME_DESKTOP_SESSION_ID=this-is-deprecated ENVIRON: MC_SID=1997 ENVIRON: LOGNAME=evgeny ENVIRON: XDG_DATA_DIRS=/usr/share/gnome-2d:/usr/share/gnome:/usr/local/share/:/usr/share/ ENVIRON: DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-hLobbjQDy1,guid=a89f0e01c62c1aa52bf48a2f0000018b ENVIRON: LESSOPEN=| /usr/bin/lesspipe %s ENVIRON: WINDOWPATH=7 ENVIRON: PROFILEHOME= ENVIRON: DISPLAY=:0 ENVIRON: LESSCLOSE=/usr/bin/lesspipe %s %s ENVIRON: XAUTHORITY=/var/run/gdm/auth-for-evgeny-F9f19I/database ENVIRON: UWSGI_RELOADS=0 max space for custom process name = 3033 [uwsgi-logger] registered "zeromq" [uwsgi-logger] registered "zmq" [uwsgi-logger] registered "syslog" [uwsgi-logger] registered "rsyslog" [uwsgi-logger] registered "socket" executable name: /usr/local/bin/uwsgi optind:14 argc:15
Program received signal SIGSEGV, Segmentation fault. 0x0000000000000000 in ?? () (gdb) bt #0 0x0000000000000000 in ?? () #1 0x000000000042f225 in uwsgi_manage_opt (key=0x45b4dc "pythonpath", value=0x6744e0 ".") at uwsgi.c:364 #2 0x000000000042f29a in uwsgi_configure () at uwsgi.c:383 #3 0x000000000043418a in main (argc=<value optimized out>, argv=<value optimized out>, envp=<value optimized out>) at uwsgi.c:1387 2012/2/2 Evgeny Turnaev <[email protected]>: > Update: Sorry deadlock prevention seems to working too. But not always: > Why request with pid:13443 did not managed to get lock? Master not yet > collected dead children? > > 2012-02-02 13:30:16,918 DEBUG 13441 pid: 13441 going to lock > 2012-02-02 13:30:22,238 DEBUG 13437 pid: 13437 going again to sleep: 5.70 > *** HARAKIRI ON WORKER 1 (pid: 13441) *** > HARAKIRI: -- syscall> 202 0x7f0481a080a0 0x0 0x2 0x0 0x7f0481a080a0 > 0x3481 0x7fffc5af0a30 0x7f04815db7c4 > HARAKIRI: -- wchan> futex_wait_queue_me > HARAKIRI: --- uWSGI worker 1 (pid: 13441) WAS managing request > /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:30:11 > 2012 --- > *** HARAKIRI ON WORKER 2 (pid: 13437) *** > HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffc5af0a40 > 0x4014000000000000 0x7fffc5aef5e0 0x7f047fd74123 > HARAKIRI: -- wchan> poll_schedule_timeout > HARAKIRI: --- uWSGI worker 2 (pid: 13437) WAS managing request > /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:30:11 > 2012 --- > 2012-02-02 13:30:23,932 DEBUG 13437 pid: 13437 going to UNlock > 2012-02-02 13:30:23,932 DEBUG 13437 pid: 13437 going to lock > 2012-02-02 13:30:23,932 DEBUG 13437 pid: 13437 locked aquire time: 0.000129. > 2012-02-02 13:30:23,932 DEBUG 13437 pid: 13437 going to sleep: 9.53 > DAMN ! worker 2 (pid: 13437) died :( trying respawn ... > Respawned uWSGI worker 2 (new pid: 13442) > DAMN ! worker 1 (pid: 13441) died :( trying respawn ... > Respawned uWSGI worker 1 (new pid: 13443) > > > 2012-02-02 13:30:55,593 DEBUG 13443 pid: 13443 request started > 2012-02-02 13:31:00,600 DEBUG 13443 pid: 13443 going to lock > *** HARAKIRI ON WORKER 1 (pid: 13443) *** > HARAKIRI: -- syscall> 202 0x7f0481a080a0 0x0 0x2 0x0 0x7f0481a080a0 > 0x3483 0x7fffc5af0a30 0x7f04815db7c4 > HARAKIRI: -- wchan> futex_wait_queue_me > HARAKIRI: --- uWSGI worker 1 (pid: 13443) WAS managing request > /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:30:55 > 2012 --- > DAMN ! worker 1 (pid: 13443) died :( trying respawn ... > Respawned uWSGI worker 1 (new pid: 13445) > 2012-02-02 13:31:16,629 DEBUG 13445 pid: 13445 request started > 2012-02-02 13:31:21,632 DEBUG 13445 pid: 13445 going to lock > 2012-02-02 13:31:21,633 DEBUG 13445 pid: 13445 locked aquire time: 0.000343. > 2012-02-02 13:31:21,633 DEBUG 13445 pid: 13445 going to sleep: 2.03 > 2012-02-02 13:31:23,669 DEBUG 13445 pid: 13445 going again to sleep: 2.03 > 2012-02-02 13:31:25,706 DEBUG 13445 pid: 13445 going to UNlock > 2012-02-02 13:31:25,706 DEBUG 13445 pid: 13445 going to lock > 2012-02-02 13:31:25,706 DEBUG 13445 pid: 13445 locked aquire time: 0.000133. > 2012-02-02 13:31:25,706 DEBUG 13445 pid: 13445 going to sleep: 4.74 > *** HARAKIRI ON WORKER 1 (pid: 13445) *** > HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffc5af0a40 > 0x4010000000000000 0x7fffc5af0a38 0x7f047fd74123 > HARAKIRI: -- wchan> poll_schedule_timeout > HARAKIRI: --- uWSGI worker 1 (pid: 13445) WAS managing request > /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:31:16 > 2012 --- > 2012-02-02 13:31:27,994 DEBUG 13445 pid: 13445 going again to sleep: 4.74 > DAMN ! worker 1 (pid: 13445) died :( trying respawn ... > Respawned uWSGI worker 1 (new pid: 13446) > > > 2012-02-02 13:32:00,001 DEBUG 13442 pid: 13442 request started > 2012-02-02 13:32:05,006 DEBUG 13442 pid: 13442 going to lock > 2012-02-02 13:32:05,007 DEBUG 13442 pid: 13442 locked aquire time: 0.000336. > 2012-02-02 13:32:05,007 DEBUG 13442 pid: 13442 going to sleep: 6.55 > *** HARAKIRI ON WORKER 2 (pid: 13442) *** > HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffc5af0a40 > 0x4018000000000000 0x7fffc5af0a08 0x7f047fd74123 > HARAKIRI: -- wchan> poll_schedule_timeout > HARAKIRI: --- uWSGI worker 2 (pid: 13442) WAS managing request > /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:32:00 > 2012 --- > 2012-02-02 13:32:10,034 DEBUG 13442 pid: 13442 going again to sleep: 6.55 > DAMN ! worker 2 (pid: 13442) died :( trying respawn ... > Respawned uWSGI worker 2 (new pid: 13448) > > 2012/2/2 Evgeny Turnaev <[email protected]>: >> Locking is working. Deadlock prevention not. >> 1.1-dev-1910 >> >> >> 2012-02-02 13:22:56,643 DEBUG 13388 pid: 13388 request started >> 2012-02-02 13:22:57,037 DEBUG 13387 pid: 13387 request started >> 2012-02-02 13:23:01,649 DEBUG 13388 pid: 13388 going to lock >> 2012-02-02 13:23:01,649 DEBUG 13388 pid: 13388 locked aquire time: 0.000332. >> 2012-02-02 13:23:01,649 DEBUG 13388 pid: 13388 going to sleep: 2.33 >> 2012-02-02 13:23:02,043 DEBUG 13387 pid: 13387 going to lock >> 2012-02-02 13:23:03,978 DEBUG 13388 pid: 13388 going again to sleep: 2.33 >> 2012-02-02 13:23:06,308 DEBUG 13388 pid: 13388 going to UNlock >> 2012-02-02 13:23:06,308 DEBUG 13388 pid: 13388 going to lock >> 2012-02-02 13:23:06,308 DEBUG 13387 pid: 13387 locked aquire time: 4.265560. >> 2012-02-02 13:23:06,309 DEBUG 13387 pid: 13387 going to sleep: 0.06 >> 2012-02-02 13:23:06,367 DEBUG 13387 pid: 13387 going again to sleep: 0.06 >> 2012-02-02 13:23:06,426 DEBUG 13387 pid: 13387 going to UNlock >> 2012-02-02 13:23:06,427 DEBUG 13387 pid: 13387 going to lock >> 2012-02-02 13:23:06,427 DEBUG 13388 pid: 13388 locked aquire time: 0.118412. >> 2012-02-02 13:23:06,427 DEBUG 13388 pid: 13388 going to sleep: 8.01 >> *** HARAKIRI ON WORKER 2 (pid: 13388) *** >> HARAKIRI: -- syscall> 23 0x0 0x0 0x0 0x0 0x7fffe2ef7ca0 >> 0x4020000000000000 0x7fffe2ef7c98 0x7fadfb7c3123 >> HARAKIRI: -- wchan> poll_schedule_timeout >> HARAKIRI: --- uWSGI worker 2 (pid: 13388) WAS managing request >> /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:22:56 >> 2012 --- >> 2012-02-02 13:23:07,397 DEBUG 13388 pid: 13388 going again to sleep: 8.01 >> *** HARAKIRI ON WORKER 1 (pid: 13387) *** >> HARAKIRI: -- syscall> 202 0x7fadfd4570a0 0x0 0x2 0x0 0x7fadfd4570a0 >> 0x344b 0x7fffe2ef7c98 0x7fadfd02a7c4 >> HARAKIRI: -- wchan> futex_wait_queue_me >> HARAKIRI: --- uWSGI worker 1 (pid: 13387) WAS managing request >> /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:22:57 >> 2012 --- >> DAMN ! worker 2 (pid: 13388) died :( trying respawn ... >> Respawned uWSGI worker 2 (new pid: 13390) >> DAMN ! worker 1 (pid: 13387) died :( trying respawn ... >> Respawned uWSGI worker 1 (new pid: 13391) >> >> >> >> 2012-02-02 13:24:28,786 DEBUG 13390 pid: 13390 request started >> 2012-02-02 13:24:29,105 DEBUG 13391 pid: 13391 request started >> 2012-02-02 13:24:33,791 DEBUG 13390 pid: 13390 going to lock >> 2012-02-02 13:24:34,111 DEBUG 13391 pid: 13391 going to lock >> *** HARAKIRI ON WORKER 2 (pid: 13390) *** >> HARAKIRI: -- syscall> 202 0x7fadfd4570a0 0x0 0x2 0x0 0x7fadfd4570a0 >> 0x344e 0x7fffe2ef7c90 0x7fadfd02a7c4 >> HARAKIRI: -- wchan> futex_wait_queue_me >> HARAKIRI: --- uWSGI worker 2 (pid: 13390) WAS managing request >> /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:24:28 >> 2012 --- >> *** HARAKIRI ON WORKER 1 (pid: 13391) *** >> HARAKIRI: -- syscall> 202 0x7fadfd4570a0 0x0 0x2 0x0 0x7fadfd4570a0 >> 0x344f 0x7fffe2ef7c90 0x7fadfd02a7c4 >> HARAKIRI: -- wchan> futex_wait_queue_me >> HARAKIRI: --- uWSGI worker 1 (pid: 13391) WAS managing request >> /serp?query=%D0%BF%D1%83%D1%82%D0%B8%D0%BD since Thu Feb 2 13:24:29 >> 2012 --- >> DAMN ! worker 2 (pid: 13390) died :( trying respawn ... >> Respawned uWSGI worker 2 (new pid: 13393) >> DAMN ! worker 1 (pid: 13391) died :( trying respawn ... >> Respawned uWSGI worker 1 (new pid: 13394) >> >> >> ------------ >> def do_lock_thing(): >> start_time = time.time() >> debug("pid: %s going to lock" % os.getpid()) >> uwsgi.lock() >> debug("pid: %s locked aquire time: %0.6f." % (os.getpid(), >> time.time() - start_time)) >> sleep_time = random.random() * 10 >> debug("pid: %s going to sleep: %0.2f" % (os.getpid(), sleep_time)) >> time.sleep(sleep_time) >> debug("pid: %s going again to sleep: %0.2f" % (os.getpid(), sleep_time)) >> time.sleep(sleep_time) >> debug("pid: %s going to UNlock" % os.getpid()) >> uwsgi.unlock() >> >> def application(environ, start_response): >> headers = [ >> ('Content-Type', 'text/html'), >> ] >> write = start_response('200 OK', headers) >> debug("pid: %s request started" % os.getpid()) >> time.sleep(5) >> for x in range(2): >> do_lock_thing() >> yield 'Hello World' >> debug("pid: %s end of application.." % os.getpid()) >> >> >> >> 2012/2/2 Roberto De Ioris <[email protected]>: >>> >>>> Whoa! That's really a nice and elegant solution of deadlock preventions. >>>> Hmm something went wrong. >>>> 1.1-dev-1906 >>>> >>>> >>> >>> >>> Should be fixed now (both) >>> >>> >>>> 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. >>>> >>> >>> This would require a bit of refactoring as USR2 is not only used by >>> harakiri, but in general i am not against it. >>> >>> >>> -- >>> 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 >> -------------------------------------------- > > > > -- > -------------------------------------------- > Турнаев Евгений Викторович > +7 906 875 09 43 > -------------------------------------------- -- -------------------------------------------- Турнаев Евгений Викторович +7 906 875 09 43 -------------------------------------------- _______________________________________________ uWSGI mailing list [email protected] http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi
