[Home]

Summary:ASTERISK-13732: Asterisk becomes unresponsive and seems to be locked waiting on a mutex
Reporter:tomsullivan (tomsullivan)Labels:
Date Opened:2009-03-11 22:50:49Date Closed:2011-06-07 14:00:47
Priority:BlockerRegression?No
Status:Closed/CompleteComponents:General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:After a restart, Asterisk became unresponsive. The Asterisk console still worked, but no calls could be made. After a period, Asterisk was killed, and a coredump generated.

The coredump shows that there were 1034 threads, 1015 of which were in __lll_mutex_lock_wait () (/lib/libpthread.so.0). Below is a full backtrace for one of these threads. All the waiting threads refer to the same lock (lock_addr=0x6650f0).

Below is also a listing of the logs for the period during which it was unresponsive.

****** ADDITIONAL INFORMATION ******

Log excerpt:

Mar 12 04:05:12 localhost asterisk[10731]: ERROR[10732]: utils.c:524 in lock_info_destroy: Thread 'listener             started at [ 1084] asterisk.c ast_makesocket()' still has a lock! - '&(&logchannels)->lock' (0x6650f0) from 'ast_log' in logger.c:740!
Mar 12 04:05:18 localhost asterisk[24648]: ERROR[24648]: codec_dahdi.c:419 in find_transcoders: Failed to open /dev/dahdi/transcode: No such file or directory
...
Mar 12 08:08:18 localhost asterisk[9902]: ERROR[9902]: codec_dahdi.c:419 in find_transcoders: Failed to open /dev/dahdi/transcode: No such file or directory

Full backtrace:

#0  0x00007f5c6b77beeb in __lll_mutex_lock_wait () from /lib/libpthread.so.0
No symbol table info available.
#1  0x00000000008964d8 in ?? ()
No symbol table info available.
#2  0x0000000040d0580e in ?? ()
No symbol table info available.
#3  0x00007f5c6b778dba in pthread_mutex_lock () from /lib/libpthread.so.0
No symbol table info available.
#4  0x00007f5c697be8e4 in __PRETTY_FUNCTION__.8477 () from /lib/libc.so.6
No symbol table info available.
ASTERISK-1  0x00000000008956c0 in ?? ()
No symbol table info available.
ASTERISK-2  0x0000000000000e48 in ?? ()
No symbol table info available.
ASTERISK-3  0x000000000066d220 in lock_infos_lock ()
No symbol table info available.
ASTERISK-4  0x0000000000000100 in ?? ()
No symbol table info available.
ASTERISK-5  0x00000000008956c0 in ?? ()
No symbol table info available.
ASTERISK-6 0x0000000040d05540 in ?? ()
No symbol table info available.
ASTERISK-7 0x00000000004dfee7 in ast_store_lock_info (type=AST_MUTEX, filename=0x522c54 "logger.c", line_num=740, func=0x5245bf "ast_log", lock_name=0x522ed2 "&(&logchannels)->lock", lock_addr=0x6650f0) at utils.c:591
       lock_info = (struct thr_lock_info *) 0x40d09960
       i = 0
ASTERISK-8 0x0000000000486cc0 in ast_log (level=5, file=0x522c54 "logger.c", line=904, function=0x524783 "ast_verbose", fmt=0x522e5c "%s") at logger.c:740
       chan = (struct logchannel *) 0x7f5c698e0560
       buf = (struct ast_dynamic_str *) 0x8969a0
       t = 1236792302
       tm = {tm_sec = 2, tm_min = 25, tm_hour = 4, tm_mday = 12, tm_mon = 2, tm_year = 109, tm_wday = 4, tm_yday = 70, tm_isdst = 1, tm_gmtoff = 39600, tm_zone = 0x0}
       date = "Mar 12 04:25:02\000PZÐ@\000\000\000\000PZÐ@\000\000\000\000pYÐ@\000\000\000\000\231GR\000\000\000\000\000\200\222Ð@\000\000\000\000\220XÐ@", '\0' <repeats 12 times>, "\027i\211\000\000\000\000\000\230h\211\000\000\000\000\000\230h\211\000\000\000\000\000@[Ð@\000\000\000\000PZÐ@\000\000\000\000\177\000\000\000\000\000\000\000\000 Ð@\000\000\000\000\220XÐ@\000\000\000\000úÖpi\\\177\000\000\001\200­ûÿÿÿÿ\230h\211\000\000\000\000\000\230h\211\000\000\000\000\000K\000\000\000\000\000\000\0006\tQ\000\000\000\000\000åYÐ@\000\000\000\000PYÐ@\000\000\000\000fs"...
       ap = {{gp_offset = 0, fp_offset = 0, overflow_arg_area = 0x0, reg_save_area = 0x0}}
       __PRETTY_FUNCTION__ = "ast_log"
