Actions
Bug #18209
closedsrc/common/LogClient.cc: 310: FAILED assert(num_unsent <= log_queue.size())
Status:
Duplicate
Priority:
High
Assignee:
-
Category:
-
Target version:
-
% Done:
0%
Source:
Tags:
Backport:
luminous
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
(gdb) bt
#0 0x00007f774361db09 in raise () from /lib64/libpthread.so.0
#1 0x0000555b38c9ce5f in reraise_fatal (signum=6) at /home/zhyan/Ceph/ceph/src/global/signal_handler.cc:72
#2 handle_fatal_signal (signum=6) at /home/zhyan/Ceph/ceph/src/global/signal_handler.cc:134
#3 <signal handler called>
#4 0x00007f77423b2765 in raise () from /lib64/libc.so.6
#5 0x00007f77423b436a in abort () from /lib64/libc.so.6
#6 0x0000555b38d5e4ba in ceph::__ceph_assert_fail (assertion=assertion@entry=0x555b3903b410 "num_unsent <= log_queue.size()",
file=file@entry=0x555b3903b3e0 "/home/zhyan/Ceph/ceph/src/common/LogClient.cc", line=line@entry=310,
func=func@entry=0x555b3903ba60 <LogClient::_get_mon_log_message()::__PRETTY_FUNCTION__> "Message* LogClient::_get_mon_log_message()") at /home/zhyan/Ceph/ceph/src/common/assert.cc:78
#7 0x0000555b38d13c4d in LogClient::_get_mon_log_message (this=this@entry=0x555b42e92720) at /home/zhyan/Ceph/ceph/src/common/LogClient.cc:310
#8 0x0000555b38d13e30 in LogClient::get_mon_log_message (this=0x555b42e92720) at /home/zhyan/Ceph/ceph/src/common/LogClient.cc:276
#9 0x0000555b38d6598d in MonClient::send_log (this=this@entry=0x7ffcad85daf0) at /home/zhyan/Ceph/ceph/src/mon/MonClient.cc:308
#10 0x0000555b38d71538 in MonClient::tick (this=0x7ffcad85daf0) at /home/zhyan/Ceph/ceph/src/mon/MonClient.cc:750
#11 0x0000555b3898d1c1 in Context::complete (this=0x555b42cf8210, r=<optimized out>) at /home/zhyan/Ceph/ceph/src/include/Context.h:70
#12 0x0000555b38d5b057 in SafeTimer::timer_thread (this=0x7ffcad85dcd0) at /home/zhyan/Ceph/ceph/src/common/Timer.cc:105
#13 0x0000555b38d5c55d in SafeTimerThread::entry (this=<optimized out>) at /home/zhyan/Ceph/ceph/src/common/Timer.cc:38
#14 0x00007f77436145ca in start_thread () from /lib64/libpthread.so.0
#15 0x00007f77424810ed in clone () from /lib64/libc.so.6
(gdb) f 7
#7 0x0000555b38d13c4d in LogClient::_get_mon_log_message (this=this@entry=0x555b42e92720) at /home/zhyan/Ceph/ceph/src/common/LogClient.cc:310
310 assert(num_unsent <= log_queue.size());
(gdb) p num_unsent
$1 = 13
(gdb) p log_queue
$2 = std::deque with 12 elements = {{who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16,
static NEW = -1}, addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"},
sin = {sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256,
tv_nsec = 314821762}}, seq = 2496, prio = CLOG_WARN, msg = "246 slow requests, 5 included below; oldest blocked for > 643.410362 secs", channel = "cluster"}, {who = {name = {_type = 2 '\002',
_num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1}, addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY,
type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170},
sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>,
__u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256, tv_nsec = 314825775}}, seq = 2497, prio = CLOG_WARN,
msg = "slow request 126.027886 seconds old, received at 2016-12-09 12:52:10.286878: client_request(client.3364353:1854793 create #2000000c950/modules.order 2016-12-09 12:52:01.302771 caller_uid=0, caller_gid"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256,
tv_nsec = 314828401}}, seq = 2498, prio = CLOG_WARN,
msg = "slow request 39.843430 seconds old, received at 2016-12-09 12:53:36.471333: client_request(client.3364353:1854841 create #2000000c7d6/intel_renderstate_gen6.o 2016-12-09 12:53:34.667104 caller_uid=0, "..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256,
tv_nsec = 314830635}}, seq = 2499, prio = CLOG_WARN,
msg = "slow request 32.464533 seconds old, received at 2016-12-09 12:53:43.850230: client_request(client.3364356:507234 unlink #500000057ce/fdc7 2016-12-09 12:53:39.162758 caller_uid=0, caller_gid=0{}) curre"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256,
tv_nsec = 314833095}}, seq = 2500, prio = CLOG_WARN,
msg = "slow request 127.091682 seconds old, received at 2016-12-09 12:52:09.223081: client_request(client.3364353:1854760 create #2000000c922/built-in.o 2016-12-09 12:52:00.149964 caller_uid=0, caller_gid=0{"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259256,
tv_nsec = 314834577}}, seq = 2501, prio = CLOG_WARN,
msg = "slow request 39.841822 seconds old, received at 2016-12-09 12:53:36.472941: client_request(client.3364353:1854842 create #2000000c798/ip6t_ipv6header.o 2016-12-09 12:53:34.669271 caller_uid=0, caller_"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261,
tv_nsec = 314911970}}, seq = 2502, prio = CLOG_WARN, msg = "248 slow requests, 5 included below; oldest blocked for > 648.410423 secs", channel = "cluster"}, {who = {name = {_type = 2 '\002',
_num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1}, addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY,
type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170},
sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>,
__u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261, tv_nsec = 314917425}}, seq = 2503, prio = CLOG_WARN,
msg = "slow request 38.625573 seconds old, received at 2016-12-09 12:53:42.689252: client_request(client.3364353:1855287 create #2000000c7d6/.intel_renderstate_gen7.o.d 2016-12-09 12:53:41.404088 caller_uid="..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261,
---Type <return> to continue, or q <return> to quit---
tv_nsec = 314920064}}, seq = 2504, prio = CLOG_WARN,
msg = "slow request 132.070803 seconds old, received at 2016-12-09 12:52:09.244021: client_request(client.3364353:1854761 create #2000000c922/.built-in.o.cmd 2016-12-09 12:52:00.172717 caller_uid=0, caller_g"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261,
tv_nsec = 314922847}}, seq = 2505, prio = CLOG_WARN,
msg = "slow request 130.850489 seconds old, received at 2016-12-09 12:52:10.464335: client_request(client.3364353:1854798 create #2000000c95a/built-in.o 2016-12-09 12:52:01.494544 caller_uid=0, caller_gid=0{"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261,
tv_nsec = 314925368}}, seq = 2506, prio = CLOG_WARN,
msg = "slow request 37.101413 seconds old, received at 2016-12-09 12:53:44.213412: client_request(client.3364353:1855288 create #2000000c7d6/.intel_renderstate_gen7.o.tmp 2016-12-09 12:53:43.055288 caller_ui"..., channel = "cluster"}, {who = {name = {_type = 2 '\002', _num = 1, static TYPE_MON = 1, static TYPE_MDS = 2, static TYPE_OSD = 4, static TYPE_CLIENT = 8, static TYPE_MGR = 16, static NEW = -1},
addr = {static TYPE_DEFAULT = entity_addr_t::TYPE_LEGACY, type = 1, nonce = 3669258852, u = {sa = {sa_family = 2, sa_data = "\032\221\n\000\000\n\000\000\000\000\000\000\000"}, sin = {
sin_family = 2, sin_port = 37146, sin_addr = {s_addr = 167772170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 37146, sin6_flowinfo = 167772170,
sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}}}, stamp = {tv = {tv_sec = 1481259261,
tv_nsec = 314927524}}, seq = 2507, prio = CLOG_WARN, msg = "slow request 300.300233 seconds old, received at 2016-12-09 12:49:21.014591: rejoin:client.3364356:507138 currently initiated",
channel = "cluster"}}
(gdb)
Actions