[Bugs] [Bug 1289414] New: [tiering]: Tier daemon crashed on two of eight nodes and lot of "demotion failed" seen in the system
bugzilla at redhat.com
bugzilla at redhat.com
Tue Dec 8 03:41:18 UTC 2015
https://bugzilla.redhat.com/show_bug.cgi?id=1289414
Bug ID: 1289414
Summary: [tiering]: Tier daemon crashed on two of eight nodes
and lot of "demotion failed" seen in the system
Product: GlusterFS
Version: 3.7.6
Component: tiering
Severity: high
Assignee: bugs at gluster.org
Reporter: nbalacha at redhat.com
QA Contact: bugs at gluster.org
CC: bugs at gluster.org, dlambrig at redhat.com,
kramdoss at redhat.com, nchilaka at redhat.com,
rhs-bugs at redhat.com
Depends On: 1288995
+++ This bug was initially created as a clone of Bug #1288995 +++
+++ This bug was initially created as a clone of Bug #1288003 +++
Description of problem:
Tier daemon seems to have crashed in two of eight nodes and core files have
been generated.
Huge number of 'demotion failed' error messages are seen in few nodes. No
demotion is seen although there are multiple files eligible for demotion
crossing watermark levels.
Hot tier size --> 100Gb and watermarks are set so that low watermark is a 10Gb
and high watermark is at 30Gb. Currently, size of hot tier has crossed 30Gb and
no files are being demoted yet.
Single distributed dispersed volume with 12 bricks was configured to which a
distributed replicated(4 bricks) hot tier was attached. Crash was seen few
hours after configuring the volume and doing some IO.
please note that the gluster cluster is configured on rhel 6.7.
sosreport and core files shall be attached shortly.
[root at dhcp37-121 ~]# gluster vol info
Volume Name: tiering-test-vol-01
Type: Tier
Volume ID: 8afb30c0-bd3e-4248-b4ba-8a6bfe8d237e
Status: Started
Number of Bricks: 16
Transport-type: tcp
Hot Tier :
Hot Tier Type : Distributed-Replicate
Number of Bricks: 2 x 2 = 4
Brick1: 10.70.37.111:/rhs/brick4/leg1
Brick2: 10.70.37.154:/rhs/brick4/leg1
Brick3: 10.70.37.121:/rhs/brick4/leg1
Brick4: 10.70.37.191:/rhs/brick4/leg1
Cold Tier:
Cold Tier Type : Distributed-Disperse
Number of Bricks: 2 x (4 + 2) = 12
Brick5: 10.70.37.191:/rhs/brick1/leg1
Brick6: 10.70.37.121:/rhs/brick1/leg1
Brick7: 10.70.37.154:/rhs/brick1/leg1
Brick8: 10.70.37.111:/rhs/brick1/leg1
Brick9: 10.70.37.140:/rhs/brick15/leg1
Brick10: 10.70.37.132:/rhs/brick15/leg1
Brick11: 10.70.37.180:/rhs/brick15/leg1
Brick12: 10.70.37.48:/rhs/brick15/leg1
Brick13: 10.70.37.191:/rhs/brick2/leg1
Brick14: 10.70.37.121:/rhs/brick2/leg1
Brick15: 10.70.37.154:/rhs/brick2/leg1
Brick16: 10.70.37.111:/rhs/brick2/leg1
Options Reconfigured:
cluster.tier-promote-frequency: 7200
cluster.tier-max-files: 1000
cluster.write-freq-threshold: 3
cluster.watermark-hi: 30
cluster.watermark-low: 10
cluster.tier-demote-frequency: 120
cluster.tier-mode: cache
features.ctr-enabled: on
performance.readdir-ahead: on
Version-Release number of selected component (if applicable):
How reproducible:
No pattern yet found
Steps to Reproduce:
1. configure 8 node gluster cluster
2. configure 2 x (4 + 2) distributed dispersed volume
3. Attach a dist-repl hot tier
4. Made parameter changes w.r.t tiering to the vol. values are set as shown in
the above output of vol info
4. Run IO
Actual results:
demotion failures seen along with crash
Expected results:
No crashes or promotion/demotion failure should be seen
Additional info:
<<<log snippet from a node where crash is seen>>>
[2015-12-03 00:01:25.433174] C
[rpc-clnt-ping.c:165:rpc_clnt_ping_timer_expired]
0-tiering-test-vol-01-client-9: server 10.70.37.121:49153 has not responded in
the last 42 seconds, disconnecting.
[2015-12-03 00:01:25.433755] E [rpc-clnt.c:362:saved_frames_unwind] (-->
/usr/lib64/libglusterfs.so.0(_gf_log_callingfn+0x1eb)[0x7fdf009026eb] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_unwind+0x1e7)[0x7fdf006cd227] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7fdf006cd33e] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0xab)[0x7fdf006cd40b] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_notify+0x1c2)[0x7fdf006cda42] )))))
0-tiering-test-vol-01-client-9: forced unwinding frame type(GlusterFS 3.3)
op(IPC(47)) called at 2015-12-03 00:00:01.130434 (xid=0xcc177)
[2015-12-03 00:01:25.433787] W [MSGID: 114031]
[client-rpc-fops.c:2265:client3_3_ipc_cbk] 0-tiering-test-vol-01-client-9:
remote operation failed [Transport endpoint is not connected]
[2015-12-03 00:01:25.433966] E [MSGID: 109107]
[tier.c:838:tier_process_ctr_query] 0-tiering-test-vol-01-tier-dht: Failed
query on /rhs/brick2/leg1/.glusterfs/leg1.db ret -107
pending frames:
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
patchset: git://git.gluster.com/glusterfs.git
signal received: 11
time of crash:
2015-12-03 00:01:25
configuration details:
argp 1
backtrace 1
dlfcn 1
libpthread 1
llistxattr 1
setfsid 1
spinlock 1
epoll.h 1
[2015-12-03 00:01:25.434002] E [rpc-clnt.c:362:saved_frames_unwind] (-->
/usr/lib64/libglusterfs.so.0(_gf_log_callingfn+0x1eb)[0x7fdf009026eb] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_unwind+0x1e7)[0x7fdf006cd227] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7fdf006cd33e] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0xab)[0x7fdf006cd40b] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_notify+0x1c2)[0x7fdf006cda42] )))))
0-tiering-test-vol-01-client-9: forced unwinding frame type(GlusterFS 3.3)
op(LOOKUP(27)) called at 2015-12-03 00:00:01.132380 (xid=0xcc178)
[2015-12-03 00:01:25.435552] W [MSGID: 114031]
[client-rpc-fops.c:2974:client3_3_lookup_cbk] 0-tiering-test-vol-01-client-9:
remote operation failed. Path: <gfid:44203d75-0c8a-4062-a504-ff8a21ec47ef>
(44203d75-0c8a-4062-a504-ff8a21ec47ef) [Transport endpoint is not connected]
xattr.h 1
st_atim.tv_nsec 1
package-string: glusterfs 3.7.5
[2015-12-03 00:01:25.435741] W [MSGID: 122053]
[ec-common.c:116:ec_check_status] 0-tiering-test-vol-01-disperse-1: Operation
failed on some subvolumes (up=3F, mask=3F, remaining=0, good=37, bad=8)
[2015-12-03 00:01:25.435762] W [MSGID: 122002] [ec-common.c:71:ec_heal_report]
0-tiering-test-vol-01-disperse-1: Heal failed [Invalid argument]
/usr/lib64/libglusterfs.so.0(_gf_msg_backtrace_nomem+0xb6)[0x7fdf008fe9e6]
/usr/lib64/libglusterfs.so.0(gf_print_trace+0x32f)[0x7fdf0091e54f]
/lib64/libc.so.6(+0x3d4ac326a0)[0x7fdeff29c6a0]
/usr/lib64/libglusterfs.so.0(__gf_free+0xc5)[0x7fdf00934d75]
/usr/lib64/glusterfs/3.7.5/xlator/cluster/tier.so(+0x5b267)[0x7fdef2887267]
/usr/lib64/glusterfs/3.7.5/xlator/cluster/tier.so(+0x5ca70)[0x7fdef2888a70]
/lib64/libpthread.so.0(+0x3d4b007a51)[0x7fdeff9e8a51]
/lib64/libc.so.6(clone+0x6d)[0x7fdeff35293d]
---------
<<<log snippet from second node where crash is seen>>>
[2015-12-02 13:52:50.473989] I [glusterfsd-mgmt.c:1596:mgmt_getspec_cbk]
0-glusterfs: No change in volfile, continuing
The message "I [MSGID: 109103] [dht-shared.c:469:dht_reconfigure] 0-DHT:
conf->dthrottle: normal, conf->defrag->recon_thread_count: 2" repeated 5 times
between [2015-12-02 13:52:30.764481] and [2015-12-02 13:52:50.473688]
pending frames:
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
frame : type(0) op(0)
patchset: git://git.gluster.com/glusterfs.git
signal received: 6
time of crash:
2015-12-03 03:35:12
configuration details:
argp 1
backtrace 1
dlfcn 1
libpthread 1
llistxattr 1
setfsid 1
spinlock 1
epoll.h 1
xattr.h 1
st_atim.tv_nsec 1
package-string: glusterfs 3.7.5
/usr/lib64/libglusterfs.so.0(_gf_msg_backtrace_nomem+0xb6)[0x7f6d288509e6]
/usr/lib64/libglusterfs.so.0(gf_print_trace+0x32f)[0x7f6d2887054f]
/lib64/libc.so.6(+0x33ed4326a0)[0x7f6d271ee6a0]
/lib64/libc.so.6(gsignal+0x35)[0x7f6d271ee625]
/lib64/libc.so.6(abort+0x175)[0x7f6d271efe05]
/lib64/libc.so.6(+0x33ed470537)[0x7f6d2722c537]
/lib64/libc.so.6(+0x33ed475f4e)[0x7f6d27231f4e]
/lib64/libc.so.6(+0x33ed476353)[0x7f6d27232353]
/lib64/libc.so.6(+0x33ed479c28)[0x7f6d27235c28]
/lib64/libc.so.6(__libc_malloc+0x5c)[0x7f6d27236b1c]
/usr/lib64/libglusterfs.so.0(glusterfs_lkowner_buf_get+0x22)[0x7f6d2888b7b2]
/usr/lib64/libglusterfs.so.0(lkowner_utoa+0x18)[0x7f6d28870188]
/usr/lib64/libglusterfs.so.0(gf_proc_dump_call_stack+0x1d2)[0x7f6d2888ece2]
/usr/lib64/libglusterfs.so.0(gf_proc_dump_pending_frames+0xde)[0x7f6d2888f04e]
/usr/lib64/libglusterfs.so.0(gf_proc_dump_info+0xccb)[0x7f6d2888dafb]
/usr/sbin/glusterfs(glusterfs_sigwaiter+0xcd)[0x7f6d28d1d10d]
/lib64/libpthread.so.0(+0x33ed807a51)[0x7f6d2793aa51]
/lib64/libc.so.6(clone+0x6d)[0x7f6d272a493d]
---------
--- Additional comment from krishnaram Karthick on 2015-12-04 04:22:03 EST ---
Pasting BT for both the cores
<<<<<<BT from dhcp37-121.core.5159>>>>>>
(gdb) bt
#0 0x00007fdf00934d75 in __gf_free (free_ptr=0x7fdebc001970) at mem-pool.c:313
#1 0x00007fdef2887267 in tier_process_ctr_query (args=0x7fdee9fa3c40,
query_cbk_args=<value optimized out>, is_promotion=<value optimized out>) at
tier.c:878
#2 tier_process_brick (args=0x7fdee9fa3c40, query_cbk_args=<value optimized
out>, is_promotion=<value optimized out>) at tier.c:967
#3 tier_build_migration_qfile (args=0x7fdee9fa3c40, query_cbk_args=<value
optimized out>, is_promotion=<value optimized out>) at tier.c:1043
#4 0x00007fdef2888a70 in tier_promote (args=0x7fdee9fa3c40) at tier.c:1143
#5 0x00007fdeff9e8a51 in start_thread () from /lib64/libpthread.so.0
#6 0x00007fdeff35293d in clone () from /lib64/libc.so.6
<<<<<<<BT from dhcp37-111.core.5424>>>>>>
#0 0x00007f6d271ee625 in raise () from /lib64/libc.so.6
#1 0x00007f6d271efe05 in abort () from /lib64/libc.so.6
#2 0x00007f6d2722c537 in __libc_message () from /lib64/libc.so.6
#3 0x00007f6d27231f4e in malloc_printerr () from /lib64/libc.so.6
#4 0x00007f6d27232353 in malloc_consolidate () from /lib64/libc.so.6
#5 0x00007f6d27235c28 in _int_malloc () from /lib64/libc.so.6
#6 0x00007f6d27236b1c in malloc () from /lib64/libc.so.6
#7 0x00007f6d2888b7b2 in __gf_default_malloc () at mem-pool.h:106
#8 glusterfs_lkowner_buf_get () at globals.c:329
#9 0x00007f6d28870188 in lkowner_utoa (lkowner=0x7f6d2625f970) at
common-utils.c:2407
#10 0x00007f6d2888ece2 in gf_proc_dump_call_stack (call_stack=0x7f6d2625f718,
key_buf=<value optimized out>) at stack.c:167
#11 0x00007f6d2888f04e in gf_proc_dump_pending_frames
(call_pool=0x7f6d299727a0) at stack.c:210
#12 0x00007f6d2888dafb in gf_proc_dump_info (signum=<value optimized out>,
ctx=0x7f6d29950010) at statedump.c:825
#13 0x00007f6d28d1d10d in glusterfs_sigwaiter (arg=<value optimized out>) at
glusterfsd.c:2020
#14 0x00007f6d2793aa51 in start_thread () from /lib64/libpthread.so.0
#15 0x00007f6d272a493d in clone () from /lib64/libc.so.6
--- Additional comment from Vijay Bellur on 2015-12-07 03:08:08 EST ---
REVIEW: http://review.gluster.org/12890 (cluster/tier : Fix double free in tier
process) posted (#1) for review on master by N Balachandran
(nbalacha at redhat.com)
--- Additional comment from Nithya Balachandran on 2015-12-07 03:14:42 EST ---
Analysis of dhcp37-121.core.5159:
>From the logs:
[2015-12-03 00:01:25.433174] C
[rpc-clnt-ping.c:165:rpc_clnt_ping_timer_expired]
0-tiering-test-vol-01-client-9: server 10.70.37.121:49153 has not responded in
the last 42 seconds, disconnecting.
[2015-12-03 00:01:25.433755] E [rpc-clnt.c:362:saved_frames_unwind] (-->
/usr/lib64/libglusterfs.so.0(_gf_log_callingfn+0x1eb)[0x7fdf009026eb] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_unwind+0x1e7)[0x7fdf006cd227] (-->
/usr/lib64/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7fdf006cd33e] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0xab)[0x7fdf006cd40b] (-->
/usr/lib64/libgfrpc.so.0(rpc_clnt_notify+0x1c2)[0x7fdf006cda42] )))))
0-tiering-test-vol-01-client-9: forced unwinding frame type(GlusterFS 3.3)
op(IPC(47)) called at 2015-12-03 00:00:01.130434 (xid=0xcc177)
[2015-12-03 00:01:25.433787] W [MSGID: 114031]
[client-rpc-fops.c:2265:client3_3_ipc_cbk] 0-tiering-test-vol-01-client-9:
remote operation failed [Transport endpoint is not connected]
[2015-12-03 00:01:25.433966] E [MSGID: 109107]
[tier.c:838:tier_process_ctr_query] 0-tiering-test-vol-01-tier-dht: Failed
query on /rhs/brick2/leg1/.glusterfs/leg1.db ret -107
pending frames:
This means that the syncop_ipc call in tier_process_ctr_query failed.
ret = dict_set_bin (ctr_ipc_in_dict, GFDB_IPC_CTR_GET_QUERY_PARAMS,
ipc_ctr_params, sizeof (*ipc_ctr_params));
if (ret) {
gf_msg (this->name, GF_LOG_ERROR, 0, LG_MSG_SET_PARAM_FAILED,
"Failed setting %s to params dictionary",
GFDB_IPC_CTR_GET_QUERYsyncop_ipc_PARAMS);
goto out;
}
ret = syncop_ipc (local_brick->xlator, GF_IPC_TARGET_CTR,
ctr_ipc_in_dict, &ctr_ipc_out_dict);
if (ret) {
gf_msg (this->name, GF_LOG_ERROR, 0,
DHT_MSG_LOG_IPC_TIER_ERROR, "Failed query on %s ret
%d",
local_brick->brick_db_path, ret);
goto out;
}
Since the call to syncop_ipc() failed, ctr_ipc_out_dict is NULL. On goto out:
out:
if (ctr_ipc_in_dict) {
dict_unref(ctr_ipc_in_dict); <-- this will free ipc_ctr_params
ctr_ipc_in_dict = NULL;
}
if (ctr_ipc_out_dict) {
dict_unref(ctr_ipc_out_dict);
ctr_ipc_out_dict = NULL;
ipc_ctr_params = NULL; <-- this is not set to NULL
}
GF_FREE (ipc_ctr_params); <--double free
return ret;
}
The dict_unref(ctr_ipc_in_dict) will call GF_FREE on ipc_ctr_params as part of
dict_destroy()->data_unref() as data->is_static is false.
As the memory has already been freed, the second call to GF_FREE
(ipc_ctr_params) will crash.
--- Additional comment from Vijay Bellur on 2015-12-07 09:36:04 EST ---
COMMIT: http://review.gluster.org/12890 committed in master by Dan Lambright
(dlambrig at redhat.com)
------
commit 06818a0fd69bb0d6daabde73e5c3cc2661a70854
Author: N Balachandran <nbalacha at redhat.com>
Date: Mon Dec 7 13:32:57 2015 +0530
cluster/tier : Fix double free in tier process
The tier process tries to free ipc_ctr_params twice
if the syncop_ipc call in tier_process_ctr_query fails.
ipc_ctr_params is freed when ctr_ipc_in_dict is freed.
But ctr_ipc_out_dict is NULL when syncop_ipc fails, causing
GF_FREE to be called on a non-NULL ipc_ctr_params ptr again.
Change-Id: Ia15f36dfbcd97be5524588beb7caad5cb79efdb4
BUG: 1288995
Signed-off-by: N Balachandran <nbalacha at redhat.com>
Reviewed-on: http://review.gluster.org/12890
Reviewed-by: Joseph Fernandes
Tested-by: NetBSD Build System <jenkins at build.gluster.org>
Tested-by: Gluster Build System <jenkins at build.gluster.com>
Reviewed-by: Dan Lambright <dlambrig at redhat.com>
Referenced Bugs:
https://bugzilla.redhat.com/show_bug.cgi?id=1288995
[Bug 1288995] [tiering]: Tier daemon crashed on two of eight nodes and lot
of "demotion failed" seen in the system
--
You are receiving this mail because:
You are the QA Contact for the bug.
You are on the CC list for the bug.
You are the assignee for the bug.
More information about the Bugs
mailing list