Bug 1227677

Summary: Glusterd crashes and cannot start after rebalance
Product: [Community] GlusterFS Reporter: lenz <lenz73>
Component: glusterdAssignee: Susant Kumar Palai <spalai>
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: unspecified    
Version: 3.7.0CC: amukherj, bugs, chris, gluster-bugs, lenz73, nbalacha, nsathyan
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: glusterfs-3.7.2 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-06-20 09:49:40 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description lenz 2015-06-03 09:52:12 UTC
Description of problem:


I am using the RPMS supplied for Centos7. If I create a replicated volume and then start a rebalance, the server crashes and will not restart.


Version-Release number of selected component (if applicable):

glusterfs-server.x86_64                 3.7.1-1.el7

How reproducible:

Any time. I tried this on two DigitalOcean boxes, freshly installed.


Steps to Reproduce:


yum update -y
yum install -y mc wget lsof nano epel-release
wget -P /etc/yum.repos.d http://download.gluster.org/pub/gluster/glusterfs/LATEST/RHEL/glusterfs-epel.repo
yum install -y glusterfs-server glusterfs-client
service glusterd start && chkconfig glusterd on

gluster peer probe 46.101.184.191

gluster volume create livebackup replica 2 transport tcp 46.101.160.245:/opt/gluster_brick1 46.101.184.191:/opt/gluster_brick2 force
gluster volume start livebackup
gluster volume add-brick livebackup 46.101.160.245:/opt/gluster_brick2 46.101.184.191:/opt/gluster_brick1 force

[root@glu2 ~]# gluster volume info

Volume Name: livebackup
Type: Distributed-Replicate
Volume ID: 55cf62a0-099f-4a5e-ae4a-0ddec29239b4
Status: Started
Number of Bricks: 2 x 2 = 4
Transport-type: tcp
Bricks:
Brick1: 46.101.160.245:/opt/gluster_brick1
Brick2: 46.101.184.191:/opt/gluster_brick2
Brick3: 46.101.160.245:/opt/gluster_brick2
Brick4: 46.101.184.191:/opt/gluster_brick1
Options Reconfigured:
performance.readdir-ahead: on

mount -t glusterfs localhost:/livebackup /mnt

