[Gluster-users] Folders and files are disappearing

Tue May 29 09:03:56 UTC 2012

Hi,

We have been using gluster for about about six months now and all has
been well until last Friday. Each evening the contents of one folder
is disappearing and contents of two other folders are disappearing
altogether. I'll post some logs below and give some details of what we
are using.

Any help would be appreciated as we would like to stick with Gluster
but the data loss is getting a bit scary.

:: Dual Opteron Box, 96Gb Ram
:: Xen Cloud Platform Virtual Server
:: QSAN ISCSI SAN
:: VM - CentOS 5.7 - Gluster Master - glusterfs 3.2.5 - SAN Storage
:: VM - CentOS 5.5 - Glusterfs Mount - glusterfs 3.1.7 - SAN Storage

:: Dual Xeon Box, 24Gb RAM
:: VM - CentOS 5.7 - Gluster Slave (replicating) - glusterfs 3.2.5 -
Local Disk Storage

A portion of the logfile for the master gluster brick...the logfile is
currently sitting at 1Gb.

[2012-05-25 09:47:33.355696] I [server3_1-fops.c:449:server_rmdir_cbk]
0-bz00-server: 261150746: RMDIR /filestore/log (-2774780063) ==> -1
(Directory not empty)
[2012-05-25 09:48:15.673415] I [server3_1-fops.c:449:server_rmdir_cbk]
0-bz00-server: 458832022: RMDIR /filestore/log (-2774780063) ==> -1
(Directory not empty)
[2012-05-25 09:52:05.903266] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:52:05.907349] I [server3_1-fops.c:449:server_rmdir_cbk]
0-bz00-server: 458832043: RMDIR /filestore/log (-2774780063) ==> -1
(Directory not empty)
[2012-05-25 09:52:28.394946] I [server3_1-fops.c:449:server_rmdir_cbk]
0-bz00-server: 261167569: RMDIR /filestore/log (-2774780063) ==> -1
(Directory not empty)
[2012-05-25 09:54:11.851739] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.852606] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.853903] I [server-resolve.c:571:server_resolve]
0-bz00-server: pure path resolution for /filestore/log/migration-ui
(INODELK)
[2012-05-25 09:54:11.854294] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(resolve_deep_cbk+0x2ea)
[0x2aaaabec004a]))) 0-: inode not found
[2012-05-25 09:54:11.854348] I
[server-resolve.c:330:resolve_path_simple] 0-: failed to resolve,
inode not found
[2012-05-25 09:54:11.854373] I
[server3_1-fops.c:259:server_inodelk_cbk] 0-bz00-server: 261174185:
INODELK /filestore/log/migration-ui (0) ==> -1 (No such file or
directory)
[2012-05-25 09:54:11.854718] I [server-resolve.c:571:server_resolve]
0-bz00-server: pure path resolution for /filestore/log/migration-ui
(ENTRYLK)
[2012-05-25 09:54:11.854989] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(resolve_deep_cbk+0x2ea)
[0x2aaaabec004a]))) 0-: inode not found
[2012-05-25 09:54:11.855015] I
[server-resolve.c:330:resolve_path_simple] 0-: failed to resolve,
inode not found
[2012-05-25 09:54:11.855034] I
[server3_1-fops.c:340:server_entrylk_cbk] 0-bz00-server: 261174186:
ENTRYLK /filestore/log/migration-ui (0) ==> -1 (No such file or
directory)
[2012-05-25 09:54:11.856217] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.857074] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.857943] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.858873] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.859852] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.860711] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.861551] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.862418] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.863236] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.864047] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.864895] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.865953] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found
[2012-05-25 09:54:11.868228] W [inode.c:844:inode_lookup]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/features/marker.so(marker_lookup_cbk+0xda)
[0x2aaaaba8a86a]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe4)
[0x2aaaabca6fa4]
(-->/opt/glusterfs/3.2.5/lib64/glusterfs/3.2.5/xlator/protocol/server.so(server_lookup_cbk+0x791)
[0x2aaaabed6f81]))) 0-: inode not found

A portion of the logfile from the server mounting the volume

