call ngx_localtime may cause deadlock?

[Maxim Dounin]

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.

> 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.

Maxim Dounin