cp /var/log/* /mnt

gluster volume rebalance livebackup fix-layout start

[root@glu2 ~]# gluster volume rebalance livebackup fix-layout start
Connection failed. Please check if gluster daemon is operational.

The error appearing is:

*** buffer overflow detected ***: glusterd terminated
======= Backtrace: =========
/lib64/libc.so.6(__fortify_fail+0x37)[0x7f3dba994a57]
/lib64/libc.so.6(+0x10bc10)[0x7f3dba992c10]
/lib64/libc.so.6(+0x10b32b)[0x7f3dba99232b]
/lib64/libc.so.6(__snprintf_chk+0x78)[0x7f3dba992248]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_volume_defrag_restart+0x191)[0x7f3db0d5d931]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_restart_rebalance+0x82)[0x7f3db0d63aa2]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_spawn_daemons+0x4f)[0x7f3db0d63b1f]
/lib64/libglusterfs.so.0(synctask_wrap+0x12)[0x7f3dbbf05482]
/lib64/libc.so.6(+0x470f0)[0x7f3dba8ce0f0]






Actual results:

Crashes. If restarted, will crash again. No way to get the daemon back up, but reinstalling.


Expected results:

Disk rebalancing, or an error. 


Additional info:

[root@glu2 ~]# glusterd --debug
[2015-06-03 09:00:02.052842] I [MSGID: 100030] [glusterfsd.c:2294:main] 0-glusterd: Started running glusterd version 3.7.1 (args: glusterd --debug)
[2015-06-03 09:00:02.053455] D [logging.c:1788:__gf_log_inject_timer_event] 0-logging-infra: Starting timer now. Timeout = 120, current buf size = 5
[2015-06-03 09:00:02.053671] D [MSGID: 0] [glusterfsd.c:626:get_volfp] 0-glusterfsd: loading volume file /etc/glusterfs/glusterd.vol
[2015-06-03 09:00:02.058875] I [glusterd.c:1282:init] 0-management: Maximum allowed open file descriptors set to 65536
[2015-06-03 09:00:02.058924] I [glusterd.c:1327:init] 0-management: Using /var/lib/glusterd as working directory
[2015-06-03 09:00:02.059032] D [glusterd.c:391:glusterd_rpcsvc_options_build] 0-: listen-backlog value: 128
[2015-06-03 09:00:02.059246] D [rpcsvc.c:2315:rpcsvc_init] 0-rpc-service: RPC service inited.
[2015-06-03 09:00:02.059260] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GF-DUMP, Num: 123451501, Ver: 1, Port: 0
[2015-06-03 09:00:02.059295] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.066955] D [socket.c:3867:socket_init] 0-socket.management: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.066984] D [socket.c:3938:socket_init] 0-socket.management: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.066992] D [socket.c:3941:socket_init] 0-socket.management: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.066999] D [socket.c:3958:socket_init] 0-socket.management: using system polling thread
[2015-06-03 09:00:02.067013] D [name.c:550:server_fill_address_family] 0-socket.management: option address-family not specified, defaulting to inet
[2015-06-03 09:00:02.067122] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/rdma.so
[2015-06-03 09:00:02.067179] E [rpc-transport.c:291:rpc_transport_load] 0-rpc-transport: /usr/lib64/glusterfs/3.7.1/rpc-transport/rdma.so: impossibile aprire il file oggetto condiviso: File o directory non esistente
[2015-06-03 09:00:02.067190] W [rpc-transport.c:295:rpc_transport_load] 0-rpc-transport: volume 'rdma.management': transport-type 'rdma' is not valid or not found on this machine
[2015-06-03 09:00:02.067198] W [rpcsvc.c:1595:rpcsvc_transport_create] 0-rpc-service: cannot create listener, initing the transport failed
[2015-06-03 09:00:02.067207] E [glusterd.c:1515:init] 0-management: creation of 1 listeners failed, continuing with succeeded transport
[2015-06-03 09:00:02.067215] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GlusterD svc peer, Num: 1238437, Ver: 2, Port: 0
[2015-06-03 09:00:02.067224] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GlusterD svc cli read-only, Num: 1238463, Ver: 2, Port: 0
[2015-06-03 09:00:02.067231] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GlusterD svc mgmt, Num: 1238433, Ver: 2, Port: 0
[2015-06-03 09:00:02.067238] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GlusterD svc mgmt v3, Num: 1238433, Ver: 3, Port: 0
[2015-06-03 09:00:02.067245] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: Gluster Portmap, Num: 34123456, Ver: 1, Port: 0
[2015-06-03 09:00:02.067252] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: Gluster Handshake, Num: 14398633, Ver: 2, Port: 0
[2015-06-03 09:00:02.067259] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: Gluster MGMT Handshake, Num: 1239873, Ver: 1, Port: 0
[2015-06-03 09:00:02.067326] D [rpcsvc.c:2315:rpcsvc_init] 0-rpc-service: RPC service inited.
[2015-06-03 09:00:02.067336] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GF-DUMP, Num: 123451501, Ver: 1, Port: 0
[2015-06-03 09:00:02.067356] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.067424] D [socket.c:3816:socket_init] 0-socket.management: disabling nodelay
[2015-06-03 09:00:02.067435] D [socket.c:3867:socket_init] 0-socket.management: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.067443] D [socket.c:3938:socket_init] 0-socket.management: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.067449] D [socket.c:3941:socket_init] 0-socket.management: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.067456] D [socket.c:3958:socket_init] 0-socket.management: using system polling thread
[2015-06-03 09:00:02.067768] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: GlusterD svc cli, Num: 1238463, Ver: 2, Port: 0
[2015-06-03 09:00:02.067785] D [rpcsvc.c:1872:rpcsvc_program_register] 0-rpc-service: New program registered: Gluster Handshake (CLI Getspec), Num: 14398633, Ver: 2, Port: 0
[2015-06-03 09:00:02.067854] D [glusterd-utils.c:5763:glusterd_sm_tr_log_init] 0-: returning 0
[2015-06-03 09:00:02.067869] D [glusterd.c:1582:init] 0-management: cannot get run-with-valgrind value
[2015-06-03 09:00:02.069737] I [glusterd.c:413:glusterd_check_gsync_present] 0-glusterd: geo-replication module not installed in the system
[2015-06-03 09:00:02.069799] D [glusterd.c:446:glusterd_check_gsync_present] 0-glusterd: Returning -1
[2015-06-03 09:00:02.070953] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.070996] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.071095] D [store.c:304:gf_store_retrieve_value] 0-: key operating-version found
[2015-06-03 09:00:02.071136] I [glusterd-store.c:1986:glusterd_restore_op_version] 0-glusterd: retrieved op-version: 30700
[2015-06-03 09:00:02.071237] D [store.c:304:gf_store_retrieve_value] 0-: key UUID found
[2015-06-03 09:00:02.071283] D [glusterd-store.c:2055:glusterd_retrieve_uuid] 0-: Returning 0
[2015-06-03 09:00:02.071298] I [glusterd.c:154:glusterd_uuid_init] 0-management: retrieved UUID: c1920745-99ec-49a7-b26d-89de1dfb8266
[2015-06-03 09:00:02.071411] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-glustershd: setting frame-timeout to 600
[2015-06-03 09:00:02.071421] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-glustershd: disable ping-timeout
[2015-06-03 09:00:02.071435] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.071553] D [socket.c:3816:socket_init] 0-glustershd: disabling nodelay
[2015-06-03 09:00:02.071564] D [socket.c:3867:socket_init] 0-glustershd: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.071573] D [socket.c:3938:socket_init] 0-glustershd: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.071579] D [socket.c:3941:socket_init] 0-glustershd: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.071586] D [socket.c:3958:socket_init] 0-glustershd: using system polling thread
[2015-06-03 09:00:02.071656] D [MSGID: 0] [glusterd-svc-mgmt.c:116:glusterd_svc_init_common] 0-management: Returning 0
[2015-06-03 09:00:02.071672] D [glusterd.c:1204:glusterd_svc_init_all] 0-management: shd service initialized
[2015-06-03 09:00:02.071743] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-nfs: setting frame-timeout to 600
[2015-06-03 09:00:02.071752] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-nfs: disable ping-timeout
[2015-06-03 09:00:02.071760] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.071828] D [socket.c:3816:socket_init] 0-nfs: disabling nodelay
[2015-06-03 09:00:02.071839] D [socket.c:3867:socket_init] 0-nfs: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.071847] D [socket.c:3938:socket_init] 0-nfs: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.071853] D [socket.c:3941:socket_init] 0-nfs: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.071860] D [socket.c:3958:socket_init] 0-nfs: using system polling thread
[2015-06-03 09:00:02.071937] D [glusterd.c:1212:glusterd_svc_init_all] 0-management: nfs service initialized
[2015-06-03 09:00:02.071992] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-quotad: setting frame-timeout to 600
[2015-06-03 09:00:02.072001] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-quotad: disable ping-timeout
[2015-06-03 09:00:02.072021] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.072098] D [socket.c:3816:socket_init] 0-quotad: disabling nodelay
[2015-06-03 09:00:02.072112] D [socket.c:3867:socket_init] 0-quotad: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.072120] D [socket.c:3938:socket_init] 0-quotad: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.072126] D [socket.c:3941:socket_init] 0-quotad: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.072132] D [socket.c:3958:socket_init] 0-quotad: using system polling thread
[2015-06-03 09:00:02.072231] D [glusterd.c:1221:glusterd_svc_init_all] 0-management: quotad service initialized
[2015-06-03 09:00:02.072322] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-bitd: setting frame-timeout to 600
[2015-06-03 09:00:02.072331] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-bitd: disable ping-timeout
[2015-06-03 09:00:02.072353] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.072414] D [socket.c:3816:socket_init] 0-bitd: disabling nodelay
[2015-06-03 09:00:02.072422] D [socket.c:3867:socket_init] 0-bitd: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.072430] D [socket.c:3938:socket_init] 0-bitd: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.072436] D [socket.c:3941:socket_init] 0-bitd: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.072442] D [socket.c:3958:socket_init] 0-bitd: using system polling thread
[2015-06-03 09:00:02.072508] D [glusterd.c:1230:glusterd_svc_init_all] 0-management: BitD service initialized
[2015-06-03 09:00:02.072611] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-scrub: setting frame-timeout to 600
[2015-06-03 09:00:02.072621] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-scrub: disable ping-timeout
[2015-06-03 09:00:02.072630] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.072705] D [socket.c:3816:socket_init] 0-scrub: disabling nodelay
[2015-06-03 09:00:02.072713] D [socket.c:3867:socket_init] 0-scrub: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.072721] D [socket.c:3938:socket_init] 0-scrub: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.072727] D [socket.c:3941:socket_init] 0-scrub: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.072733] D [socket.c:3958:socket_init] 0-scrub: using system polling thread
[2015-06-03 09:00:02.072822] D [glusterd.c:1238:glusterd_svc_init_all] 0-management: scrub service initialized
[2015-06-03 09:00:02.073273] D [glusterd-utils.c:519:glusterd_volinfo_new] 0-management: Returning 0
[2015-06-03 09:00:02.073366] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-snapd: setting frame-timeout to 600
[2015-06-03 09:00:02.073402] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-snapd: disable ping-timeout
[2015-06-03 09:00:02.073412] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.073704] D [socket.c:3816:socket_init] 0-snapd: disabling nodelay
[2015-06-03 09:00:02.073732] D [socket.c:3867:socket_init] 0-snapd: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:02.073741] D [socket.c:3938:socket_init] 0-snapd: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.073747] D [socket.c:3941:socket_init] 0-snapd: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.073753] D [socket.c:3958:socket_init] 0-snapd: using system polling thread
[2015-06-03 09:00:02.073786] D [glusterd-snapd-svc.c:112:glusterd_snapdsvc_init] 0-management: Returning 0
[2015-06-03 09:00:02.074677] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.074694] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.074714] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.074773] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074782] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = type value = 2
[2015-06-03 09:00:02.074793] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074799] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = count value = 4
[2015-06-03 09:00:02.074821] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074828] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = status value = 1
[2015-06-03 09:00:02.074837] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074842] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = sub_count value = 2
[2015-06-03 09:00:02.074851] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074857] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = stripe_count value = 1
[2015-06-03 09:00:02.074866] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074871] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = replica_count value = 2
[2015-06-03 09:00:02.074880] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074885] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = disperse_count value = 0
[2015-06-03 09:00:02.074894] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074900] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = redundancy_count value = 0
[2015-06-03 09:00:02.074908] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074914] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = version value = 3
[2015-06-03 09:00:02.074922] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074928] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = transport-type value = 0
[2015-06-03 09:00:02.074936] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074942] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = volume-id value = 55cf62a0-099f-4a5e-ae4a-0ddec29239b4
[2015-06-03 09:00:02.074954] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074959] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = username value = 665df14d-1e1e-440e-ab5b-080702e36282
[2015-06-03 09:00:02.074970] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074976] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = password value = f3b78a26-3262-49b5-aad8-f07097cd5383
[2015-06-03 09:00:02.074985] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.074991] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = op-version value = 3
[2015-06-03 09:00:02.075002] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075008] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = client-op-version value = 3
[2015-06-03 09:00:02.075017] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075023] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = parent_volname value = N/A
[2015-06-03 09:00:02.075034] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075039] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = restored_from_snap value = 00000000-0000-0000-0000-000000000000
[2015-06-03 09:00:02.075050] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075056] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = snap-max-hard-limit value = 256
[2015-06-03 09:00:02.075066] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075071] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = performance.readdir-ahead value = on
[2015-06-03 09:00:02.075119] D [glusterd-store.c:2634:glusterd_store_update_volinfo] 0-: Parsed as Volume-set:key=performance.readdir-ahead,value:on
[2015-06-03 09:00:02.075132] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075138] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = brick-0 value = 46.101.160.245:-opt-gluster_brick1
[2015-06-03 09:00:02.075148] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075154] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = brick-1 value = 46.101.184.191:-opt-gluster_brick2
[2015-06-03 09:00:02.075164] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075170] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = brick-2 value = 46.101.160.245:-opt-gluster_brick2
[2015-06-03 09:00:02.075179] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075185] D [glusterd-store.c:2485:glusterd_store_update_volinfo] 0-: key = brick-3 value = 46.101.184.191:-opt-gluster_brick1
[2015-06-03 09:00:02.075195] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.075237] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.075265] D [glusterd-utils.c:811:glusterd_brickinfo_new] 0-management: Returning 0
[2015-06-03 09:00:02.075285] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075293] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075301] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075308] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075315] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075322] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075329] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075337] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075344] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075454] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075465] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075472] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075479] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075486] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075493] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075500] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075508] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075516] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075523] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075552] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.075976] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.075992] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.076011] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.076038] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.076049] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.076058] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283426] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283484] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283495] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283507] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283516] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.283541] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.283590] D [glusterd-utils.c:811:glusterd_brickinfo_new] 0-management: Returning 0
[2015-06-03 09:00:02.283608] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284376] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.284393] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.284449] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.284482] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284493] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284502] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284511] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284519] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284547] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284557] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284566] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.284574] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.284612] D [glusterd-utils.c:811:glusterd_brickinfo_new] 0-management: Returning 0
[2015-06-03 09:00:02.284627] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285410] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.285449] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.285513] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.285580] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285594] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285604] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285617] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285625] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285633] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285642] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285651] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.285659] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.285710] D [glusterd-utils.c:811:glusterd_brickinfo_new] 0-management: Returning 0
[2015-06-03 09:00:02.285727] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286241] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.286257] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.286275] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.286304] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286314] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286323] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286331] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286339] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286347] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286354] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286362] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.286370] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.286397] D [glusterd-store.c:2325:glusterd_store_retrieve_bricks] 0-: Returning with 0
[2015-06-03 09:00:02.286791] D [glusterd-utils.c:1964:glusterd_volume_compute_cksum] 0-management: Returning with 0
[2015-06-03 09:00:02.288137] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.288257] D [glusterd-store.c:4231:glusterd_store_retrieve_quota_version] 0-management: Version absent
[2015-06-03 09:00:02.288276] D [store.c:458:gf_store_handle_destroy] 0-: Returning 0
[2015-06-03 09:00:02.289227] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.289315] D [glusterd-utils.c:1964:glusterd_volume_compute_cksum] 0-management: Returning with 0
[2015-06-03 09:00:02.290142] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.290267] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:02.290312] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:02.292641] D [store.c:458:gf_store_handle_destroy] 0-: Returning 0
[2015-06-03 09:00:02.298438] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.298668] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.298728] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.298820] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.298853] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.298866] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.298883] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.298911] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.298971] D [glusterd-store.c:2968:glusterd_store_retrieve_volumes] 0-: Returning with 0
[2015-06-03 09:00:02.299999] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.300029] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.300052] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.300124] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.300152] D [glusterd-utils.c:5763:glusterd_sm_tr_log_init] 0-: returning 0
[2015-06-03 09:00:02.300193] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.300206] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.300226] D [glusterd-peer-utils.c:454:glusterd_peer_hostname_new] 0-glusterd: Returning 0
[2015-06-03 09:00:02.300242] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.300291] I [glusterd-handler.c:3387:glusterd_friend_add_from_peerinfo] 0-management: connect returned 0
[2015-06-03 09:00:02.300416] D [glusterd-handler.c:3220:glusterd_transport_inet_options_build] 0-glusterd: Returning 0
[2015-06-03 09:00:02.300449] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-management: setting frame-timeout to 600
[2015-06-03 09:00:02.300461] D [rpc-clnt.c:984:rpc_clnt_connection_init] 0-management: setting ping-timeout to 30
[2015-06-03 09:00:02.300476] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:02.300771] D [socket.c:3867:socket_init] 0-management: Configued transport.tcp-user-timeout=-1
[2015-06-03 09:00:02.300796] D [socket.c:3938:socket_init] 0-management: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:02.300805] D [socket.c:3941:socket_init] 0-management: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:02.300816] D [socket.c:3958:socket_init] 0-management: using system polling thread
[2015-06-03 09:00:02.306391] D [common-utils.c:334:gf_resolve_ip6] 0-resolver: returning ip-46.101.184.191 (port-24007) for hostname: 46.101.184.191 and port: 24007
[2015-06-03 09:00:02.306410] D [socket.c:2883:socket_fix_ssl_opts] 0-management: disabling SSL for portmapper connection
[2015-06-03 09:00:02.306460] W [socket.c:923:__socket_keepalive] 0-socket: failed to set TCP_USER_TIMEOUT -1000 on socket 11, Argomento non valido
[2015-06-03 09:00:02.306472] E [socket.c:3015:socket_connect] 0-management: Failed to set keep-alive: Argomento non valido
[2015-06-03 09:00:02.306574] D [glusterd-handler.c:3153:glusterd_rpc_create] 0-management: returning 0
[2015-06-03 09:00:02.306591] D [glusterd-store.c:3986:glusterd_store_retrieve_peers] 0-: Returning with 0
[2015-06-03 09:00:02.306676] D [glusterd-store.c:3386:glusterd_store_retrieve_missed_snaps_list] 0-management: EOF for missed_snap_list
[2015-06-03 09:00:02.306691] D [glusterd-store.c:3487:glusterd_store_retrieve_snaps] 0-: Returning with 0
[2015-06-03 09:00:02.306786] D [glusterd-peer-utils.c:129:glusterd_peerinfo_find_by_hostname] 0-management: Unable to find friend: 46.101.160.245
[2015-06-03 09:00:02.306816] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.306914] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.306940] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:02.306949] D [glusterd-utils.c:851:glusterd_resolve_brick] 0-management: Returning 0
[2015-06-03 09:00:02.306957] D [glusterd-peer-utils.c:636:gd_peerinfo_find_from_hostname] 0-management: Friend 46.101.184.191 found.. state: 3
[2015-06-03 09:00:02.306965] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:02.306971] D [glusterd-utils.c:851:glusterd_resolve_brick] 0-management: Returning 0
[2015-06-03 09:00:02.307037] D [glusterd-peer-utils.c:129:glusterd_peerinfo_find_by_hostname] 0-management: Unable to find friend: 46.101.160.245
[2015-06-03 09:00:02.307061] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.307101] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.307110] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:02.307117] D [glusterd-utils.c:851:glusterd_resolve_brick] 0-management: Returning 0
[2015-06-03 09:00:02.307123] D [glusterd-peer-utils.c:636:gd_peerinfo_find_from_hostname] 0-management: Friend 46.101.184.191 found.. state: 3
[2015-06-03 09:00:02.307131] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:02.307137] D [glusterd-utils.c:851:glusterd_resolve_brick] 0-management: Returning 0
[2015-06-03 09:00:02.307146] D [glusterd-store.c:4196:glusterd_restore] 0-: Returning 0
[2015-06-03 09:00:02.308029] D [store.c:418:gf_store_handle_new] 0-: Returning 0
[2015-06-03 09:00:02.308108] D [store.c:437:gf_store_handle_retrieve] 0-: Returning 0
[2015-06-03 09:00:02.308125] D [store.c:499:gf_store_iter_new] 0-: Returning with 0
[2015-06-03 09:00:02.308161] D [store.c:608:gf_store_iter_get_next] 0-: Returning with 0
[2015-06-03 09:00:02.308174] D [store.c:608:gf_store_iter_get_next] 0-: Returning with -1
[2015-06-03 09:00:02.308196] D [store.c:458:gf_store_handle_destroy] 0-: Returning 0
Final graph:
+------------------------------------------------------------------------------+
  1: volume management
  2:     type mgmt/glusterd
  3:     option rpc-auth.auth-glusterfs on
  4:     option rpc-auth.auth-unix on
  5:     option rpc-auth.auth-null on
  6:     option transport.socket.listen-backlog 128
  7:     option ping-timeout 30
  8:     option transport.socket.read-fail-log off
  9:     option transport.socket.keepalive-interval 2
 10:     option transport.socket.keepalive-time 10
 11:     option transport-type rdma
 12:     option working-directory /var/lib/glusterd
 13: end-volume
 14:
+------------------------------------------------------------------------------+
[2015-06-03 09:00:02.308629] I [event-epoll.c:629:event_dispatch_epoll_worker] 0-epoll: Started thread with index 1
[2015-06-03 09:00:02.308710] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.308722] D [glusterd-handler.c:4793:__glusterd_peer_rpc_notify] 0-management: got RPC_CLNT_CONNECT
[2015-06-03 09:00:02.308733] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.309594] D [rpc-clnt-ping.c:94:__rpc_clnt_remove_ping_timer] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x186)[0x7f3dbbec9ee6] (--> /lib64/libgfrpc.so.0(+0x12dac)[0x7f3dbbc9cdac] (--> /lib64/libgfrpc.so.0(+0x133c4)[0x7f3dbbc9d3c4] (--> /lib64/libgfrpc.so.0(rpc_clnt_submit+0x34f)[0x7f3dbbc9955f] (--> /usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_submit_request_unlocked+0x166)[0x7f3db0d4df86] ))))) 0-: 46.101.184.191:24007: ping timer event already removed
[2015-06-03 09:00:02.309974] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.310002] D [glusterd-handshake.c:2024:__glusterd_peer_dump_version_cbk] 0-management: Proceeding to op-version handshake with peer 46.101.184.191
[2015-06-03 09:00:02.310022] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.310714] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.310746] D [glusterd-handshake.c:1602:gd_validate_peer_op_version] 0-management: Peer 46.101.184.191 accepted
[2015-06-03 09:00:02.320401] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.320427] D [glusterd-peer-utils.c:977:glusterd_peerinfo_find_by_generation] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.320437] D [glusterd-sm.c:1104:glusterd_friend_sm_inject_event] 0-glusterd: Enqueue event: 'GD_FRIEND_EVENT_CONNECTED'
[2015-06-03 09:00:02.320445] D [glusterd-handshake.c:1555:glusterd_event_connected_inject] 0-: returning 0
[2015-06-03 09:00:02.320484] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.320494] D [glusterd-sm.c:1195:glusterd_friend_sm] 0-: Dequeued event of type: 'GD_FRIEND_EVENT_CONNECTED'
[2015-06-03 09:00:02.320502] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.320521] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.320759] D [glusterd-utils.c:2409:glusterd_add_volume_to_dict] 0-management: Returning with 0
[2015-06-03 09:00:02.321329] D [glusterd-rpc-ops.c:1511:glusterd_rpc_friend_add] 0-glusterd: Returning 0
[2015-06-03 09:00:02.321346] D [glusterd-sm.c:321:glusterd_ac_friend_add] 0-: Returning with 0
[2015-06-03 09:00:02.321355] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.321362] D [glusterd-utils.c:5812:glusterd_sm_tr_log_transition_add] 0-management: Transitioning from 'Peer in Cluster' to 'Peer in Cluster' due to event 'GD_FRIEND_EVENT_CONNECTED'
[2015-06-03 09:00:02.321387] D [glusterd-utils.c:5814:glusterd_sm_tr_log_transition_add] 0-management: returning 0
[2015-06-03 09:00:02.321394] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:02.321408] D [glusterd-store.c:3673:glusterd_store_create_peer_dir] 0-: Returning with 0
[2015-06-03 09:00:02.321506] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:02.321561] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:02.321608] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:02.321619] D [glusterd-store.c:3802:glusterd_store_peer_write] 0-: Returning with 0
[2015-06-03 09:00:02.326209] D [glusterd-store.c:3828:glusterd_store_perform_peer_store] 0-: Returning 0
[2015-06-03 09:00:02.326236] D [glusterd-store.c:3849:glusterd_store_peerinfo] 0-: Returning with 0
[2015-06-03 09:00:02.679857] D [glusterd-handshake.c:404:glusterd_get_args_from_dict] 0-management: brick_name = /opt/gluster_brick1
[2015-06-03 09:00:02.679903] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning -1
[2015-06-03 09:00:02.679971] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.680051] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.680101] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning -1
[2015-06-03 09:00:02.680115] D [glusterd-utils.c:1347:glusterd_volinfo_find] 0-management: Volume livebackup found
[2015-06-03 09:00:02.680125] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning 0
[2015-06-03 09:00:02.680171] D [glusterd-handshake.c:812:__server_getspec] 0-management: Look for missing snap creates for /opt/gluster_brick1
[2015-06-03 09:00:02.680279] I [glusterd-pmap.c:227:pmap_registry_bind] 0-pmap: adding brick /opt/gluster_brick1 on port 49152
[2015-06-03 09:00:02.680334] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.680399] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.744673] D [glusterd-handshake.c:404:glusterd_get_args_from_dict] 0-management: brick_name = /opt/gluster_brick2
[2015-06-03 09:00:02.744718] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning -1
[2015-06-03 09:00:02.744809] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.744926] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.744951] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning -1
[2015-06-03 09:00:02.744964] D [glusterd-utils.c:1347:glusterd_volinfo_find] 0-management: Volume livebackup found
[2015-06-03 09:00:02.744975] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning 0
[2015-06-03 09:00:02.745022] D [glusterd-handshake.c:812:__server_getspec] 0-management: Look for missing snap creates for /opt/gluster_brick2
[2015-06-03 09:00:02.745111] I [glusterd-pmap.c:227:pmap_registry_bind] 0-pmap: adding brick /opt/gluster_brick2 on port 49153
[2015-06-03 09:00:02.745161] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.745222] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:02.745259] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.184.191
[2015-06-03 09:00:02.745440] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.184.191
[2015-06-03 09:00:02.745519] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.184.191
[2015-06-03 09:00:02.745618] D [common-utils.c:3132:gf_is_local_addr] 0-management: 46.101.184.191 is not local
[2015-06-03 09:00:02.745657] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:02.745710] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:03.033312] D [glusterd-handshake.c:399:glusterd_get_args_from_dict] 0-management: No brick name present
[2015-06-03 09:00:03.033350] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning -1
[2015-06-03 09:00:03.033415] D [common-utils.c:3116:gf_is_local_addr] 0-management: 127.0.0.1
[2015-06-03 09:00:03.471836] D [glusterd-handshake.c:399:glusterd_get_args_from_dict] 0-management: No brick name present
[2015-06-03 09:00:03.471875] D [glusterd-utils.c:1347:glusterd_volinfo_find] 0-management: Volume livebackup found
[2015-06-03 09:00:03.471884] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning 0
[2015-06-03 09:00:03.471934] D [common-utils.c:3116:gf_is_local_addr] 0-management: 127.0.0.1
[2015-06-03 09:00:03.471948] D [glusterd-utils.c:1347:glusterd_volinfo_find] 0-management: Volume livebackup found
[2015-06-03 09:00:03.471956] D [glusterd-utils.c:1354:glusterd_volinfo_find] 0-management: Returning 0
[2015-06-03 09:00:03.510791] I [glusterd-rpc-ops.c:464:__glusterd_friend_add_cbk] 0-glusterd: Received ACC from uuid: 9b66f64b-0c2b-49c7-8de9-e6b7ce3594d7, host: 46.101.184.191, port: 0
[2015-06-03 09:00:03.510838] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.510855] D [glusterd-sm.c:1104:glusterd_friend_sm_inject_event] 0-glusterd: Enqueue event: 'GD_FRIEND_EVENT_RCVD_ACC'
[2015-06-03 09:00:03.510867] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.510877] D [glusterd-sm.c:1195:glusterd_friend_sm] 0-: Dequeued event of type: 'GD_FRIEND_EVENT_RCVD_ACC'
[2015-06-03 09:00:03.510887] D [glusterd-sm.c:198:glusterd_ac_none] 0-: Returning with 0
[2015-06-03 09:00:03.510896] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.510905] D [glusterd-utils.c:5812:glusterd_sm_tr_log_transition_add] 0-management: Transitioning from 'Peer in Cluster' to 'Peer in Cluster' due to event 'GD_FRIEND_EVENT_RCVD_ACC'
[2015-06-03 09:00:03.510916] D [glusterd-utils.c:5814:glusterd_sm_tr_log_transition_add] 0-management: returning 0
[2015-06-03 09:00:03.510925] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.510949] D [glusterd-store.c:3673:glusterd_store_create_peer_dir] 0-: Returning with 0
[2015-06-03 09:00:03.511091] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:03.511143] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:03.511175] D [store.c:372:gf_store_save_value] 0-: returning: 0
[2015-06-03 09:00:03.511187] D [glusterd-store.c:3802:glusterd_store_peer_write] 0-: Returning with 0
[2015-06-03 09:00:03.514908] D [glusterd-store.c:3828:glusterd_store_perform_peer_store] 0-: Returning 0
[2015-06-03 09:00:03.514932] D [glusterd-store.c:3849:glusterd_store_peerinfo] 0-: Returning with 0
[2015-06-03 09:00:03.522175] D [glusterd-utils.c:172:glusterd_lock] 0-management: Cluster lock held by c1920745-99ec-49a7-b26d-89de1dfb8266
[2015-06-03 09:00:03.522272] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.522286] I [glusterd-handler.c:2587:__glusterd_handle_friend_update] 0-glusterd: Received friend update from uuid: 9b66f64b-0c2b-49c7-8de9-e6b7ce3594d7
[2015-06-03 09:00:03.522315] I [glusterd-handler.c:2630:__glusterd_handle_friend_update] 0-management: Received my uuid as Friend
[2015-06-03 09:00:03.522402] D [glusterd-peer-utils.c:196:glusterd_peerinfo_find_by_uuid] 0-management: Friend found... state: Peer in Cluster
[2015-06-03 09:00:03.522849] D [glusterd-peer-utils.c:129:glusterd_peerinfo_find_by_hostname] 0-management: Unable to find friend: 46.101.160.245
[2015-06-03 09:00:03.522887] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:03.522950] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:03.522961] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:03.522969] D [glusterd-utils.c:1249:glusterd_volume_brickinfo_get] 0-management: Found brick 46.101.160.245:/opt/gluster_brick1 in volume livebackup
[2015-06-03 09:00:03.522976] D [glusterd-utils.c:1258:glusterd_volume_brickinfo_get] 0-management: Returning 0
[2015-06-03 09:00:03.522985] D [glusterd-peer-utils.c:636:gd_peerinfo_find_from_hostname] 0-management: Friend 46.101.184.191 found.. state: 3
[2015-06-03 09:00:03.522992] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:03.522999] D [glusterd-utils.c:1249:glusterd_volume_brickinfo_get] 0-management: Found brick 46.101.184.191:/opt/gluster_brick2 in volume livebackup
[2015-06-03 09:00:03.523006] D [glusterd-utils.c:1258:glusterd_volume_brickinfo_get] 0-management: Returning 0
[2015-06-03 09:00:03.523069] D [glusterd-peer-utils.c:129:glusterd_peerinfo_find_by_hostname] 0-management: Unable to find friend: 46.101.160.245
[2015-06-03 09:00:03.523129] D [common-utils.c:3116:gf_is_local_addr] 0-management: 46.101.160.245
[2015-06-03 09:00:03.523170] D [common-utils.c:3013:gf_interface_search] 0-management: 46.101.160.245 is local address at interface eth0
[2015-06-03 09:00:03.523180] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:03.523187] D [glusterd-utils.c:1249:glusterd_volume_brickinfo_get] 0-management: Found brick 46.101.160.245:/opt/gluster_brick2 in volume livebackup
[2015-06-03 09:00:03.523194] D [glusterd-utils.c:1258:glusterd_volume_brickinfo_get] 0-management: Returning 0
[2015-06-03 09:00:03.523203] D [glusterd-peer-utils.c:636:gd_peerinfo_find_from_hostname] 0-management: Friend 46.101.184.191 found.. state: 3
[2015-06-03 09:00:03.523210] D [glusterd-peer-utils.c:164:glusterd_hostname_to_uuid] 0-management: returning 0
[2015-06-03 09:00:03.523217] D [glusterd-utils.c:1249:glusterd_volume_brickinfo_get] 0-management: Found brick 46.101.184.191:/opt/gluster_brick1 in volume livebackup
[2015-06-03 09:00:03.523224] D [glusterd-utils.c:1258:glusterd_volume_brickinfo_get] 0-management: Returning 0
[2015-06-03 09:00:03.523481] D [glusterd-volgen.c:852:_xl_link_children] 0-management: nfs-server:livebackup
[2015-06-03 09:00:03.523521] D [glusterd-volgen.c:4353:build_nfs_graph] 0-glusterd: Returning 0
[2015-06-03 09:00:03.523893] I [MSGID: 106132] [glusterd-proc-mgmt.c:83:glusterd_proc_stop] 0-management: nfs already stopped
[2015-06-03 09:00:03.523960] D [MSGID: 0] [glusterd-svc-mgmt.c:238:glusterd_svc_stop] 0-management: Returning 0
[2015-06-03 09:00:03.523971] D [glusterd-nfs-svc.c:218:glusterd_nfssvc_stop] 0-management: Returning 0
[2015-06-03 09:00:03.524027] D [MSGID: 0] [glusterd-svc-mgmt.c:206:glusterd_svc_start] 0-management: Starting nfs service
[2015-06-03 09:00:03.581753] D [MSGID: 0] [glusterd-svc-mgmt.c:219:glusterd_svc_start] 0-management: Returning 0
[2015-06-03 09:00:03.581858] W [socket.c:3059:socket_connect] 0-nfs: Ignore failed connection attempt on , (File o directory non esistente)
[2015-06-03 09:00:03.581893] D [glusterd-nfs-svc.c:188:glusterd_nfssvc_manager] 0-management: Returning 0
[2015-06-03 09:00:03.582044] D [glusterd-volgen.c:852:_xl_link_children] 0-management: glustershd:livebackup-replicate-0
[2015-06-03 09:00:03.582055] D [glusterd-volgen.c:852:_xl_link_children] 0-management: glustershd:livebackup-replicate-1
[2015-06-03 09:00:03.582492] D [glusterd-shd-svc.c:71:glusterd_shdsvc_create_volfile] 0-management: Returning 0
[2015-06-03 09:00:03.582599] D [MSGID: 0] [glusterd-proc-mgmt.c:87:glusterd_proc_stop] 0-management: Stopping glustershd daemon running in pid: 19156
[2015-06-03 09:00:04.583027] D [MSGID: 0] [glusterd-svc-mgmt.c:238:glusterd_svc_stop] 0-management: Returning 0
[2015-06-03 09:00:04.583176] D [MSGID: 0] [glusterd-svc-mgmt.c:206:glusterd_svc_start] 0-management: Starting glustershd service
[2015-06-03 09:00:04.604103] D [MSGID: 0] [glusterd-svc-mgmt.c:219:glusterd_svc_start] 0-management: Returning 0
[2015-06-03 09:00:04.604156] D [glusterd-shd-svc.c:157:glusterd_shdsvc_start] 0-management: Returning 0
[2015-06-03 09:00:04.604226] W [socket.c:3059:socket_connect] 0-glustershd: Ignore failed connection attempt on , (File o directory non esistente)
[2015-06-03 09:00:04.604251] D [glusterd-shd-svc.c:119:glusterd_shdsvc_manager] 0-management: Returning 0
[2015-06-03 09:00:04.604294] D [glusterd-quotad-svc.c:97:glusterd_quotadsvc_manager] 0-management: Returning 0
[2015-06-03 09:00:04.604341] I [MSGID: 106132] [glusterd-proc-mgmt.c:83:glusterd_proc_stop] 0-management: bitd already stopped
[2015-06-03 09:00:04.604368] D [MSGID: 0] [glusterd-svc-mgmt.c:238:glusterd_svc_stop] 0-management: Returning 0
[2015-06-03 09:00:04.604377] D [glusterd-bitd-svc.c:87:glusterd_bitdsvc_manager] 0-management: Returning 0
[2015-06-03 09:00:04.604406] I [MSGID: 106132] [glusterd-proc-mgmt.c:83:glusterd_proc_stop] 0-management: scrub already stopped
[2015-06-03 09:00:04.604430] D [MSGID: 0] [glusterd-svc-mgmt.c:238:glusterd_svc_stop] 0-management: Returning 0
[2015-06-03 09:00:04.604439] D [glusterd-scrub-svc.c:83:glusterd_scrubsvc_manager] 0-management: Returning 0
[2015-06-03 09:00:04.604446] D [glusterd-utils.c:4412:glusterd_restart_bricks] 0-management: starting the volume livebackup
[2015-06-03 09:00:04.604573] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-management: setting frame-timeout to 600
[2015-06-03 09:00:04.604585] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-management: disable ping-timeout
[2015-06-03 09:00:04.604598] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:04.604685] D [socket.c:3816:socket_init] 0-management: disabling nodelay
[2015-06-03 09:00:04.604694] D [socket.c:3867:socket_init] 0-management: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:04.604703] D [socket.c:3938:socket_init] 0-management: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:04.604709] D [socket.c:3941:socket_init] 0-management: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:04.604715] D [socket.c:3958:socket_init] 0-management: using system polling thread
[2015-06-03 09:00:04.604763] D [glusterd-handler.c:3153:glusterd_rpc_create] 0-management: returning 0
[2015-06-03 09:00:04.604774] D [glusterd-utils.c:1493:glusterd_brick_connect] 0-: Returning 0
[2015-06-03 09:00:04.604782] D [glusterd-utils.c:4387:glusterd_brick_start] 0-management: returning 0
[2015-06-03 09:00:04.604788] D [glusterd-utils.c:4387:glusterd_brick_start] 0-management: returning 0
[2015-06-03 09:00:04.604853] I [rpc-clnt.c:972:rpc_clnt_connection_init] 0-management: setting frame-timeout to 600
[2015-06-03 09:00:04.604862] D [rpc-clnt.c:989:rpc_clnt_connection_init] 0-management: disable ping-timeout
[2015-06-03 09:00:04.604874] D [rpc-transport.c:287:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.7.1/rpc-transport/socket.so
[2015-06-03 09:00:04.604941] D [socket.c:3816:socket_init] 0-management: disabling nodelay
[2015-06-03 09:00:04.604950] D [socket.c:3867:socket_init] 0-management: Configued transport.tcp-user-timeout=0
[2015-06-03 09:00:04.604958] D [socket.c:3938:socket_init] 0-management: SSL support on the I/O path is NOT enabled
[2015-06-03 09:00:04.604964] D [socket.c:3941:socket_init] 0-management: SSL support for glusterd is NOT enabled
[2015-06-03 09:00:04.604970] D [socket.c:3958:socket_init] 0-management: using system polling thread
[2015-06-03 09:00:04.605001] D [glusterd-handler.c:3153:glusterd_rpc_create] 0-management: returning 0
[2015-06-03 09:00:04.605012] D [glusterd-utils.c:1493:glusterd_brick_connect] 0-: Returning 0
[2015-06-03 09:00:04.605018] D [glusterd-utils.c:4387:glusterd_brick_start] 0-management: returning 0
[2015-06-03 09:00:04.605025] D [glusterd-utils.c:4387:glusterd_brick_start] 0-management: returning 0
*** buffer overflow detected ***: glusterd terminated
======= Backtrace: =========
/lib64/libc.so.6(__fortify_fail+0x37)[0x7f3dba994a57]
/lib64/libc.so.6(+0x10bc10)[0x7f3dba992c10]
/lib64/libc.so.6(+0x10b32b)[0x7f3dba99232b]
/lib64/libc.so.6(__snprintf_chk+0x78)[0x7f3dba992248]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_volume_defrag_restart+0x191)[0x7f3db0d5d931]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_restart_rebalance+0x82)[0x7f3db0d63aa2]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_spawn_daemons+0x4f)[0x7f3db0d63b1f]
/lib64/libglusterfs.so.0(synctask_wrap+0x12)[0x7f3dbbf05482]
/lib64/libc.so.6(+0x470f0)[0x7f3dba8ce0f0]
======= Memory map: ========
7f3d9c000000-7f3d9c021000 rw-p 00000000 00:00 0
7f3d9c021000-7f3da0000000 ---p 00000000 00:00 0
7f3da0000000-7f3da0021000 rw-p 00000000 00:00 0
7f3da0021000-7f3da4000000 ---p 00000000 00:00 0
7f3da7dff000-7f3da8000000 rw-p 00000000 00:00 0                          [stack:19299]
7f3da8000000-7f3da8021000 rw-p 00000000 00:00 0
7f3da8021000-7f3dac000000 ---p 00000000 00:00 0
7f3dac19f000-7f3dac1a0000 ---p 00000000 00:00 0
7f3dac1a0000-7f3dac9a0000 rw-p 00000000 00:00 0                          [stack:19303]
7f3dac9a0000-7f3dac9a1000 ---p 00000000 00:00 0
7f3dac9a1000-7f3dad1a1000 rw-p 00000000 00:00 0                          [stack:19302]
7f3dad1a1000-7f3dad1ac000 r-xp 00000000 fd:01 1051132                    /usr/lib64/libnss_files-2.17.so
7f3dad1ac000-7f3dad3ab000 ---p 0000b000 fd:01 1051132                    /usr/lib64/libnss_files-2.17.so
7f3dad3ab000-7f3dad3ac000 r--p 0000a000 fd:01 1051132                    /usr/lib64/libnss_files-2.17.so
7f3dad3ac000-7f3dad3ad000 rw-p 0000b000 fd:01 1051132                    /usr/lib64/libnss_files-2.17.so
7f3dad3ad000-7f3dad558000 rw-p 00000000 00:00 0
7f3dad558000-7f3dad56e000 r-xp 00000000 fd:01 1051154                    /usr/lib64/libresolv-2.17.so
7f3dad56e000-7f3dad76e000 ---p 00016000 fd:01 1051154                    /usr/lib64/libresolv-2.17.so
7f3dad76e000-7f3dad76f000 r--p 00016000 fd:01 1051154                    /usr/lib64/libresolv-2.17.so
7f3dad76f000-7f3dad770000 rw-p 00017000 fd:01 1051154                    /usr/lib64/libresolv-2.17.so
7f3dad770000-7f3dad772000 rw-p 00000000 00:00 0
7f3dad772000-7f3dad775000 r-xp 00000000 fd:01 1047227                    /usr/lib64/libkeyutils.so.1.5
7f3dad775000-7f3dad974000 ---p 00003000 fd:01 1047227                    /usr/lib64/libkeyutils.so.1.5
7f3dad974000-7f3dad975000 r--p 00002000 fd:01 1047227                    /usr/lib64/libkeyutils.so.1.5
7f3dad975000-7f3dad976000 rw-p 00003000 fd:01 1047227                    /usr/lib64/libkeyutils.so.1.5
7f3dad976000-7f3dad983000 r-xp 00000000 fd:01 1047568    [2015-06-03 09:00:04.605628] D [logging.c:1765:gf_log_flush_extra_msgs] 0-logging-infra: Log buffer size reduced. About to flush 5 extra log messages
The message "D [MSGID: 0] [glusterd-svc-mgmt.c:116:glusterd_svc_init_common] 0-management: Returning 0" repeated 4 times between [2015-06-03 09:00:02.071656] and [2015-06-03 09:00:02.072821]
[2015-06-03 09:00:04.605930] D [logging.c:1768:gf_log_flush_extra_msgs] 0-logging-infra: Just flushed 5 extra log messages
pending frames:
frame : type(0) op(0)
patchset: git://git.gluster.com/glusterfs.git
signal received: 6
time of crash:
2015-06-03 09:00:04
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.1
/lib64/libglusterfs.so.0(_gf_msg_backtrace_nomem+0xb2)[0x7f3dbbecad92]
/lib64/libglusterfs.so.0(gf_print_trace+0x32d)[0x7f3dbbee59ed]
/lib64/libc.so.6(+0x35650)[0x7f3dba8bc650]
/lib64/libc.so.6(gsignal+0x37)[0x7f3dba8bc5d7]
/lib64/libc.so.6(abort+0x148)[0x7f3dba8bdcc8]
/lib64/libc.so.6(+0x75e07)[0x7f3dba8fce07]
/lib64/libc.so.6(__fortify_fail+0x37)[0x7f3dba994a57]
/lib64/libc.so.6(+0x10bc10)[0x7f3dba992c10]
/lib64/libc.so.6(+0x10b32b)[0x7f3dba99232b]
/lib64/libc.so.6(__snprintf_chk+0x78)[0x7f3dba992248]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_volume_defrag_restart+0x191)[0x7f3db0d5d931]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_restart_rebalance+0x82)[0x7f3db0d63aa2]
/usr/lib64/glusterfs/3.7.1/xlator/mgmt/glusterd.so(glusterd_spawn_daemons+0x4f)[0x7f3db0d63b1f]
/lib64/libglusterfs.so.0(synctask_wrap+0x12)[0x7f3dbbf05482]
/lib64/libc.so.6(+0x470f0)[0x7f3dba8ce0f0]
---------
Annullato (core dumped)

Comment 1 lenz 2015-06-03 14:40:17 UTC
I can confirm that when removing all RPMs and manually installing the RPMs for 3.6.3, it works like a charm.

Comment 2 Atin Mukherjee 2015-06-04 04:29:11 UTC
Could you attach the glusterd core file?

Comment 3 Susant Kumar Palai 2015-06-04 14:23:29 UTC
Was able to reproduce the issue, but not on rebalance restart path.

On 3.7.1 rpm glusterd gets crashed upon starting rebalance.

Here is the bt.
#0  0x0000003455232625 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x0000003455233e05 in abort () at abort.c:92
#2  0x0000003455270537 in __libc_message (do_abort=2, fmt=0x34553575ef "*** %s ***: %s terminated\n")
    at ../sysdeps/unix/sysv/linux/libc_fatal.c:198
#3  0x0000003455302527 in __fortify_fail (msg=0x3455357595 "buffer overflow detected") at fortify_fail.c:32
#4  0x0000003455300410 in __chk_fail () at chk_fail.c:29
#5  0x00000034552ffb0b in ___vsnprintf_chk (s=0x64c1 <Address 0x64c1 out of bounds>, maxlen=25797, flags=6, 
    slen=18446744073709551615, format=0x0, args=0x3455291390) at vsnprintf_chk.c:39
#6  0x00000034552ff9da in ___snprintf_chk (s=<value optimized out>, maxlen=<value optimized out>, 
    flags=<value optimized out>, slen=<value optimized out>, format=<value optimized out>) at snprintf_chk.c:36
#7  0x00007f836a20a061 in snprintf (volinfo=0x7f8364008b60, op_errstr=<value optimized out>, len=140202165164256, 
    cmd=1, cbk=0, op=<value optimized out>) at /usr/include/bits/stdio2.h:65
#8  glusterd_handle_defrag_start (volinfo=0x7f8364008b60, op_errstr=<value optimized out>, len=140202165164256, 
    cmd=1, cbk=0, op=<value optimized out>) at glusterd-rebalance.c:234
#9  0x00007f836a20ac97 in glusterd_op_rebalance (dict=0x7f8372d435e4, op_errstr=0x7f835c40d420, 
    rsp_dict=<value optimized out>) at glusterd-rebalance.c:823
#10 0x00007f836a1c4e79 in glusterd_op_commit_perform (op=GD_OP_REBALANCE, dict=0x7f8372d435e4, 
    op_errstr=0x7f835c40d420, rsp_dict=0x0) at glusterd-op-sm.c:5126
#11 0x00007f836a1c6202 in glusterd_op_ac_send_commit_op (event=0x7f83581bd5b0, ctx=<value optimized out>)
    at glusterd-op-sm.c:4301
#12 0x00007f836a1c0679 in glusterd_op_sm () at glusterd-op-sm.c:6869
#13 0x00007f836a20b01b in __glusterd_handle_defrag_volume (req=0x81e59c) at glusterd-rebalance.c:515
#14 0x00007f836a19ce6f in glusterd_big_locked_handler (req=0x81e59c, 
    actor_fn=0x7f836a20ad40 <__glusterd_handle_defrag_volume>) at glusterd-handler.c:83
#15 0x00007f83744f45b2 in synctask_wrap (old_task=<value optimized out>) at syncop.c:375
#16 0x00000034552438f0 in ?? () from /lib64/libc-2.12.so
#17 0x0000000000000000 in ?? ()


From the backtrace the information for frame 7 and 8 looks wrong as they both have the same arguments. And also the "parameter" looks fishy. 

Need more investigation to see whether it is a optimization issue or something else.

Comment 4 Susant Kumar Palai 2015-06-04 14:23:45 UTC
Was able to reproduce the issue, but not on rebalance restart path.

On 3.7.1 rpm glusterd gets crashed upon starting rebalance.

Here is the bt.
#0  0x0000003455232625 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x0000003455233e05 in abort () at abort.c:92
#2  0x0000003455270537 in __libc_message (do_abort=2, fmt=0x34553575ef "*** %s ***: %s terminated\n")
    at ../sysdeps/unix/sysv/linux/libc_fatal.c:198
#3  0x0000003455302527 in __fortify_fail (msg=0x3455357595 "buffer overflow detected") at fortify_fail.c:32
#4  0x0000003455300410 in __chk_fail () at chk_fail.c:29
#5  0x00000034552ffb0b in ___vsnprintf_chk (s=0x64c1 <Address 0x64c1 out of bounds>, maxlen=25797, flags=6, 
    slen=18446744073709551615, format=0x0, args=0x3455291390) at vsnprintf_chk.c:39
#6  0x00000034552ff9da in ___snprintf_chk (s=<value optimized out>, maxlen=<value optimized out>, 
    flags=<value optimized out>, slen=<value optimized out>, format=<value optimized out>) at snprintf_chk.c:36
#7  0x00007f836a20a061 in snprintf (volinfo=0x7f8364008b60, op_errstr=<value optimized out>, len=140202165164256, 
    cmd=1, cbk=0, op=<value optimized out>) at /usr/include/bits/stdio2.h:65
#8  glusterd_handle_defrag_start (volinfo=0x7f8364008b60, op_errstr=<value optimized out>, len=140202165164256, 
    cmd=1, cbk=0, op=<value optimized out>) at glusterd-rebalance.c:234
#9  0x00007f836a20ac97 in glusterd_op_rebalance (dict=0x7f8372d435e4, op_errstr=0x7f835c40d420, 
    rsp_dict=<value optimized out>) at glusterd-rebalance.c:823
#10 0x00007f836a1c4e79 in glusterd_op_commit_perform (op=GD_OP_REBALANCE, dict=0x7f8372d435e4, 
    op_errstr=0x7f835c40d420, rsp_dict=0x0) at glusterd-op-sm.c:5126
#11 0x00007f836a1c6202 in glusterd_op_ac_send_commit_op (event=0x7f83581bd5b0, ctx=<value optimized out>)
    at glusterd-op-sm.c:4301
#12 0x00007f836a1c0679 in glusterd_op_sm () at glusterd-op-sm.c:6869
#13 0x00007f836a20b01b in __glusterd_handle_defrag_volume (req=0x81e59c) at glusterd-rebalance.c:515
#14 0x00007f836a19ce6f in glusterd_big_locked_handler (req=0x81e59c, 
    actor_fn=0x7f836a20ad40 <__glusterd_handle_defrag_volume>) at glusterd-handler.c:83
#15 0x00007f83744f45b2 in synctask_wrap (old_task=<value optimized out>) at syncop.c:375
#16 0x00000034552438f0 in ?? () from /lib64/libc-2.12.so
#17 0x0000000000000000 in ?? ()


From the backtrace the information for frame 7 and 8 looks wrong as they both have the same arguments. And also the "parameter" looks fishy. 

Need more investigation to see whether it is a optimization issue or something else.

Comment 5 Susant Kumar Palai 2015-06-04 14:41:38 UTC
Missed about the "len" parameter which is 140202165164256 and does not make sense here. Not sure, it's gdb which is giving wrong data here or actually the program received the wrong value. 

As we can see snprintf is crashing here, the only reason I can think of snprintf crashing here is "size" argument being greater than the buffer with which the target is created.

Susant~

Comment 6 Anand Avati 2015-06-04 17:18:28 UTC
REVIEW: http://review.gluster.org/11090 (glusterd: Buffer overflow causing crash for glusterd) posted (#1) for review on master by Susant Palai (spalai)

Comment 7 Anand Avati 2015-06-04 17:25:27 UTC
REVIEW: http://review.gluster.org/11091 (glusterd: Buffer overflow causing crash for glusterd) posted (#1) for review on release-3.7 by Susant Palai (spalai)

Comment 8 Anand Avati 2015-06-04 17:27:48 UTC
REVIEW: http://review.gluster.org/11090 (glusterd: Buffer overflow causing crash for glusterd) posted (#2) for review on master by Susant Palai (spalai)

Comment 9 Anand Avati 2015-06-04 17:28:09 UTC
REVIEW: http://review.gluster.org/11091 (glusterd: Buffer overflow causing crash for glusterd) posted (#2) for review on release-3.7 by Susant Palai (spalai)

Comment 10 Anand Avati 2015-06-16 06:18:06 UTC
REVIEW: http://review.gluster.org/11091 (glusterd: Buffer overflow causing crash for glusterd) posted (#3) for review on release-3.7 by Atin Mukherjee (amukherj)

Comment 11 Anand Avati 2015-06-19 01:30:54 UTC
COMMIT: http://review.gluster.org/11091 committed in release-3.7 by Vijay Bellur (vbellur) 
------
commit f56b94d85ae5063ba9eb97c6ed07fc869f0e4b53
Author: Susant Palai <spalai>
Date:   Thu Jun 4 22:37:11 2015 +0530

    glusterd: Buffer overflow causing crash for glusterd
    
    Backport of http://review.gluster.org/11090
    
    Problem: In GLUSTERD_GET_DEFRAG_PROCESS we are using PATH_MAX (4096)
    as the max size of the input for target path, but we have allocated
    NAME_MAX (255) size of buffer for the target.
    
    Now this crash is not seen with source, but seen with RPMS.
    The reason is _foritfy_fail. This check happens when _FORTIFY_SOURCE
    is enabled. This option tries to figure out possible
    overflow scenarios like the bug here and does crash the process.
    
    BUG: 1227677
    Change-Id: I50cf83cb60c640e46cc7a1a8d3a8321b9147fba9
    Signed-off-by: Susant Palai <spalai>
    Reviewed-on: http://review.gluster.org/11091
    Reviewed-by: Atin Mukherjee <amukherj>
    Tested-by: Gluster Build System <jenkins.com>
    Tested-by: NetBSD Build System <jenkins.org>

Comment 12 Niels de Vos 2015-06-20 09:49:40 UTC
This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.7.2, please reopen this bug report.

glusterfs-3.7.2 has been announced on the Gluster Packaging mailinglist [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution.

[1] http://www.gluster.org/pipermail/packaging/2015-June/000006.html
[2] http://thread.gmane.org/gmane.comp.file-systems.gluster.user

Comment 13 lenz 2019-11-07 16:06:10 UTC
Info not needed anymore.