7 messages in ru.sysoev.nginxRe: call ngx_localtime may cause dead...| From | Sent On | Attachments |
|---|---|---|
| georgexsh | Mar 4, 2010 2:08 am | |
| Maxim Dounin | Mar 4, 2010 4:14 am | |
| Igor Sysoev | Mar 4, 2010 4:21 am | |
| georgexsh | Mar 4, 2010 7:20 am | |
| Maxim Dounin | Mar 4, 2010 8:49 am | |
| Igor Sysoev | Mar 4, 2010 11:54 am | |
| Maxim Dounin | Mar 4, 2010 4:58 pm |
| Subject: | Re: call ngx_localtime may cause deadlock? | |
|---|---|---|
| From: | Igor Sysoev (ig...@sysoev.ru) | |
| Date: | Mar 4, 2010 4:21:33 am | |
| List: | ru.sysoev.nginx | |
On Thu, Mar 04, 2010 at 03:14:53PM +0300, Maxim Dounin wrote:
Hello!
On Thu, Mar 04, 2010 at 05:09:33AM -0500, georgexsh wrote:
I am writing a module based on nginx 0.7.65, ngx_localtime() is called in the module. Problem is, if set "timer_resolution 100ms;" in config file, nginx workers(*4) will hangs randomly. then if "timer_resolution" command was turned off , everything works just fine.
here is the backtrace (coredump generated with gcore(1) on a hanged worker process):
#0 0x007347a2 in ?? ()
#1 0x00823a9e in pthread_cond_init@@GLIBC_2.3.2 () from /lib/tls/libc.so.6
#2 0x007c942d in __wcsmbs_named_conv () from /lib/tls/libc.so.6
#3 0x080611c6 in ngx_localtime (s=1267569890, tm=0x9ba2048) at
src/os/unix/ngx_time.c:59
#4 0x08055223 in ngx_time_update (sec=1267569890, msec=5) at
src/core/ngx_times.c:114
#5 0x0805e51a in ngx_timer_signal_handler (signo=14) at
src/event/ngx_event.c:565
#6 0x00775898 in __open_catalog () from /lib/tls/libc.so.6
#7 0x007cc043 in __tzfile_read () from /lib/tls/libc.so.6
#8 0x007cb217 in tzset_internal () from /lib/tls/libc.so.6
#9 0x007c942d in __wcsmbs_named_conv () from /lib/tls/libc.so.6
#10 0x080611c6 in ngx_localtime (s=1267569889, tm=0x875ff4) at
src/os/unix/ngx_time.c:59
#11 0x08088c9f in ngx_foo_time_str (r=0x9dcdc28, time_str=0xbfe18450, t=-4) at
./ngx_foo_module//uti.c:111
#12 0x08087d1a in ngx_http_foo_record (r=0x9dcdc28, request_arg=0x9dcddb0) at
./ngx_foo_module//foo.c:124
#13 0x0808788c in ngx_http_foo_handler (r=0x9dcdc28) at
./ngx_foo_module//ngx_http_foo_module.c:74
#14 0x0806d4f9 in ngx_http_core_content_phase (r=0x9dcdc28, ph=0x9bb9938) at
src/http/ngx_http_core_module.c:1262
strace shows (not on the same worker, but similar) :
futex(0x2c2eec, FUTEX_WAIT, 2, NULL)
I guess this situation is a deadlock, happens beneath localtime_r() of glibc. While my module is calling localtime_r, a time update signal trigged localtime at the same time, then deadlocked. Is this correct?
Yes, your analysis is correct. With timer_resolution set and for event methods which does not support timers (all but kqueue, eventport) nginx uses localtime_r() in signal handler. This isn't generally safe thing to do as POSIX doesn't list it as async-signal-safe function. Any other usage of localtime_r() in the same process may cause deadlock.
In fact it may even deadlock by itself as soon as new signal arrives before localtime_r() will finish execution (though unlikely).
I'm a bit surprised that this actually happens as nginx isn't threaded and I see no reason for glibc to use locks. But anyway it's not glibc's fault.
Here is third-party module which probably uses threads:
#11 0x08088c9f in ngx_foo_time_str (r=0x9dcdc28, time_str=0xbfe18450, t=-4) at
./ngx_foo_module//uti.c:111
#12 0x08087d1a in ngx_http_foo_record (r=0x9dcdc28, request_arg=0x9dcddb0) at
./ngx_foo_module//foo.c:124
#13 0x0808788c in ngx_http_foo_handler (r=0x9dcdc28) at
./ngx_foo_module//ngx_http_foo_module.c:74
Now I employ ngx_gmtime() to get formated time instead of ngx_localtime(), works stable for weeks. Maybe ngx_localtime() should not be used outside ngx_time_update().
You should use ngx_time()/ngx_timeofday() instead in your module.
-- Igor Sysoev http://sysoev.ru/en/
_______________________________________________ nginx mailing list ngi...@nginx.org http://nginx.org/mailman/listinfo/nginx