Attachment 587108 Details for Bug 825559 – Client log

Client log

mnt-gluster-mysql1.log (text/x-log), 18.34 KB, created by Joe Julian on 2012-05-27 19:38:34 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Joe Julian

Created: 2012-05-27 19:38:34 UTC

Size: 18.34 KB

patch

obsolete

>[2012-05-27 12:12:32.895886] I [glusterfsd.c:1651:main] 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.3.0qa43
>[2012-05-27 12:12:33.004478] I [client.c:2142:notify] 0-mysql1-client-0: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.009818] I [client.c:2142:notify] 0-mysql1-client-1: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.014860] I [client.c:2142:notify] 0-mysql1-client-2: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.019933] I [client.c:2142:notify] 0-mysql1-client-3: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.024887] I [client.c:2142:notify] 0-mysql1-client-4: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.029901] I [client.c:2142:notify] 0-mysql1-client-5: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.034727] I [client.c:2142:notify] 0-mysql1-client-6: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.039575] I [client.c:2142:notify] 0-mysql1-client-7: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.045232] I [client.c:2142:notify] 0-mysql1-client-8: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.050095] I [client.c:2142:notify] 0-mysql1-client-9: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.054842] I [client.c:2142:notify] 0-mysql1-client-10: parent translators are ready, attempting connect on transport
>[2012-05-27 12:12:33.059569] I [client.c:2142:notify] 0-mysql1-client-11: parent translators are ready, attempting connect on transport
>Given volfile:
>+------------------------------------------------------------------------------+
>  1: volume mysql1-client-0
>  2:     type protocol/client
>  3:     option remote-host ewcs2
>  4:     option remote-subvolume /var/spool/glusterfs/a_mysql1
>  5:     option transport-type tcp
>  6: end-volume
>  7: 
>  8: volume mysql1-client-1
>  9:     type protocol/client
> 10:     option remote-host ewcs4
> 11:     option remote-subvolume /var/spool/glusterfs/a_mysql1
> 12:     option transport-type tcp
> 13: end-volume
> 14: 
> 15: volume mysql1-client-2
> 16:     type protocol/client
> 17:     option remote-host ewcs7
> 18:     option remote-subvolume /var/spool/glusterfs/a_mysql1
> 19:     option transport-type tcp
> 20: end-volume
> 21: 
> 22: volume mysql1-client-3
> 23:     type protocol/client
> 24:     option remote-host ewcs2
> 25:     option remote-subvolume /var/spool/glusterfs/b_mysql1
> 26:     option transport-type tcp
> 27: end-volume
> 28: 
> 29: volume mysql1-client-4
> 30:     type protocol/client
> 31:     option remote-host ewcs4
> 32:     option remote-subvolume /var/spool/glusterfs/b_mysql1
> 33:     option transport-type tcp
> 34: end-volume
> 35: 
> 36: volume mysql1-client-5
> 37:     type protocol/client
> 38:     option remote-host ewcs7
> 39:     option remote-subvolume /var/spool/glusterfs/b_mysql1
> 40:     option transport-type tcp
> 41: end-volume
> 42: 
> 43: volume mysql1-client-6
> 44:     type protocol/client
> 45:     option remote-host ewcs2
> 46:     option remote-subvolume /var/spool/glusterfs/c_mysql1
> 47:     option transport-type tcp
> 48: end-volume
> 49: 
> 50: volume mysql1-client-7
> 51:     type protocol/client
> 52:     option remote-host ewcs4
> 53:     option remote-subvolume /var/spool/glusterfs/c_mysql1
> 54:     option transport-type tcp
> 55: end-volume
> 56: 
> 57: volume mysql1-client-8
> 58:     type protocol/client
> 59:     option remote-host ewcs7
> 60:     option remote-subvolume /var/spool/glusterfs/c_mysql1
> 61:     option transport-type tcp
> 62: end-volume
> 63: 
> 64: volume mysql1-client-9
> 65:     type protocol/client
> 66:     option remote-host ewcs2
> 67:     option remote-subvolume /var/spool/glusterfs/d_mysql1
> 68:     option transport-type tcp
> 69: end-volume
> 70: 
> 71: volume mysql1-client-10
> 72:     type protocol/client
> 73:     option remote-host ewcs4
> 74:     option remote-subvolume /var/spool/glusterfs/d_mysql1
> 75:     option transport-type tcp
> 76: end-volume
> 77: 
> 78: volume mysql1-client-11
> 79:     type protocol/client
> 80:     option remote-host ewcs7
> 81:     option remote-subvolume /var/spool/glusterfs/d_mysql1
> 82:     option transport-type tcp
> 83: end-volume
> 84: 
> 85: volume mysql1-replicate-0
> 86:     type cluster/replicate
> 87:     subvolumes mysql1-client-0 mysql1-client-1 mysql1-client-2
> 88: end-volume
> 89: 
> 90: volume mysql1-replicate-1
> 91:     type cluster/replicate
> 92:     subvolumes mysql1-client-3 mysql1-client-4 mysql1-client-5
> 93: end-volume
> 94: 
> 95: volume mysql1-replicate-2
> 96:     type cluster/replicate
> 97:     subvolumes mysql1-client-6 mysql1-client-7 mysql1-client-8
> 98: end-volume
> 99: 
>100: volume mysql1-replicate-3
>101:     type cluster/replicate
>102:     subvolumes mysql1-client-9 mysql1-client-10 mysql1-client-11
>103: end-volume
>104: 
>105: volume mysql1-dht
>106:     type cluster/distribute
>107:     subvolumes mysql1-replicate-0 mysql1-replicate-1 mysql1-replicate-2 mysql1-replicate-3
>108: end-volume
>109: 
>110: volume mysql1-stat-prefetch
>111:     type performance/stat-prefetch
>112:     subvolumes mysql1-dht
>113: end-volume
>114: 
>115: volume mysql1
>116:     type debug/io-stats
>117:     subvolumes mysql1-stat-prefetch
>118: end-volume
>
>+------------------------------------------------------------------------------+
>[2012-05-27 12:12:33.070929] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-8: changing port to 24143 (from 0)
>[2012-05-27 12:12:33.071139] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-7: changing port to 24015 (from 0)
>[2012-05-27 12:12:33.071552] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-5: changing port to 24142 (from 0)
>[2012-05-27 12:12:33.072051] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-4: changing port to 24014 (from 0)
>[2012-05-27 12:12:33.072276] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-2: changing port to 24141 (from 0)
>[2012-05-27 12:12:33.072747] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-11: changing port to 24144 (from 0)
>[2012-05-27 12:12:33.072915] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-10: changing port to 24016 (from 0)
>[2012-05-27 12:12:33.073503] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-1: changing port to 24013 (from 0)
>[2012-05-27 12:12:33.082500] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-0: changing port to 24057 (from 0)
>[2012-05-27 12:12:33.082728] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-9: changing port to 24060 (from 0)
>[2012-05-27 12:12:33.083147] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-6: changing port to 24059 (from 0)
>[2012-05-27 12:12:33.083565] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-mysql1-client-3: changing port to 24058 (from 0)
>[2012-05-27 12:12:36.942235] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-8: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.942914] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-8: Connected to 10.0.0.120:24143, attached to remote volume '/var/spool/glusterfs/c_mysql1'.
>[2012-05-27 12:12:36.942976] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-8: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.943067] I [afr-common.c:3628:afr_notify] 0-mysql1-replicate-2: Subvolume 'mysql1-client-8' came back up; going online.
>[2012-05-27 12:12:36.943395] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-8: Server lk version = 1
>[2012-05-27 12:12:36.946072] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-7: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.946722] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-7: Connected to 10.0.0.4:24015, attached to remote volume '/var/spool/glusterfs/c_mysql1'.
>[2012-05-27 12:12:36.946770] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-7: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.947166] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-7: Server lk version = 1
>[2012-05-27 12:12:36.951076] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-5: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.951774] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-5: Connected to 10.0.0.120:24142, attached to remote volume '/var/spool/glusterfs/b_mysql1'.
>[2012-05-27 12:12:36.951817] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-5: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.951899] I [afr-common.c:3628:afr_notify] 0-mysql1-replicate-1: Subvolume 'mysql1-client-5' came back up; going online.
>[2012-05-27 12:12:36.952366] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-5: Server lk version = 1
>[2012-05-27 12:12:36.956699] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-4: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.957389] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-4: Connected to 10.0.0.4:24014, attached to remote volume '/var/spool/glusterfs/b_mysql1'.
>[2012-05-27 12:12:36.957431] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-4: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.957774] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-4: Server lk version = 1
>[2012-05-27 12:12:36.961820] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-2: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.962436] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-2: Connected to 10.0.0.120:24141, attached to remote volume '/var/spool/glusterfs/a_mysql1'.
>[2012-05-27 12:12:36.962483] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-2: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.962583] I [afr-common.c:3628:afr_notify] 0-mysql1-replicate-0: Subvolume 'mysql1-client-2' came back up; going online.
>[2012-05-27 12:12:36.962893] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-2: Server lk version = 1
>[2012-05-27 12:12:36.966971] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-11: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.967584] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-11: Connected to 10.0.0.120:24144, attached to remote volume '/var/spool/glusterfs/d_mysql1'.
>[2012-05-27 12:12:36.967631] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-11: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.967715] I [afr-common.c:3628:afr_notify] 0-mysql1-replicate-3: Subvolume 'mysql1-client-11' came back up; going online.
>[2012-05-27 12:12:36.968064] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-11: Server lk version = 1
>[2012-05-27 12:12:36.972074] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-10: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.972721] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-10: Connected to 10.0.0.4:24016, attached to remote volume '/var/spool/glusterfs/d_mysql1'.
>[2012-05-27 12:12:36.972766] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-10: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.973100] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-10: Server lk version = 1
>[2012-05-27 12:12:36.977043] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-1: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.977709] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-1: Connected to 10.0.0.4:24013, attached to remote volume '/var/spool/glusterfs/a_mysql1'.
>[2012-05-27 12:12:36.977779] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-1: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:36.978170] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-1: Server lk version = 1
>[2012-05-27 12:12:36.982194] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-0: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.987110] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-9: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.991775] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-6: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:36.996111] I [client-handshake.c:1628:select_server_supported_programs] 0-mysql1-client-3: Using Program GlusterFS 3.3.0qa43, Num (1298437), Version (330)
>[2012-05-27 12:12:37.007550] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-9: Connected to 10.0.0.12:24060, attached to remote volume '/var/spool/glusterfs/d_mysql1'.
>[2012-05-27 12:12:37.007621] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-9: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:37.008509] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-0: Connected to 10.0.0.12:24057, attached to remote volume '/var/spool/glusterfs/a_mysql1'.
>[2012-05-27 12:12:37.008561] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-0: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:37.009368] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-3: Connected to 10.0.0.12:24058, attached to remote volume '/var/spool/glusterfs/b_mysql1'.
>[2012-05-27 12:12:37.009417] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-3: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:37.010283] I [client-handshake.c:1425:client_setvolume_cbk] 0-mysql1-client-6: Connected to 10.0.0.12:24059, attached to remote volume '/var/spool/glusterfs/c_mysql1'.
>[2012-05-27 12:12:37.010327] I [client-handshake.c:1437:client_setvolume_cbk] 0-mysql1-client-6: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-27 12:12:37.020425] I [fuse-bridge.c:4138:fuse_graph_setup] 0-fuse: switched to graph 0
>[2012-05-27 12:12:37.020672] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-0: Server lk version = 1
>[2012-05-27 12:12:37.020714] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-9: Server lk version = 1
>[2012-05-27 12:12:37.020854] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-6: Server lk version = 1
>[2012-05-27 12:12:37.020884] I [client-handshake.c:453:client_set_lk_version_cbk] 0-mysql1-client-3: Server lk version = 1
>[2012-05-27 12:12:37.021443] I [fuse-bridge.c:3376:fuse_init] 0-glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.13 kernel 7.10
>[2012-05-27 12:12:37.022455] I [afr-common.c:1965:afr_set_root_inode_on_first_lookup] 0-mysql1-replicate-0: added root inode
>[2012-05-27 12:12:37.024880] I [afr-common.c:1965:afr_set_root_inode_on_first_lookup] 0-mysql1-replicate-2: added root inode
>[2012-05-27 12:12:37.025282] I [afr-common.c:1965:afr_set_root_inode_on_first_lookup] 0-mysql1-replicate-1: added root inode
>[2012-05-27 12:12:37.025575] I [afr-common.c:1965:afr_set_root_inode_on_first_lookup] 0-mysql1-replicate-3: added root inode
>[2012-05-27 12:15:51.595646] W [afr-self-heal-data.c:826:afr_lookup_select_read_child_by_txn_type] 0-mysql1-replicate-0: /mariadb/mysql/tables_priv.MYI: Possible split-brain
>[2012-05-27 12:15:51.595753] W [afr-common.c:1227:afr_detect_self_heal_by_lookup_status] 0-mysql1-replicate-0: split brain detected during lookup of /mariadb/mysql/tables_priv.MYI.
>[2012-05-27 12:15:51.595778] I [afr-common.c:1189:afr_detect_self_heal_by_iatt] 0-mysql1-replicate-0: size differs for /mariadb/mysql/tables_priv.MYI 
>[2012-05-27 12:15:51.595849] I [afr-common.c:1341:afr_launch_self_heal] 0-mysql1-replicate-0: background  data missing-entry gfid self-heal triggered. path: /mariadb/mysql/tables_priv.MYI, reason: lookup detected pending operations
>[2012-05-27 12:15:51.597998] I [afr-self-heal-common.c:1318:afr_sh_missing_entries_lookup_done] 0-mysql1-replicate-0: No sources for dir of /mariadb/mysql/tables_priv.MYI, in missing entry self-heal, continuing with the rest of the self-heals
>[2012-05-27 12:15:51.601431] E [afr-self-heal-data.c:769:afr_sh_data_fxattrop_fstat_done] 0-mysql1-replicate-0: Unable to self-heal contents of '/mariadb/mysql/tables_priv.MYI' (possible split-brain). Please delete the file from all but the preferred subvolume.
>[2012-05-27 12:15:51.602002] E [afr-self-heal-common.c:2156:afr_self_heal_completion_cbk] 0-mysql1-replicate-0: background  data missing-entry gfid self-heal failed on /mariadb/mysql/tables_priv.MYI
>[2012-05-27 12:18:32.111760] I [afr-common.c:1215:afr_detect_self_heal_by_lookup_status] 0-mysql1-replicate-0: entries are missing in lookup of /mariadb/mysql/tables_priv.MYI.
>[2012-05-27 12:18:32.111873] I [afr-common.c:1341:afr_launch_self_heal] 0-mysql1-replicate-0: background  meta-data data entry missing-entry gfid self-heal triggered. path: /mariadb/mysql/tables_priv.MYI, reason: lookup detected pending operations
>[2012-05-27 12:18:32.113830] E [afr-self-heal-common.c:1087:afr_sh_common_lookup_resp_handler] 0-mysql1-replicate-0: path /mariadb/mysql/tables_priv.MYI on subvolume mysql1-client-0 => -1 (No such file or directory)
>[2012-05-27 12:18:32.113941] E [afr-self-heal-common.c:1087:afr_sh_common_lookup_resp_handler] 0-mysql1-replicate-0: path /mariadb/mysql/tables_priv.MYI on subvolume mysql1-client-2 => -1 (No such file or directory)
>[2012-05-27 12:18:32.120354] E [afr-self-heal-data.c:769:afr_sh_data_fxattrop_fstat_done] 0-mysql1-replicate-0: Unable to self-heal contents of '/mariadb/mysql/tables_priv.MYI' (possible split-brain). Please delete the file from all but the preferred subvolume.
>[2012-05-27 12:18:32.121019] E [afr-self-heal-common.c:2156:afr_self_heal_completion_cbk] 0-mysql1-replicate-0: background  meta-data data entry missing-entry gfid self-heal failed on /mariadb/mysql/tables_priv.MYI

Actions: View

Attachments on bug 825559: 587108