ASTERISK-9 0x0000000000487893 in ast_verbose (fmt=0x40d05a50 "\177  == Parsing '%s': ") at logger.c:904
       v = (struct verb *) 0x0
       buf = (struct ast_dynamic_str *) 0x896890
       res = 44
       ap = {{gp_offset = 16, fp_offset = 48, overflow_arg_area = 0x40d05c50, reg_save_area = 0x40d05b90}}
       __PRETTY_FUNCTION__ = "ast_verbose"
ASTERISK-10 0x000000000045d722 in config_text_file_load (database=0x40d08240 "@Åe", table=0x40d08140 "", filename=0x52527c "manager.conf", cfg=0x8967e0, withcomments=0) at config.c:881
       i = 0
       glob_ret = 0
       globbuf = {gl_pathc = 1, gl_pathv = 0x800820, gl_offs = 0, gl_flags = 3088, gl_closedir = 0, gl_readdir = 0, gl_opendir = 0, gl_lstat = 0, gl_stat = 0}
       fn = "/etc/asterisk/manager.conf\000\000\000\000\000\000H\016\000\000\000\000\000\000 Òf\000\000\000\000\000À\tf\000\000\000\000\000ÀV\211\000\000\000\000\0000\200Ð@\000\000\000\000E\004N\000\000\000\000\000\224ªQ\000\000\000\000\000À\tf\000\000\000\000\000ÀV\211\000\000\000\000\000À\tf\000\000\000\000\000 \200Ð@\000\000\000\000\177ëE", '\0' <repeats 37 times>, "À\tf\000\000\000\000\000\"´Q\000\000\000\000\000m¸Q\000\000\000\000\000\177\203Ð@1\005\000\000\224ªQ\000\000\000\000\0000\203Ð@\000\000\000\000\000\000\000\000\001", '\0' <repeats 11 times>, "\020\201Ð@"...
       buf = '\0' <repeats 6688 times>, "\002\000\000\000\000\000\000\000°\200Ð@\000\000\000\000âQR\000\000\000\000\000äQR\000\000\000\000\000\006\000\000\000\000\000\000\000þ±ni\\\177\000\000\000\000\000\000\000\000\000\000p\200Ð@", '\0' <repeats 20 times>, "\220{Ð@\000\000\000\000 \202Ð@\000\000\000\000àQR\000\000\000\000\000À\200Ð@", '\0' <repeats 52 times>, "ÿÿÿÿÿÿÿÿ\000\000\000\000\b\000\000\000àQR\000\000\000\000\000x\177Ð@", '\0' <repeats 68 times>, " ", '\0' <repeats 30 times>, "s", '\0' <repeats 112 times>, "áQR\000\000\000\000\000\000\000\000\000ÿÿÿÿ", '\0' <repeats 192 times>...
       new_buf = 0x10040d08330 <Address 0x10040d08330 out of bounds>
       comment_p = 0x40d08140 ""
       process_buf = 0x10040d08330 <Address 0x10040d08330 out of bounds>
       f = (FILE *) 0x40d08240
       lineno = 0
       comment = 0
       nest = {0 <repeats 128 times>}
       cat = (struct ast_category *) 0x0
       count = 0
       statbuf = {st_dev = 64768, st_ino = 424975, st_nlink = 1, st_mode = 33188, st_uid = 10003, st_gid = 10001, pad0 = 0, st_rdev = 0, st_size = 88, st_blksize = 4096, st_blocks = 8, st_atim = {tv_sec = 1236215471, tv_nsec = 0},
 st_mtim = {tv_sec = 1236215471, tv_nsec = 0}, st_ctim = {tv_sec = 1236215471, tv_nsec = 0}, __unused = {0, 0, 0}}
       comment_buffer = 0x0
       comment_buffer_size = 0
       lline_buffer = 0x0
       lline_buffer_size = 0
       __PRETTY_FUNCTION__ = "config_text_file_load"
ASTERISK-11 0x000000000045f6fb in ast_config_internal_load (filename=0x52527c "manager.conf", cfg=0x8967e0, withcomments=0) at config.c:1373
       db = "@Åe\000\000\000\000\000Â-Q\000\000\000\000\000\2000Q\000\000\000\000\000\200\222Ð@\207\000\000\000¤-Q\000\000\000\000\000\bh\211", '\0' <repeats 21 times>, "ð\202Ð@\000\000\000\000{\026C\000\000\000\000\000\217\035EøªXÏè\222\001", '\0' <repeats 14 times>, "\021¬Q\000\000\000\000\000\000\000\000\000Í\001\000\000\224ªQ\000\000\000\000\000\000\000\000\000\001\000\000\000(\000\000\000\000\000\000\000pg\211\000\000\000\000\000àg\211\000\000\000\000\000\bh\211\000\000\000\000\000\220\205Ð@\222\001\000\000@\203Ð@\000\000\000\000j\024C\000\000\000\000\000O\000\000\000\000\000\000\000\021¬Q\000\000\000\000\0000\203Ð@Í\001\000"...
       table = '\0' <repeats 40 times>, "ÿÿÿÿ", '\0' <repeats 44 times>, " õ\215i\\\177", '\0' <repeats 58 times>, "Ð", '\0' <repeats 15 times>, "\a\020C", '\0' <repeats 13 times>, "@Åe\000\000\000\000\000\200\202Ð@\000\000\000\000u\023C\000\000\000\000\000\200\222Ð@\000\000\000\000c4oi\\\177\000\000 \000\000\0000\000\000\000\t\000\000\000\000\000\000\000©.Q\000\000\000\000\000¤-Q\000\000\000\000"
       loader = (struct ast_config_engine *) 0x660b40
       result = (struct ast_config *) 0x40d085df
       __PRETTY_FUNCTION__ = "ast_config_internal_load"
