Bug 762411 (GLUSTER-679)

Core was generated by `r/sbin/glusterfs -f vol/server0.vol -l log/0.log'.
Program terminated with signal 11, Segmentation fault.
#0  0x00002aaaaaaae023 in __socket_ioq_new (this=0x7594130, buf=0x75cae10 "", len=272, vector=0x0, count=0, iobref=0x0)
    at ../../../../transport/socket/src/socket.c:305
305	        entry->header.colonO[0] = ':';
#0  0x00002aaaaaaae023 in __socket_ioq_new (this=0x7594130, buf=0x75cae10 "", len=272, vector=0x0, count=0, iobref=0x0)
    at ../../../../transport/socket/src/socket.c:305
	priv = (socket_private_t *) 0x7595300
	entry = (struct ioq *) 0x0
	__PRETTY_FUNCTION__ = "__socket_ioq_new"
#1  0x00002aaaaaab05d7 in socket_submit (this=0x7594130, buf=0x75cae10 "", len=272, vector=0x0, count=0, iobref=0x0)
    at ../../../../transport/socket/src/socket.c:1321
	priv = (socket_private_t *) 0x7595300
	ret = -1
	need_poll_out = 0 '\0'
	need_append = 1 '\001'
	entry = (struct ioq *) 0x0
	ctx = (glusterfs_ctx_t *) 0x7589010
	__FUNCTION__ = "socket_submit"
#2  0x00002b2d95de9b2f in transport_submit (this=0x7594130, buf=0x75cae10 "", len=272, vector=0x0, count=0, iobref=0x0)
    at ../../../libglusterfs/src/transport.c:262
	ret = -1
	peer_trans = (transport_t *) 0x0
	iobuf = (struct iobuf *) 0x0
	msg = (struct transport_msg *) 0x0
	__FUNCTION__ = "transport_submit"
#3  0x00002b2d96eede8d in protocol_server_reply (frame=0x2aaaac0242f8, type=4, op=27, hdr=0x75cae10, hdrlen=272, vector=0x0, count=0, iobref=0x0)
    at ../../../../../xlators/protocol/server/src/server-protocol.c:334
	state = (server_state_t *) 0x2aaaac024360
	bound_xl = (xlator_t *) 0x7590060
	trans = (transport_t *) 0x7594130
	ret = 0
	this = (xlator_t *) 0x7590970
	__FUNCTION__ = "protocol_server_reply"
#4  0x00002b2d96ef3458 in server_lookup_cbk (frame=0x2aaaac0242f8, cookie=0x2aaaac024790, this=0x7590970, op_ret=0, op_errno=22, inode=0x2aaaac024680, 
    stbuf=0x53466eb0, dict=0x0, postparent=0x53466e20) at ../../../../../xlators/protocol/server/src/server-protocol.c:2474
	hdr = (gf_hdr_common_t *) 0x75cae10
	rsp = (gf_fop_lookup_rsp_t *) 0x75cae7c
	state = (server_state_t *) 0x2aaaac024360
	root_inode = (inode_t *) 0x7595570
	dict_len = 0
	hdrlen = 272
	gf_errno = 22
	ret = -1
	link_inode = (inode_t *) 0x2aaaac024680
	fresh_loc = {path = 0x0, name = 0x0, ino = 0, inode = 0x0, parent = 0x0}
	__FUNCTION__ = "server_lookup_cbk"
#5  0x00002b2d96cd9279 in iot_lookup_cbk (frame=0x2aaaac024790, cookie=0x75a5360, this=0x7590060, op_ret=0, op_errno=22, inode=0x2aaaac024680, 
    buf=0x53466eb0, xattr=0x0, postparent=0x53466e20) at ../../../../../xlators/performance/io-threads/src/io-threads.c:165
	fn = (fop_lookup_cbk_t) 0x2b2d96ef2d3e <server_lookup_cbk>
	_parent = (call_frame_t *) 0x2aaaac0242f8
	old_THIS = (xlator_t *) 0x7590060
#6  0x00002b2d96acb10a in pl_lookup_cbk (frame=0x75a5360, cookie=0x75a53e0, this=0x758f820, op_ret=0, op_errno=22, inode=0x2aaaac024680, buf=0x53466eb0, 
    dict=0x0, postparent=0x53466e20) at ../../../../../xlators/features/locks/src/posix.c:1123
	fn = (ret_fn_t) 0x2b2d96cd919a <iot_lookup_cbk>
	_parent = (call_frame_t *) 0x2aaaac024790
	old_THIS = (xlator_t *) 0x758f820
	local = (pl_local_t *) 0xeeeeeeee
#7  0x00002b2d968a94ba in posix_lookup (frame=0x75a53e0, this=0x758ee40, loc=0x2aaaac024820, xattr_req=0x0)
    at ../../../../../xlators/storage/posix/src/posix.c:507
	fn = (fop_lookup_cbk_t) 0x2b2d96acaf6e <pl_lookup_cbk>
	_parent = (call_frame_t *) 0x75a5360
	old_THIS = (xlator_t *) 0x758ee40
	buf = {st_dev = 5441857459637453811, st_ino = 3131823, st_nlink = 1, st_mode = 33188, st_uid = 0, st_gid = 0, pad0 = 0, st_rdev = 0, st_size = 0, 
  st_blksize = 4096, st_blocks = 8, st_atim = {tv_sec = 1267031354, tv_nsec = 0}, st_mtim = {tv_sec = 1267031354, tv_nsec = 0}, st_ctim = {
    tv_sec = 1267031354, tv_nsec = 0}, __unused = {0, 0, 0}}
	real_path = 0x53466da0 "/root/vikas/export/0/dir/1009"
	op_ret = 0
	entry_ret = 0
	op_errno = 22
	xattr = (dict_t *) 0x0
	pathdup = 0xeeeeeeee <Address 0xeeeeeeee out of bounds>
	parentpath = 0x75cae10 ""
	postparent = {st_dev = 5441857459637452802, st_ino = 3129805, st_nlink = 2, st_mode = 16877, st_uid = 0, st_gid = 0, pad0 = 0, st_rdev = 0, 
  st_size = 86016, st_blksize = 4096, st_blocks = 184, st_atim = {tv_sec = 1267031394, tv_nsec = 0}, st_mtim = {tv_sec = 1267031719, tv_nsec = 0}, 
  st_ctim = {tv_sec = 1267031719, tv_nsec = 0}, __unused = {0, 0, 0}}
	priv = (struct posix_private *) 0x7592920
	__FUNCTION__ = "posix_lookup"
#8  0x00002b2d96acb4eb in pl_lookup (frame=0x75a5360, this=0x758f820, loc=0x2aaaac024820, xattr_req=0x0)
    at ../../../../../xlators/features/locks/src/posix.c:1163
	_new = (call_frame_t *) 0x75a53e0
	old_THIS = (xlator_t *) 0x758f820
	tmp_cbk = (fop_lookup_cbk_t) 0x2b2d96acaf6e <pl_lookup_cbk>
	local = (pl_local_t *) 0x75a53c0
	ret = -1
	__FUNCTION__ = "pl_lookup"
#9  0x00002b2d96cd940d in iot_lookup_wrapper (frame=0x2aaaac024790, this=0x7590060, loc=0x2aaaac024820, xattr_req=0x0)
    at ../../../../../xlators/performance/io-threads/src/io-threads.c:175
	_new = (call_frame_t *) 0x75a5360
	old_THIS = (xlator_t *) 0x7590060
	tmp_cbk = (fop_lookup_cbk_t) 0x2b2d96cd919a <iot_lookup_cbk>
#10 0x00002b2d95df5d93 in call_resume_wind (stub=0x2aaaac0247f0) at ../../../libglusterfs/src/call-stub.c:2673
	__FUNCTION__ = "call_resume_wind"
#11 0x00002b2d95dfb916 in call_resume (stub=0x2aaaac0247f0) at ../../../libglusterfs/src/call-stub.c:4304
	old_THIS = (xlator_t *) 0x7590060
	__FUNCTION__ = "call_resume"
#12 0x00002b2d96cd90ec in iot_worker (data=0x75926f0) at ../../../../../xlators/performance/io-threads/src/io-threads.c:115
	conf = (iot_conf_t *) 0x75926f0
	this = (xlator_t *) 0x7590060
	stub = (call_stub_t *) 0x2aaaac0247f0
	sleep_till = {tv_sec = 1267031998, tv_nsec = 0}
	ret = 0
	timeout = 0 '\0'
	bye = 0 '\0'
#13 0x0000003243a06307 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#14 0x00000032d2ed1ded in clone () from /lib64/libc.so.6
No symbol table info available.

Yeah, I saw this a couple of days back. It occurs only when the entry, which is CALLOCd just before being used here, is NULL. In my setup, CALLOC returned NULL because NFS translator was taking up too much memory due to a memory leak. Probably a similar situation here.

In any case, we should program defensively by adding NULL checks. There are no NULL checks for entry after it is alloced.

PATCH: http://patches.gluster.com/patch/2844 in master (socket: Add NULL check for failed ioq entry allocation)

PATCH: http://patches.gluster.com/patch/2844 in release-3.0 (socket: Add NULL check for failed ioq entry allocation)