[2012-05-25 09:44:14.632402] I
[afr-dir-read.c:171:afr_examine_dir_readdir_cbk] 0-bz00-replicate-0:
entry self-heal triggered. path: /filestore/log, reason: checksums of
directory differ, forced merge option set
[2012-05-25 09:44:14.761003] E [afr-common.c:120:afr_set_split_brain]
0-bz00-replicate-0: invalid argument: inode
[2012-05-25 09:44:14.761034] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  entry self-heal completed on
/filestore/log
[2012-05-25 09:44:58.7973] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of /filestore/log.
[2012-05-25 09:44:58.8052] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log
[2012-05-25 09:44:58.13305] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log
[2012-05-25 09:45:18.106039] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of /filestore/log.
[2012-05-25 09:45:18.106099] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log
[2012-05-25 09:45:18.112220] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log
[2012-05-25 09:45:18.123225] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of
/filestore/log/migration-ui.
[2012-05-25 09:45:18.123252] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log/migration-ui
[2012-05-25 09:45:18.126129] E
[afr-self-heal-metadata.c:677:afr_sh_metadata_post_nonblocking_inodelk_cbk]
0-bz00-replicate-0: Non Blocking metadata inodelks failed for
/filestore/log/migration-ui. Metadata self-heal failed
[2012-05-25 09:45:18.126900] E
[afr-self-heal-entry.c:2274:afr_sh_post_nonblocking_entry_cbk]
0-bz00-replicate-0: Non Blocking entrylks failed for
/filestore/log/migration-ui.
[2012-05-25 09:45:18.126928] E
[afr-self-heal-common.c:1533:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal failed
on /filestore/log/migration-ui
[2012-05-25 09:45:18.126953] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218542864: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 09:45:18.251802] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218542878: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 09:45:18.427097] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218542881: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 09:45:19.299731] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218542982: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 09:45:19.304754] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218542989: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 09:48:16.791434] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of /filestore/log.
[2012-05-25 09:48:16.797658] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log
[2012-05-25 09:48:16.802911] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log
[2012-05-25 09:51:23.140486] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of /filestore/log.
[2012-05-25 09:51:23.140544] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log
[2012-05-25 09:51:23.146264] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log
[2012-05-25 09:52:59.909294] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of
/filestore/log.tar.
[2012-05-25 09:52:59.909347] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log.tar
[2012-05-25 09:53:00.52216] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log.tar
[2012-05-25 09:53:16.613692] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of /filestore/log.
[2012-05-25 09:53:16.613741] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log
[2012-05-25 09:53:16.618780] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal
completed on /filestore/log
[2012-05-25 09:53:16.619935] I [afr-common.c:747:afr_lookup_done]
0-bz00-replicate-0: entries are missing in lookup of
/filestore/log/migration-ui.
[2012-05-25 09:53:16.619964] I [afr-common.c:790:afr_lookup_done]
0-bz00-replicate-0: background  meta-data data entry self-heal
triggered. path: /filestore/log/migration-ui
[2012-05-25 09:53:16.622461] E
[afr-self-heal-metadata.c:677:afr_sh_metadata_post_nonblocking_inodelk_cbk]
0-bz00-replicate-0: Non Blocking metadata inodelks failed for
/filestore/log/migration-ui. Metadata self-heal failed
[2012-05-25 09:53:16.623094] E
[afr-self-heal-entry.c:2274:afr_sh_post_nonblocking_entry_cbk]
0-bz00-replicate-0: Non Blocking entrylks failed for
/filestore/log/migration-ui.
[2012-05-25 09:53:16.623122] E
[afr-self-heal-common.c:1533:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  meta-data data entry self-heal failed
on /filestore/log/migration-ui
[2012-05-25 09:53:16.623148] W [fuse-bridge.c:145:fuse_entry_cbk]
0-glusterfs-fuse: 218578818: LOOKUP() /filestore/log/migration-ui
returning inode 0
[2012-05-25 10:06:44.742732] I
[afr-dir-read.c:171:afr_examine_dir_readdir_cbk] 0-bz00-replicate-0:
entry self-heal triggered. path: /filestore/log, reason: checksums of
directory differ, forced merge option set
[2012-05-25 10:06:44.749356] E [afr-common.c:120:afr_set_split_brain]
0-bz00-replicate-0: invalid argument: inode
[2012-05-25 10:06:44.749384] I
[afr-self-heal-common.c:1536:afr_self_heal_completion_cbk]
0-bz00-replicate-0: background  entry self-heal completed on
/filestore/log

Thanks,

Chris