GitLab

Summary

When log rotation occurs, if named encounters an unexpected errno during a call to rename, named will hang because of an attempt to recursively acquire a lock for logging.

BIND version used

9.12.2 on Linux

Steps to reproduce

Cause named to encounter an unexpected errno from the rename call.

What is the current bug behavior?

named hangs.

What is the expected correct behavior?

named does not hang.

Relevant logs and/or screenshots

Thread 4 (Thread 0xf6a27b40 (LWP 8246)):
#0  0xf7f69a02 in ?? () from /lib/ld-linux.so.2
#1  0xf7ccdd22 in __lll_lock_wait () from /lib/i386-linux-gnu/libpthread.so.0
#2  0xf7cc79d5 in pthread_mutex_lock () from /lib/i386-linux-gnu/libpthread.so.0
#3  0x0829c445 in isc_log_doit (lctx=lctx@entry=0x8ffb2d8, category=category@entry=0x84eac20 <isc_categories+8>, module=module@entry=0x84dd780 <modules>, level=level@entry=-4, write_once=write_once@entry=isc_boolean_false, msgcat=msgcat@entry=0x0, msgset=msgset@entry=0, msg=msg@entry=0, format=format@entry=0x83c311f "%s:%d: unexpected error:", args=args@entry=0xf6a237d4 "[redacted]") at log.c:1633
#4  0x0829d517 in isc_log_write (lctx=0x8ffb2d8, category=category@entry=0x84eac20 <isc_categories+8>, module=0x84dd780 <modules>, level=level@entry=-4, format=format@entry=0x83c311f "%s:%d: unexpected error:") at log.c:837
#5  0x08075102 in library_unexpected_error (file=0x8438180 "file.c", line=414, format=0x8437f88 "unable to convert errno to isc_result: %d: %s", args=0xf6a2382c "z") at ./main.c:310
#6  0x0828fac2 in isc_error_unexpected (file=file@entry=0x8438180 "file.c", line=line@entry=414, format=format@entry=0x8437f88 "unable to convert errno to isc_result: %d: %s") at error.c:59
#7  0x082c212d in isc___errno2result (posixerrno=122, dolog=dolog@entry=isc_boolean_true, file=file@entry=0x8438180 "file.c", line=line@entry=414) at errno2result.c:111
#8  0x082c2ea1 in isc_file_rename (oldname=oldname@entry=0xf6a23e7a "/usr/local/akamai/logs/named/named.log.0", newname=newname@entry=0xf6a24e7b "/usr/local/akamai/logs/named/named.log.1") at file.c:414
#9  0x08299f77 in roll_increment (file=<optimized out>) at log.c:1396
#10 0x0829c9f2 in isc_log_open (channel=<optimized out>) at log.c:1535
#11 isc_log_doit (lctx=lctx@entry=0x8ffb2d8, category=category@entry=0x84e4c88 <dns_categories+72>, module=module@entry=0x84e4b68 <dns_modules+72>, level=level@entry=-1, write_once=write_once@entry=isc_boolean_false, msgcat=msgcat@entry=0x0, msgset=msgset@entry=0, msg=msg@entry=0, format=format@entry=0x8416844 "%s%s%s resolving '%s/%s/%s': %s", args=args@entry=0xf6a26154 "[redacted]") at log.c:1897
#12 0x0829d517 in isc_log_write (lctx=0x8ffb2d8, category=0x84e4c88 <dns_categories+72>, module=0x84e4b68 <dns_modules+72>, level=level@entry=-1, format=format@entry=0x8416844 "%s%s%s resolving '%s/%s/%s': %s") at log.c:837
#13 0x081cbf56 in add_bad (fctx=fctx@entry=0xf29b3a68, addrinfo=0xf19e8540, reason=196609, badtype=<optimized out>) at resolver.c:3250
#14 0x081db839 in rctx_nextserver (rctx=0xf6a26a0c, addrinfo=<optimized out>, result=196609) at resolver.c:8978
#15 0x081ddb92 in resquery_response (task=0xf48c82b0, event=0xf18e2218) at resolver.c:7367
#16 0x082b48c9 in dispatch (manager=0xf7a2f008) at task.c:1139
#17 run (uap=0xf7a2f008) at task.c:1311
#18 0xf7cc52a5 in start_thread () from /lib/i386-linux-gnu/libpthread.so.0
#19 0xf7b9920e in clone () from /lib/i386-linux-gnu/libc.so.6

Possible fixes

Removing the call to UNEXPECTED_ERROR in errno2result.c should prevent named from hanging, but may cause this log line to not be logged in other desirable cases.

Handling more errno values in errno2result.c would help this specific case, but would not help other unexpected errnos.