index corruption weirdness
William Taylor
william.taylor at sonic.com
Tue Oct 9 22:16:00 EEST 2018
We have started seeing index corruption ever since we upgraded (we
believe) our imap servers from SL6 to Centos 7. Mail/Indexes are stored
on Netapps mounted via NFS. We have 2 lvs servers running surealived in
dr/wlc, 2 directors and 6 backend imap/pop servers.
Most of the core dumps I've looked at for different users are like
"Backtrace 2" with some variations on folder path.
This latest crash (Backtrace 1) is different from others I've seen.
It is also leaving 0byte files in the users .Drafts/tmp folder.
# ls -s /var/spool/mail/15/00/user1/.Drafts/tmp | awk '{print $1}'
|sort | uniq -c
9692 0
1 218600
I believe the number of cores here is different from the number of tmp
files because this is when we moved the user to our debug server so we
could get the core dumps.
# ls -la /home/u/user1/core.* |wc -l
8437
Any help/insight would be greatly appreciated.
Thanks,
William
OS Info:
CentOS Linux release 7.5.1804 (Core)
3.10.0-862.14.4.el7.x86_64
NFS:
# mount -t nfs |grep mail/15
172.16.255.14:/vol/vol1/mail/15 on /var/spool/mail/15 type nfs
(rw,nosuid,nodev,relatime,vers=3,rsize=32768,wsize=32768,namlen=255,hard,nordirplus,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=172.16.255.14,mountvers=3,mountport=4046,mountproto=udp,local_lock=none,addr=172.16.255.14)
Dovecot Info:
dovecot -n
# 2.1.17: /etc/dovecot/dovecot.conf
# OS: Linux 3.10.0-862.14.4.el7.x86_64 x86_64 CentOS Linux release
7.5.1804 (Core) auth_failure_delay = 0
auth_master_user_separator = *
auth_username_format = %Ln
auth_verbose = yes
auth_verbose_passwords = sha1
auth_worker_max_count = 64
login_log_format_elements = user=<%u> session=%{session} method=%m
rip=%r lip=%l mpid=%e %c
login_trusted_networks = 172.16.0/24
mail_debug = yes
mail_fsync = always
mail_log_prefix = "%s(%u): session=%{session} "
mail_plugins = zlib
maildir_very_dirty_syncs = yes
mmap_disable = yes
passdb {
args = /etc/dovecot/master-users
driver = passwd-file
master = yes
}
passdb {
args = imap
driver = pam
}
plugin {
lazy_expunge = DELETED_MESSAGES.
mail_log_events = delete expunge flag_change
mail_log_fields = uid box msgid from flags size
quota = fs:User quota
stats_refresh = 30 secs
stats_track_cmds = yes
}
protocols = imap pop3
service anvil {
client_limit = 10000
}
service auth {
client_limit = 10000
vsz_limit = 1 G
}
service doveadm {
inet_listener {
port = 1842
}
unix_listener doveadm-server {
mode = 0666
}
}
service imap-login {
inet_listener imap {
port = 143
}
inet_listener imaps {
port = 993
ssl = yes
}
process_limit = 7000
process_min_avail = 32
vsz_limit = 256 M
}
service imap-postlogin {
executable = script-login -d /etc/dovecot/bin/foo-imap-postlogin
user = $default_internal_user
}
service imap {
executable = imap imap-postlogin
process_limit = 7000
vsz_limit = 1492 M
}
service pop3-login {
inet_listener pop3 {
port = 110
}
inet_listener pop3s {
port = 995
ssl = yes
}
process_limit = 2000
process_min_avail = 32
vsz_limit = 256 M
}
service pop3-postlogin {
executable = script-login -d /etc/dovecot/bin/foo-pop3-postlogin
user = $default_internal_user
}
service pop3 {
executable = pop3 pop3-postlogin
process_limit = 2000
}
shutdown_clients = no
ssl = required
ssl_ca = </etc/dovecot/ssl/imap.foo.com.ca-bundle
ssl_cert = </etc/dovecot/ssl/imap.foo.com.crt
ssl_key = </etc/dovecot/ssl/imap.foo.com.key
ssl_parameters_regenerate = 1 days
ssl_protocols = !SSLv2 !SSLv3
syslog_facility = local0
userdb {
driver = passwd
}
verbose_proctitle = yes
protocol imap {
imap_id_send = support-url support-email
imap_max_line_length = 128 k
mail_max_userip_connections = 20
mail_plugins = zlib mail_log notify imap_zlib
ssl_ca = </etc/dovecot/ssl/imap.foo.com.ca-bundle
ssl_cert = </etc/dovecot/ssl/imap.foo.com.crt
ssl_key = </etc/dovecot/ssl/imap.foo.com.key
}
protocol pop3 {
mail_plugins = zlib lazy_expunge
pop3_fast_size_lookups = yes
pop3_uidl_format = %f
ssl_ca = </etc/dovecot/ssl/pop.foo.com.ca-bundle
ssl_cert = </etc/dovecot/ssl/pop.foo.com.crt
ssl_key = </etc/dovecot/ssl/pop.foo.com.key
}
Backtrace 1:
Reading symbols from /usr/libexec/dovecot/imap...Reading symbols from
/usr/lib/debug/usr/libexec/dovecot/imap.debug...done.
Program terminated with signal 6, Aborted.
#0 0x00007fbee47e0277 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
Thread 1 (Thread 0x7fbee532f840 (LWP 9449)):
#0 0x00007fbee47e0277 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
resultvar = 0
pid = 9449
selftid = 9449
#1 0x00007fbee47e1968 in __GI_abort () at abort.c:90
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction =
0x0}, sa_mask = {__val = {0 <repeats 11 times>, 31683224,
140725444114256, 31908720, 140457858143945, 31683224}}, sa_flags =
-457466710, sa_restorer = 0x0}
sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00007fbee4bbdb65 in default_fatal_finish (type=<optimized out>,
status=status at entry=0) at failures.c:191
backtrace = 0x1e372d0
"/usr/lib64/dovecot/libdovecot.so.0(+0x46b55) [0x7fbee4bbdb55] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x46c1e) [0x7fbee4bbdc1e] ->
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7fbee4b90dda] ->
/usr"...
#3 0x00007fbee4bbdc1e in i_internal_fatal_handler (ctx=0x7ffd321b77a0,
format=<optimized out>, args=<optimized out>) at failures.c:649
status = 0
#4 0x00007fbee4b90dda in i_panic (format=format at entry=0x7fbee4ee0588
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:263
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area =
0x7ffd321b7890, reg_save_area = 0x7ffd321b77d0}}
#5 0x00007fbee4ea96ad in index_mail_parse_body_finish (mail=0x1e69570,
field=field at entry=MAIL_CACHE_FLAGS) at index-mail.c:769
parser_input = 0x1e6e370
ret = 1
__FUNCTION__ = "index_mail_parse_body_finish"
#6 0x00007fbee4eaaa2b in index_mail_cache_parse_deinit
(_mail=<optimized out>, received_date=<optimized out>,
success=<optimized out>)
at index-mail.c:1624
mail = <optimized out>
#7 0x00007fbee4e5dce3 in maildir_save_finish_real (_ctx=0x1e68560) at
maildir-save.c:551
ctx = 0x1e68560
e = 0x1e574d0
output_errno = <optimized out>
path = 0x1e37218
"/var/spool/mail/15/00/user1/.Drafts/tmp/1539107164.M157986P9449.debug.imapd.foo.com"
real_size = <optimized out>
size = 1539107194
#8 maildir_save_finish (ctx=0x1e68560) at maildir-save.c:630
_data_stack_cur_id = 3
#9 0x00007fbee4e90ce6 in mailbox_save_cancel
(_ctx=_ctx at entry=0x1e58d58) at mail-storage.c:1697
ctx = 0x1e68560
keywords = 0x1e65860
mail = <optimized out>
#10 0x0000000000409459 in cmd_append_continue_message (cmd=0x1e58c10) at
cmd-append.c:420
client = 0x1e58070
ctx = 0x1e58d10
size = 31819840
ret = 3920
#11 0x000000000041186c in command_exec (cmd=0x1e58c10) at
imap-commands.c:148
hook = 0x1e40d00
ret = <optimized out>
#12 0x0000000000408d21 in client_input_append (cmd=0x1e58c10) at
cmd-append.c:101
ctx = 0x1e58d10
client = 0x1e58070
finished = <optimized out>
__FUNCTION__ = "client_input_append"
#13 0x00007fbee4bcaaa7 in io_loop_call_io (io=0x1e58b10) at ioloop.c:379
ioloop = 0x1e3f6a0
t_id = 2
#14 0x00007fbee4bcb857 in io_loop_handler_run
(ioloop=ioloop at entry=0x1e3f6a0) at ioloop-epoll.c:213
ctx = 0x1e3fa10
events = <optimized out>
list = 0x1e58b60
io = <optimized out>
tv = {tv_sec = 1799, tv_usec = 999445}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
#15 0x00007fbee4bca628 in io_loop_run (ioloop=0x1e3f6a0) at ioloop.c:398
No locals.
#16 0x00007fbee4bb6213 in master_service_run (service=0x1e3f550,
callback=callback at entry=0x418fb0 <client_connected>) at
master-service.c:544
No locals.
#17 0x0000000000408933 in main (argc=2, argv=0x1e3f390) at main.c:389
set_roots = {0x41c320 <imap_setting_parser_info>, 0x0}
login_set = {auth_socket_path = 0x1e37090
"/run/dovecot/auth-master", postlogin_socket_path = 0x1e370c0
"/run/dovecot/imap-postlogin", postlogin_timeout_secs = 60, callback =
0x419440 <login_client_connected>, failure_callback = 0x419150
<login_client_failed>}
service_flags = <optimized out>
storage_service_flags = <optimized out>
username = 0x0
c = <optimized out>
Backtrace 2:
Reading symbols from /usr/libexec/dovecot/imap...Reading symbols from
/usr/lib/debug/usr/libexec/dovecot/imap.debug...done.
Program terminated with signal 6, Aborted.
#0 0x00007f437288c277 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
Thread 1 (Thread 0x7f43733d3840 (LWP 6725)):
#0 0x00007f437288c277 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
resultvar = 0
pid = 6725
selftid = 6725
#1 0x00007f437288d968 in __GI_abort () at abort.c:90
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction =
0x0}, sa_mask = {__val = {0 <repeats 11 times>, 19630744,
140729812750864, 1, 139927665268057, 19630744}}, sa_flags = 1925602218,
sa_restorer = 0x0}
sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00007f4372c69a25 in default_fatal_finish (type=<optimized out>,
status=status at entry=0) at failures.c:191
backtrace = 0x12b8ad0
"/usr/lib64/dovecot/libdovecot.so.0(+0x46a15) [0x7f4372c69a15] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x46ade) [0x7f4372c69ade] ->
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f4372c3cdaa] ->
/usr"...
#3 0x00007f4372c69ade in i_internal_fatal_handler (ctx=0x7ffe367f9260,
format=<optimized out>, args=<optimized out>) at failures.c:649
status = 0
#4 0x00007f4372c3cdaa in i_panic (format=format at entry=0x7f4372f83cc8
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:263
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area =
0x7ffe367f9350, reg_save_area = 0x7ffe367f9290}}
#5 0x00007f4372f77eb8 in keywords_update_records (ext=0x13827e8,
ext=0x13827e8, uid2=<optimized out>, uid1=<optimized out>,
type=MODIFY_ADD, keyword_idx=0, ctx=0x7ffe367f94e0) at
mail-index-sync-keywords.c:228
data = <optimized out>
data_mask = 1 '\001'
seq1 = 346
view = 0x134c110
rec = <optimized out>
data_offset = <optimized out>
seq2 = 346
#6 mail_index_sync_keywords (ctx=ctx at entry=0x7ffe367f94e0,
hdr=hdr at entry=0x1345bb8, rec=rec at entry=0x13a54e4) at
mail-index-sync-keywords.c:304
view = <optimized out>
keyword_name = <optimized out>
ext = 0x13827e8
uid = <optimized out>
end = 0x13a54fc
seqset_offset = <optimized out>
ext_map_idx = 2
keyword_idx = 0
__FUNCTION__ = "mail_index_sync_keywords"
#7 0x00007f4372f78822 in mail_index_sync_record_real (data=0x13a54e4,
hdr=0x1345bb8, ctx=0x7ffe367f94e0) at mail-index-sync-update.c:779
rec = 0x13a54e4
ret = 0
#8 mail_index_sync_record (ctx=ctx at entry=0x7ffe367f94e0, hdr=0x1345bb8,
data=0x13a54e4) at mail-index-sync-update.c:824
_data_stack_cur_id = 7
ret = 0
#9 0x00007f4372f79866 in mail_index_sync_map
(_map=_map at entry=0x1346498,
type=type at entry=MAIL_INDEX_SYNC_HANDLER_HEAD, force=force at entry=true)
at mail-index-sync-update.c:1036
map = <optimized out>
index = 0x1346410
view = 0x134c110
sync_map_ctx = {view = 0x134c110, modseq_ctx = 0x138d330,
cur_ext_map_idx = 0, ext_intro_seq = 105, ext_intro_offset = 13792,
ext_intro_end_offset = 13820, expunge_handlers = {arr = {buffer = 0x0,
element_size = 0}, v = 0x0, v_modifiable = 0x0}, extra_contexts = {
arr = {buffer = 0x134d8c0, element_size = 8}, v = 0x134d8c0,
v_modifiable = 0x134d8c0}, unknown_extensions = 0x0, type =
MAIL_INDEX_SYNC_HANDLER_HEAD, sync_handlers_initialized = 0,
expunge_handlers_set = 0, expunge_handlers_used = 0, cur_ext_ignore = 0,
internal_update = 0, errors = 0}
thdr = 0x1345bb8
tdata = 0x13a54e4
prev_seq = 105
start_offset = <optimized out>
prev_offset = 14084
ret = <optimized out>
had_dirty = <optimized out>
reset = false
__FUNCTION__ = "mail_index_sync_map"
#10 0x00007f4372f6a6e4 in mail_index_map (index=index at entry=0x1346410,
type=type at entry=MAIL_INDEX_SYNC_HANDLER_HEAD) at
mail-index-map-read.c:433
ret = <optimized out>
__FUNCTION__ = "mail_index_map"
#11 0x00007f4372f65a90 in mail_index_try_open
(index=index at entry=0x1346410) at mail-index.c:426
ret = <optimized out>
__FUNCTION__ = "mail_index_try_open"
#12 0x00007f4372f66130 in mail_index_open_files
(index=index at entry=0x1346410,
flags=flags at entry=(MAIL_INDEX_OPEN_FLAG_CREATE |
MAIL_INDEX_OPEN_FLAG_MMAP_DISABLE |
MAIL_INDEX_OPEN_FLAG_DOTLOCK_USE_EXCL)) at mail-index.c:504
ret = <optimized out>
created = false
#13 0x00007f4372f66230 in mail_index_open (index=0x1346410,
flags=flags at entry=(MAIL_INDEX_OPEN_FLAG_CREATE |
MAIL_INDEX_OPEN_FLAG_MMAP_DISABLE |
MAIL_INDEX_OPEN_FLAG_DOTLOCK_USE_EXCL)) at mail-index.c:594
ret = <optimized out>
__FUNCTION__ = "mail_index_open"
#14 0x00007f4372f57a17 in index_storage_mailbox_open
(box=box at entry=0x1388750, move_to_memory=move_to_memory at entry=false) at
index-storage.c:231
ibox = 0x1388b48
index_flags = (MAIL_INDEX_OPEN_FLAG_CREATE |
MAIL_INDEX_OPEN_FLAG_MMAP_DISABLE |
MAIL_INDEX_OPEN_FLAG_DOTLOCK_USE_EXCL)
ret = <optimized out>
__FUNCTION__ = "index_storage_mailbox_open"
#15 0x00007f4372f03212 in maildir_mailbox_open_existing
(box=box at entry=0x1388750) at maildir-storage.c:305
mbox = 0x1388750
#16 0x00007f4372f03960 in maildir_mailbox_open (box=0x1388750) at
maildir-storage.c:365
box_path = 0x1388f68
"/var/spool/mail/16/47/user2/DELETED_MESSAGES/.INBOX"
root_dir = <optimized out>
st = {st_dev = 140729812752383, st_ino = 140729812752416,
st_nlink = 19629048, st_mode = 914331680, st_uid = 32766, st_gid =
4300439, __pad0 = 0, st_rdev = 140729812752896, st_size = 1, st_blksize
= 133, st_blocks = 19629048, st_atim = {tv_sec = 139927662018357,
tv_nsec = 4222451713}, st_mtim = {tv_sec = 139927664838496,
tv_nsec = 139927664838496}, st_ctim = {tv_sec = 344592, tv_nsec =
-140729812752575}, __unused = {129, 32, 4}}
ret = <optimized out>
#17 0x00007f436fd13942 in zlib_mailbox_open (box=0x1388750) at
zlib-plugin.c:346
zbox = 0x1388e30
#18 0x00007f4372f34cc7 in mailbox_open_full (box=0x1388750, input=0x0)
at mail-storage.c:907
_data_stack_cur_id = 6
ret = <optimized out>
input = 0x0
box = 0x1388750
#19 0x00007f4372f35070 in mailbox_open (box=box at entry=0x1388750) at
mail-storage.c:942
No locals.
#20 0x00007f4372f56b2b in index_storage_get_status (box=0x1388750,
items=STATUS_UNSEEN, status_r=0x7ffe367f9b40) at index-status.c:41
hdr = <optimized out>
__FUNCTION__ = "index_storage_get_status"
#21 0x00000000004175f5 in imap_status_get (cmd=0x12d99b0, ns=0x12d8590,
mailbox=mailbox at entry=0x13883e0 "DELETED_MESSAGES.INBOX",
items=items at entry=0x12d9aec, result_r=result_r at entry=0x7ffe367f9b40,
error_r=error_r at entry=0x7ffe367f9b38) at imap-status.c:84
client = 0x12d8e60
box = 0x1388750
error = MAIL_ERROR_NONE
ret = 0
#22 0x000000000040bee7 in list_send_status (flags=<optimized out>,
mutf7_name=0x12b8548 "DELETED_MESSAGES.INBOX", name=0x13883e0
"DELETED_MESSAGES.INBOX", ctx=0x12d9ad0) at cmd-list.c:466
result = {status = {messages = 0, recent = 0, unseen = 0,
uidvalidity = 0, uidnext = 0, first_unseen_seq = 0, first_recent_uid =
0, last_cached_seq = 0, highest_modseq = 0, keywords = 0x0,
permanent_flags = 0, nonpermanent_modseqs = 0, permanent_keywords = 0,
allow_new_keywords = 0}, metadata = {guid = '\000' <repeats 15 times>,
virtual_size = 0, cache_fields = 0x0, precache_fields = (MAIL_FETCH_DATE
| MAIL_FETCH_RECEIVED_DATE | MAIL_FETCH_SAVE_DATE |
MAIL_FETCH_VIRTUAL_SIZE | MAIL_FETCH_NUL_STATE | MAIL_FETCH_IMAP_BODY |
MAIL_FETCH_FROM_ENVELOPE | MAIL_FETCH_HEADER_MD5 |
MAIL_FETCH_UIDL_BACKEND | MAIL_FETCH_MAILBOX_NAME | MAIL_FETCH_GUID |
unknown: 16779264)}}
ns = <optimized out>
error = 0x12b8360 "*"
#23 list_namespace_mailboxes (ctx=0x12d9ad0) at cmd-list.c:566
_data_stack_cur_id = 5
info = <optimized out>
flags = <optimized out>
str = 0x12b83c0
ret = 1
ns = 0x0
mutf7_name = 0x12b8510
name = 0x13883e0 "DELETED_MESSAGES.INBOX"
#24 cmd_list_continue (cmd=cmd at entry=0x12d99b0) at cmd-list.c:912
_data_stack_cur_id = 4
ctx = 0x12d9ad0
#25 0x000000000040cb27 in cmd_list_full (cmd=0x12d99b0, lsub=<optimized
out>) at cmd-list.c:1092
client = 0x12d8e60
args = 0x12c3968
list_args = 0x12c3a40
arg_count = 0
ctx = 0x12d9ad0
patterns = {arr = {buffer = <optimized out>, element_size = 8},
v = <optimized out>, v_modifiable = <optimized out>}
pattern = 0x12b8360 "*"
patterns_strarr = <optimized out>
str = <optimized out>
#26 0x00000000004117fc in command_exec (cmd=cmd at entry=0x12d99b0) at
imap-commands.c:148
hook = 0x12c1d00
ret = <optimized out>
#27 0x000000000041079b in client_command_input (cmd=cmd at entry=0x12d99b0)
at imap-client.c:682
client = 0x12d8e60
command = <optimized out>
__FUNCTION__ = "client_command_input"
#28 0x0000000000410885 in client_command_input (cmd=0x12d99b0) at
imap-client.c:733
client = 0x12d8e60
command = <optimized out>
__FUNCTION__ = "client_command_input"
#29 0x0000000000410aed in client_handle_next_command
(remove_io_r=<synthetic pointer>, client=0x12d8e60) at imap-client.c:774
size = 52
#30 client_handle_input (client=client at entry=0x12d8e60) at
imap-client.c:786
_data_stack_cur_id = 3
remove_io = false
handled_commands = false
__FUNCTION__ = "client_handle_input"
#31 0x0000000000411302 in client_input (client=0x12d8e60) at
imap-client.c:825
cmd = 0x7f4372c69eae <i_set_failure_prefix+46>
output = 0x12dde18
bytes = 52
__FUNCTION__ = "client_input"
#32 0x00007f4372c76937 in io_loop_call_io (io=0x12d1150) at ioloop.c:379
ioloop = 0x12c06a0
t_id = 2
#33 0x00007f4372c776e7 in io_loop_handler_run
(ioloop=ioloop at entry=0x12c06a0) at ioloop-epoll.c:213
ctx = 0x12c0a10
events = <optimized out>
list = 0x12d9900
io = <optimized out>
tv = {tv_sec = 1799, tv_usec = 999765}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
#34 0x00007f4372c764b8 in io_loop_run (ioloop=0x12c06a0) at ioloop.c:398
No locals.
#35 0x00007f4372c62113 in master_service_run (service=0x12c0550,
callback=callback at entry=0x418f40 <client_connected>) at
master-service.c:544
No locals.
#36 0x00000000004088e3 in main (argc=2, argv=0x12c0390) at main.c:389
set_roots = {0x41c2a0 <imap_setting_parser_info>, 0x0}
login_set = {auth_socket_path = 0x12b8090
"/run/dovecot/auth-master", postlogin_socket_path = 0x12b80c0
"/run/dovecot/imap-postlogin", postlogin_timeout_secs = 60, callback =
0x4193d0 <login_client_connected>, failure_callback = 0x4190e0
<login_client_failed>}
service_flags = <optimized out>
storage_service_flags = <optimized out>
username = 0x0
c = <optimized out>
More information about the dovecot
mailing list