ASTERISK-12 0x000000000045f77c in ast_config_load (filename=0x52527c "manager.conf") at config.c:1392
       cfg = (struct ast_config *) 0x8967e0
       result = (struct ast_config *) 0x300000000
ASTERISK-13 0x000000000048a79d in authenticate (s=0x7f5c5d924080, m=0x40d08c90) at manager.c:964
       cfg = (struct ast_config *) 0x40d08590
       cat = 0x40d08590 "òLR"
       user = 0x40d0882a "munin"
       pass = 0x40d08808 "alxdvc3f"
       authtype = 0x524cf2 ""
       key = 0x524cf2 ""
       events = 0x40d087e8 "off"
       __PRETTY_FUNCTION__ = "authenticate"
ASTERISK-14 0x000000000048e85d in process_message (s=0x7f5c5d924080, m=0x40d08c90) at manager.c:2195
       action = "login", '\0' <repeats 74 times>
       tmp = (struct manager_action *) 0x40d09960
       id = 0x524cf2 ""
       idText = '\0' <repeats 255 times>
       ret = 0
       __PRETTY_FUNCTION__ = "process_message"
ASTERISK-15 0x000000000048f09c in do_message (s=0x7f5c5d924080) at manager.c:2321
       m = {hdrcount = 4, headers = {0x40d08840 "Action: login", 0x40d08820 "Username: munin", 0x40d08800 "Secret: alxdvc3f", 0x40d087e0 "Events: off", 0x0 <repeats 124 times>}}
       header_buf = "\000\n\000nts: off\000\n\0003f\000\n", '\0' <repeats 1005 times>
       res = 1
ASTERISK-16 0x000000000048f1d0 in session_do (data=0x7f5c5d924080) at manager.c:2337
       s = (struct mansession *) 0x7f5c5d924080
       res = 0
       __PRETTY_FUNCTION__ = "session_do"
ASTERISK-17 0x00000000004e0b80 in dummy_start (data=0x7f5c5d92e9c0) at utils.c:856
       __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {0, 1087410640, 0, 1087412576, 1087410816, 1087414272, 1087410432, 5114466}, __mask_was_saved = 0}}, __pad = {0x40d091f0, 0x0, 0x0, 0x0}}
       __cancel_routine = (void (*)(void *)) 0x42836a <ast_unregister_thread>
       __cancel_arg = (void *) 0x40d09960
       not_first_call = 0
       ret = (void *) 0x0
       a = {start_routine = 0x48f1a0 <session_do>, data = 0x7f5c5d924080, name = 0x7f5c5d924750 "session_do", ' ' <repeats 11 times>, "started at [ 2460] manager.c accept_thread()"}
       lock_info = (struct thr_lock_info *) 0x8956c0
       mutex_attr = {__size = "\001\000\000", __align = 1}
       __PRETTY_FUNCTION__ = "dummy_start"
ASTERISK-18 0x00007f5c6b776f1a in start_thread () from /lib/libpthread.so.0
No symbol table info available.
ASTERISK-19 0x00007f5c697725d2 in clone () from /lib/libc.so.6
No symbol table info available.
ASTERISK-20 0x0000000000000000 in ?? ()
No symbol table info available.
Comments:By: Tilghman Lesher (tilghman) 2009-03-12 10:06:15

Please turn on DEBUG_THREADS in 'make menuselect' and get a 'core show locks' when the lockup occurs.
By: Tilghman Lesher (tilghman) 2009-03-12 10:10:27

Also, please do not upload coredumps in the future.  They are completely useless on any machine except the machine on which it was generated.  The information we need is detailed in doc/backtrace.txt.
By: Leif Madsen (lmadsen) 2009-04-09 10:48:44

Pinging reporter for feedback here? Otherwise we'll need to close the issue. Thanks!
By: Joshua C. Colp (jcolp) 2009-04-21 09:06:48

Suspending this issue since the reporter has not responded in quite some time.