Re: [uWSGI] Possible deadlock.

Thu, 02 Feb 2012 02:16:48 -0800 

> Don't know if it is related to prev.
> Never used gdb so please don't blame me.

pyargv and pythonpath has been ported to the new api in rev 1915

Be sure to use it (or a higher commit)

>
> (gdb) run uwsgi -s /var/run/uwsgi_hypernova.sock -p 3  -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  -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: TERM=xterm
> ENVIRON: SHELL=/bin/bash
> ENVIRON: USER=root
> 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: SUDO_USER=evgeny
> ENVIRON: SUDO_UID=1000
> ENVIRON: USERNAME=root
> ENVIRON: COLUMNS=180
> ENVIRON:
> PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/X11R6/bin:/opt/google/chrome:/home/evgeny/bin
> ENVIRON: MAIL=/var/mail/root
> ENVIRON: _=/usr/bin/gdb
> ENVIRON: PWD=/home/evgeny/box/trunk/frontend_new/src
> ENVIRON: LANG=en_US.UTF-8
> ENVIRON: LINES=59
> ENVIRON: HOME=/home/evgeny
> ENVIRON: SUDO_COMMAND=/bin/bash
> ENVIRON: SHLVL=1
> ENVIRON: LANGUAGE=en_US:en
> ENVIRON: LOGNAME=root
> ENVIRON: LESSOPEN=| /usr/bin/lesspipe %s
> ENVIRON: DISPLAY=:0
> ENVIRON: SUDO_GID=1000
> 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 = 1845
> [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:12 argc:13
> *** Starting uWSGI 1.1-dev-1910 (64bit) on [Thu Feb  2 13:55:30 2012] ***
> ***
> *** You are running a DEBUG version of uWSGI, please disable debug in
> your build profile and recompile it ***
> ***
> compiled with version: 4.5.2 on 02 February 2012 13:48:52
> current working directory: /home/evgeny/box/trunk/frontend_new/src
> detected binary path: /usr/local/bin/uwsgi
> uWSGI running as root, you can use --uid/--gid/--chroot options
> *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
> *** WARNING: you are running uWSGI without its master process manager ***
> your memory page size is 4096 bytes
> detected max file descriptor number: 1024
> cores allocated...
> uwsgi socket 0 bound to UNIX address /var/run/uwsgi_hypernova.sock fd 5
> Python version: 2.7.1+ (r271:86832, Apr 11 2011, 18:37:12)  [GCC 4.5.2]
> Python main interpreter initialized at 0x67c990
> [uWSGI DEBUG] uwsgi socket 255 SO_RCVBUF size: 126976
> [uWSGI DEBUG] uwsgi socket 255 SO_SNDBUF size: 126976
> your server socket listen backlog is limited to 100 connections
> *** Operational MODE: preforking ***
>
> Program received signal SIGSEGV, Segmentation fault.
> __strlen_sse2 () at ../sysdeps/x86_64/multiarch/../strlen.S:32
> 32      ../sysdeps/x86_64/multiarch/../strlen.S: No such file or
> directory.
>         in ../sysdeps/x86_64/multiarch/../strlen.S
> (gdb) bt
> #0  __strlen_sse2 () at ../sysdeps/x86_64/multiarch/../strlen.S:32
> #1  0x00007ffff66c16fb in PyString_FromString () from
> /usr/lib/libpython2.7.so.1.0
> #2  0x00007ffff6746ff0 in PySys_SetArgvEx () from
> /usr/lib/libpython2.7.so.1.0
> #3  0x000000000043e93d in init_pyargv () at plugins/python/pyutils.c:122
> #4  0x000000000043e53b in uwsgi_python_preinit_apps () at
> plugins/python/python_plugin.c:853
> #5  0x00000000004323a2 in uwsgi_start (v_argv=<value optimized out>)
> at uwsgi.c:2404
> #6  0x000000000043470d in main (argc=<value optimized out>,
> argv=<value optimized out>, envp=<value optimized out>) at
> uwsgi.c:1573
> (gdb) frame 6
> #6  0x000000000043470d in main (argc=<value optimized out>,
> argv=<value optimized out>, envp=<value optimized out>) at
> uwsgi.c:1573
> 1573                    uwsgi_start((void *) uwsgi.argv);
> (gdb) frame 5
> #5  0x00000000004323a2 in uwsgi_start (v_argv=<value optimized out>)
> at uwsgi.c:2404
> 2404                            uwsgi.p[i]->preinit_apps();
> (gdb) frame 6
> #6  0x000000000043470d in main (argc=<value optimized out>,
> argv=<value optimized out>, envp=<value optimized out>) at
> uwsgi.c:1573
> 1573                    uwsgi_start((void *) uwsgi.argv);
> (gdb) buf
> Undefined command: "buf".  Try "help".
> (gdb) print buf
> $1 = 0x0
> (gdb) frame 5
> #5  0x00000000004323a2 in uwsgi_start (v_argv=<value optimized out>)
> at uwsgi.c:2404
> 2404                            uwsgi.p[i]->preinit_apps();
> (gdb) print buf
> $2 = 0x0
>
> 2012/2/2 Evgeny Turnaev <[email protected]>:
>> 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
>> --------------------------------------------
>
>
>
> --
> --------------------------------------------
> Турнаев Евгений Викторович
> +7 906 875 09 43
> --------------------------------------------
> _______________________________________________
> uWSGI mailing list
> [email protected]
> http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi
>


-- 
Roberto De Ioris
http://unbit.it
_______________________________________________
uWSGI mailing list
[email protected]
http://lists.unbit.it/cgi-bin/mailman/listinfo/uwsgi

Reply via email to