Quota count does not work with lock_method=dotlock

mkliewe at gmx.de mkliewe at gmx.de
Tue Jan 24 12:01:45 UTC 2017


On 24.01.2017 10:32, Aki Tuomi wrote:
> On 24.01.2017 11:31, Tom Sommer wrote:
>> On 2017-01-24 10:25, Aki Tuomi wrote:
>>> On 24.01.2017 11:13, Tom Sommer wrote:
>>>> On 2017-01-18 15:27, mkliewe at gmx.de wrote:
>>>>> dovecot crashes when I switch the quota tracking from dict to count.
>>>> I have the same problem, but I use 'dict:file' as quota backend -
>>>> Maybe the error is due to quota_vsizes and not 'count'.
>>>>
>>>> // Tom Sommer
>>> Hi!
>>>
>>> What version of dovecot are you both using?
>> 2.2.27 (c0f36b0)
> A gdb bt full would help if possible.
Hi Aki,

I'm using 2.2.26.0 (23d1de6)

Below a "bt full". In this case I have a mailbox which already is using 
the count quota module, and I changed the lock_method from fcntl to 
dotlock. After a dovecot restart, every change in the mailbox (new mail, 
delete mail) crashes the imap process.
The same happens if I have a mailbox which is using dict quota and 
lock_method=dotlock. As soon as I switch to the count quota (and enable 
quota_vsizes), it crashes directly after login, because I guess dovecot 
detects that the vsizes or count data is missing, and wants to calculate 
and store it. Then it crashes during login.

   #quota = dict:User quota::proxy::quota
   quota = count:User quota
   quota_vsizes = yes
   quota_clone_dict = proxy::quota


Reading symbols from /usr/local/libexec/dovecot/imap...done.
[New LWP 25953]
Core was generated by `dovecot/imap'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f517f0c0428 in __GI_raise (sig=sig at entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
54    ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.

#0  0x00007f517f0c0428 in __GI_raise (sig=sig at entry=6) at 
../sysdeps/unix/sysv/linux/raise.c:54
         resultvar = 0
         pid = 25953
         selftid = 25953
#1  0x00007f517f0c202a in __GI_abort () at abort.c:89
         save_stage = 2
         act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 
0x0}, sa_mask = {__val = {0, 139987996092596, 139987996095480,
               139988007874990, 139988007830623, 139988007831156, 
139988007887477, 33523136, 16395163946287022080, 0, 0, 139988007573664,
               33526848, 140721879070388, 0, 2401}}, sa_flags = 
2135830010, sa_restorer = 0x5}
         sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007f517f4e7e9a in default_fatal_finish (type=LOG_TYPE_PANIC, 
status=status at entry=0) at failures.c:201
         backtrace = 0x1ff83f0 
"/usr/local/lib/dovecot/libdovecot.so.0(+0x93ea2) [0x7f517f4e7ea2] -> 
/usr/local/lib/dovecot/libdovecot.so.0(+0x93f8d) [0x7f517f4e7f8d] -> 
/usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f517f481"...
#3  0x00007f517f4e7f8d in i_internal_fatal_handler (ctx=0x7ffc5d9d3850, 
format=<optimized out>, args=<optimized out>) at failures.c:670
         status = 0
#4  0x00007f517f4817c1 in i_panic (format=format at entry=0x7f517f518714 
"file %s: line %d: unreached") at failures.c:275
         ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, 
timestamp_usecs = 0}
         args = <error reading variable args (Attempt to dereference a 
generic pointer.)>
#5  0x00007f517f4ec810 in file_lock_do (fd=fd at entry=19,
     path=path at entry=0x1ff8300 
"/mnt/storage/xxx/yyy/zzz/maildir/.FOLDERNAME 05_04_2014 
13:58.Sent/.vsize.lockdd843829ef7eb296",
     lock_type=lock_type at entry=1, 
lock_method=lock_method at entry=FILE_LOCK_METHOD_DOTLOCK, timeout_secs=0, 
error_r=error_r at entry=0x7ffc5d9d3ae8)
     at file-lock.c:285
         lock_type_str = 0x7f517f52bc38 "write-lock"
         started = 1485257739
         ret = <optimized out>
         __FUNCTION__ = "file_lock_do"
#6  0x00007f517f4ecbe6 in file_wait_lock_error (fd=19,
     path=0x1ff8300 "/mnt/storage/xxx/yyy/zzz/maildir/.FOLDERNAME 
05_04_2014 13:58.Sent/.vsize.lockdd843829ef7eb296", lock_type=1,
     lock_method=FILE_LOCK_METHOD_DOTLOCK, timeout_secs=<optimized out>, 
lock_r=0x2025020, error_r=0x7ffc5d9d3ae8) at file-lock.c:314
         ret = <optimized out>
#7  0x00007f517f4ecc61 in file_try_lock_error (fd=<optimized out>, 
path=<optimized out>, lock_type=lock_type at entry=1,
     lock_method=lock_method at entry=FILE_LOCK_METHOD_DOTLOCK, 
lock_r=lock_r at entry=0x2025020, error_r=error_r at entry=0x7ffc5d9d3ae8)
     at file-lock.c:66
No locals.
#8  0x00007f517f4e9d1d in try_create_new (error_r=0x7ffc5d9d3ae8, 
lock_r=0x2025020, fd_r=0x7ffc5d9d3a80, set=0x7ffc5d9d3af0,
     path=0x2029e80 "/mnt/storage/xxx/yyy/zzz/maildir/.FOLDERNAME 
05_04_2014 13:58.Sent/.vsize.lock") at file-create-locked.c:65
         fd = 19
         orig_errno = <optimized out>
         ret = -1
         temp_path = 0x1ff82c8
         mode = 2
         uid = <optimized out>
         gid = <optimized out>
#9  file_create_locked (path=0x2029e80 
"/mnt/storage/xxx/yyy/zzz/maildir/.FOLDERNAME 05_04_2014 
13:58.Sent/.vsize.lock",
     set=set at entry=0x7ffc5d9d3af0, lock_r=lock_r at entry=0x2025020, 
created_r=created_r at entry=0x7ffc5d9d3ae7,
     error_r=error_r at entry=0x7ffc5d9d3ae8) at file-create-locked.c:118
         i = 0
         fd = -1
         ret = <optimized out>
         __FUNCTION__ = "file_create_locked"
#10 0x00007f517f8225f3 in vsize_update_lock_full (update=0x2024fe0, 
lock_secs=lock_secs at entry=0) at index-mailbox-size.c:140
         box = <optimized out>
         perm = 0x2029198
         set = {lock_timeout_secs = 0, lock_method = 
FILE_LOCK_METHOD_DOTLOCK, mode = 432, uid = 0, gid = 4294967295,
           gid_origin = 0x202a760 
"/mnt/storage/xxx/yyy/zzz/maildir/.FOLDERNAME 05_04_2014 13:58.Sent"}
         error = 0x7ffc5d9d3b30 ""
         created = false
#11 0x00007f517f8226d7 in index_mailbox_vsize_update_try_lock 
(update=<optimized out>) at index-mailbox-size.c:157
No locals.
#12 0x00007f517f822bb2 in index_mailbox_vsize_update_appends 
(box=<optimized out>) at index-mailbox-size.c:401
         update = 0x2024fe0
         status = {messages = 107, recent = 0, unseen = 0, uidvalidity = 
1281450483, uidnext = 108, first_unseen_seq = 0,
           first_recent_uid = 108, last_cached_seq = 0, highest_modseq = 
0, highest_pvt_modseq = 0, keywords = 0x0, permanent_flags = 0,
           permanent_keywords = 0, allow_new_keywords = 0, 
nonpermanent_modseqs = 0, no_modseq_tracking = 0, have_guids = 1,
           have_save_guids = 1, have_only_guid128 = 0}
#13 0x00007f517f82df4c in index_mailbox_sync_deinit (_ctx=0x2030f90, 
status_r=0x7ffc5d9d3d00) at index-sync.c:346
         ctx = 0x2030f90
         sync_rec = {seq1 = 0, seq2 = 0, type = (unknown: 0)}
         delayed_expunges = false
         ret = <optimized out>
#14 0x00007f517e8442cf in fts_sync_deinit (ctx=0x2030f90, 
status_r=0x7ffc5d9d3d00) at fts-storage.c:704
         box = 0x2028fc0
         fbox = 0x20297d0
         flist = 0x201e998
         optimize = <optimized out>
         ret = 0
#15 0x00007f517ec80bf3 in quota_mailbox_sync_deinit (ctx=0x2030f90, 
status_r=0x7ffc5d9d3d00) at quota-storage.c:436
         qbox = 0x2029638
         ret = <optimized out>
#16 0x00007f517f811447 in index_list_sync_deinit (ctx=0x2030f90, 
status_r=0x7ffc5d9d3d00) at mailbox-list-index-status.c:749
         box = 0x2028fc0
         ibox = <optimized out>
#17 0x00007f517f7b4312 in mailbox_sync_deinit 
(_ctx=_ctx at entry=0x7ffc5d9d3d10, status_r=status_r at entry=0x7ffc5d9d3d00) 
at mail-storage.c:1751
         ctx = <optimized out>
         box = 0x2028fc0
         errormsg = <optimized out>
         error = MAIL_ERROR_NONE
         ret = <optimized out>
#18 0x00007f517f7b43e9 in mailbox_sync (box=box at entry=0x2028fc0, 
flags=<optimized out>, flags at entry=MAILBOX_SYNC_FLAG_FAST)
     at mail-storage.c:1777
         ctx = 0x0
         status = {sync_delayed_expunges = 0}
#19 0x00007f517f82a2ed in index_mailbox_get_metadata 
(box=box at entry=0x2028fc0, items=items at entry=MAILBOX_METADATA_VIRTUAL_SIZE,
     metadata_r=metadata_r at entry=0x7ffc5d9d3f30) at index-status.c:326
No locals.
#20 0x00007f517f7dce81 in maildir_mailbox_get_metadata (box=0x2028fc0, 
items=MAILBOX_METADATA_VIRTUAL_SIZE, metadata_r=0x7ffc5d9d3f30)
     at maildir-storage.c:548
         mbox = 0x2028fc0
#21 0x00007f517f8115ac in index_list_get_metadata (box=0x2028fc0, 
items=MAILBOX_METADATA_VIRTUAL_SIZE, metadata_r=0x7ffc5d9d3f30)
     at mailbox-list-index-status.c:377
         ibox = 0x202a520
#22 0x00007f517f7b5d80 in mailbox_get_metadata (box=0x2028fc0, 
items=MAILBOX_METADATA_VIRTUAL_SIZE, 
metadata_r=metadata_r at entry=0x7ffc5d9d3f30)
     at mail-storage.c:1700
No locals.
#23 0x00007f517ec7bbce in quota_count_mailbox (root=0x2017ef0, 
root=0x2017ef0, ns=0x201d300, count=0x7ffc5d9d3fd0, bytes=0x7ffc5d9d3fc8,
     vname=0x2024870 "MAIL_DE LIVE 05_04_2014 13:58.Sent") at 
quota-count.c:48
         rule = <optimized out>
         box = 0x2028fc0
         status = {messages = 0, recent = 0, unseen = 0, uidvalidity = 
0, uidnext = 1, first_unseen_seq = 0, first_recent_uid = 0,
           last_cached_seq = 0, highest_modseq = 0, highest_pvt_modseq = 
0, keywords = 0x0, permanent_flags = 0, permanent_keywords = 0,
           allow_new_keywords = 0, nonpermanent_modseqs = 0, 
no_modseq_tracking = 0, have_guids = 1, have_save_guids = 1, 
have_only_guid128 = 0}
         errstr = <optimized out>
         ret = <optimized out>
         metadata = {guid = '\000' <repeats 15 times>, virtual_size = 0, 
physical_size = 0, first_save_date = 0, cache_fields = 0x0,
           precache_fields = (unknown: 0), backend_ns_prefix = 0x0, 
backend_ns_type = (unknown: 0)}
         error = 32593
#24 quota_count (root=0x2017ef0, bytes_r=0x7ffc5d9d3fc8, 
count_r=0x7ffc5d9d3fd0) at quota-count.c:159
         iter = 0x2023fd0
         info = <optimized out>
         ret = 1
         count_r = 0x7ffc5d9d3fd0
         bytes_r = 0x7ffc5d9d3fc8
         root = 0x2017ef0
#25 0x00007f517ec7bd3e in quota_count_cached (count_r=0x7ffc5d9d3fd0, 
bytes_r=0x7ffc5d9d3fc8, root=0x2017ef0) at quota-count.c:185
         ret = <optimized out>
#26 count_quota_get_resource (_root=0x2017ef0, name=0x7f517ec82a6c 
"STORAGE_BYTES", value_r=0x7ffc5d9d4098) at quota-count.c:234
         root = 0x2017ef0
         bytes = 0
         count = 0
#27 0x00007f517ec7a578 in quota_get_resource (root=root at entry=0x2017ef0, 
mailbox_name=mailbox_name at entry=0x7f517ec8362c "",
     name=0x7f517ec82a6c "STORAGE_BYTES", 
value_r=value_r at entry=0x7ffc5d9d4098, 
limit_r=limit_r at entry=0x7ffc5d9d40a0) at quota.c:696
         bytes_limit = 16395163946287022080
         count_limit = 0
         ignored = false
         kilobytes = true
         ret = <optimized out>
#28 0x00007f517ec7a8b4 in quota_over_flag_check_root (root=0x2017ef0) at 
quota.c:1063
         name = <optimized out>
         overquota_script = <optimized out>
         resources = 0x7f517ee86600 <resources>
         i = 0
         value = 0
         limit = 0
         cur_overquota = false
         ret = <optimized out>
#29 0x00007f517ec7b3f8 in quota_over_flag_check_startup 
(quota=<optimized out>) at quota.c:1105
         i = <optimized out>
         count = <optimized out>
         name = <optimized out>
#30 0x00007f517f7b71ae in hook_mail_namespaces_created 
(namespaces=0x201d300) at mail-storage-hooks.c:296
         _data_stack_cur_id = 4
         hooks__foreach_end = 0x201b530
         hooks = 0x201b500
#31 0x00007f517f7ac45f in mail_namespaces_init_finish 
(namespaces=0x201d300, error_r=error_r at entry=0x7ffc5d9d42b0) at 
mail-namespace.c:357
         _data_stack_cur_id = 3
         ns = 0x0
         prefixless_found = <optimized out>
         __FUNCTION__ = "mail_namespaces_init_finish"
#32 0x00007f517f7ac674 in mail_namespaces_init (user=0x2019330, 
error_r=error_r at entry=0x7ffc5d9d42b0) at mail-namespace.c:405
         mail_set = 0x201a218
         namespaces = 0x201d300
         ns_p = <optimized out>
         i = <optimized out>
         count = <optimized out>
         count2 = <optimized out>
         __FUNCTION__ = "mail_namespaces_init"
#33 0x00007f517f7ba275 in mail_storage_service_init_post (ctx=0x2005030, 
error_r=0x7ffc5d9d42b0, mail_user_r=<optimized out>,
     priv=0x7ffc5d9d42c0, user=0x2005030) at mail-storage-service.c:730
         mail_set = 0x201a218
         home = 0x20061f9 "/mnt/storage/xxx/yyy/zzz"
         mail_user = 0x2019330
#34 mail_storage_service_next_real (mail_user_r=<optimized out>, 
user=0x2005030, ctx=0x2005030) at mail-storage-service.c:1428
         len = <optimized out>
         temp_priv_drop = <optimized out>
         priv = {uid = 5000, gid = 1, uid_source = 0x7f517f85e660 
"userdb lookup", gid_source = 0x7f517f85e660 "userdb lookup",
           home = 0x20061f9 "/mnt/storage/xxx/yyy/zzz", chroot = 
0x1ff73f8 ""}
         error = 0x5b5b5b5b5b5b5b5b <error: Cannot access memory at 
address 0x5b5b5b5b5b5b5b5b>
         disallow_root = <optimized out>
         use_chroot = <optimized out>
#35 mail_storage_service_next (ctx=ctx at entry=0x20007c0, user=0x2005030, 
mail_user_r=mail_user_r at entry=0x7ffc5d9d4390)
     at mail-storage-service.c:1446
         old_log_prefix = 0x2004e40 "imap(test at domain.de): "
#36 0x00007f517f7ba5dc in mail_storage_service_lookup_next 
(ctx=0x20007c0, input=input at entry=0x7ffc5d9d4400,
     user_r=user_r at entry=0x7ffc5d9d4388, 
mail_user_r=mail_user_r at entry=0x7ffc5d9d4390, 
error_r=error_r at entry=0x7ffc5d9d43f8)
     at mail-storage-service.c:1479
         user = 0x2005030
         ret = <optimized out>
#37 0x0000000000425476 in client_create_from_input 
(input=input at entry=0x7ffc5d9d4400, fd_in=7, fd_out=7,
     client_r=client_r at entry=0x7ffc5d9d43f0, 
error_r=error_r at entry=0x7ffc5d9d43f8) at main.c:228
         user = 0x7ffc5d9d44e0
         mail_user = 0x2000250
         ns = <optimized out>
         client = <optimized out>
         imap_set = <optimized out>
         lda_set = <optimized out>
         errstr = <optimized out>
         mail_error = MAIL_ERROR_NONE
#38 0x000000000042567f in login_client_connected 
(login_client=0x2002a10, username=<optimized out>, 
extra_fields=<optimized out>) at main.c:316
         input = {module = 0x42dacc "imap", service = 0x42dacc "imap", 
username = 0x1ff604b "test at domain.de",
           session_id = 0x2002a90 "wYnbg9VGoOYKAHZl", session_id_prefix 
= 0x0, session_create_time = 0, local_ip = {family = 2, u = {ip6 = {
                 __in6_u = {__u6_addr8 = "\n\000v\265", '\000' <repeats 
11 times>, __u6_addr16 = {10, 46454, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {
                     3044409354, 0, 0, 0}}}, ip4 = {s_addr = 
3044409354}}}, remote_ip = {family = 2, u = {ip6 = {__in6_u = {
                   __u6_addr8 = "\n\000ve", '\000' <repeats 11 times>, 
__u6_addr16 = {10, 25974, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {1702232074,
                     0, 0, 0}}}, ip4 = {s_addr = 1702232074}}}, 
local_port = 0, remote_port = 0, userdb_fields = 0x1ff6158,
           flags_override_add = (unknown: 0), flags_override_remove = 
(unknown: 0), no_userdb_lookup = 0, debug = 0}
         client = 0x7ffc5d9d4400
         flags = <optimized out>
         error = 0xe38752be6cbac000 <error: Cannot access memory at 
address 0xe38752be6cbac000>
         __FUNCTION__ = "login_client_connected"
#39 0x00007f517f48570e in master_login_auth_finish (client=0x2002a10, 
auth_args=auth_args at entry=0x1ff6150) at master-login.c:210
         login = 0x2001d20
         service = 0x1ffe5d0
         close_sockets = true
         __FUNCTION__ = "master_login_auth_finish"
#40 0x00007f517f4859bd in master_login_auth_callback 
(auth_args=0x1ff6150, errormsg=0x0, context=<optimized out>) at 
master-login.c:379
         client = 0x2002a10
         conn = 0x2002810
         reply = {tag = 7, status = MASTER_AUTH_STATUS_OK, mail_pid = 25953}
#41 0x00007f517f48635a in master_login_auth_input_user (args=<optimized 
out>, auth=<optimized out>) at master-login-auth.c:244
         request = 0x2001c20
         list = 0x1ff6148
         id = 3972268033
#42 master_login_auth_input (auth=0x2001da0) at master-login-auth.c:364
         line = <optimized out>
#43 0x00007f517f4fc68c in io_loop_call_io (io=0x2001ca0) at ioloop.c:589
         ioloop = 0x1ffe730
         t_id = 2
         __FUNCTION__ = "io_loop_call_io"
#44 0x00007f517f4fdb79 in io_loop_handler_run_internal 
(ioloop=ioloop at entry=0x1ffe730) at ioloop-epoll.c:222
         ctx = 0x2000250
         io = <optimized out>
         tv = {tv_sec = 154, tv_usec = 999151}
         events_count = <optimized out>
         msecs = <optimized out>
         ret = 1
         i = 0
         j = <optimized out>
         call = <optimized out>
         __FUNCTION__ = "io_loop_handler_run_internal"
#45 0x00007f517f4fc715 in io_loop_handler_run 
(ioloop=ioloop at entry=0x1ffe730) at ioloop.c:637
No locals.
#46 0x00007f517f4fc8b8 in io_loop_run (ioloop=0x1ffe730) at ioloop.c:613
         __FUNCTION__ = "io_loop_run"
#47 0x00007f517f487ca3 in master_service_run (service=0x1ffe5d0, 
callback=callback at entry=0x424e10 <client_connected>) at master-service.c:641
No locals.
#48 0x000000000040c622 in main (argc=1, argv=0x1ffe390) at main.c:460
         set_roots = {0x42db60 <imap_setting_parser_info>, 0x637180 
<lda_setting_parser_info>, 0x0}
         login_set = {auth_socket_path = 0x1ff6058 "uid=5000", 
postlogin_socket_path = 0x0, postlogin_timeout_secs = 60,
           callback = 0x4255e0 <login_client_connected>, 
failure_callback = 0x424f20 <login_client_failed>, request_auth_token = 1}
         service_flags = <optimized out>
         storage_service_flags = <optimized out>
         username = 0x0
         auth_socket_path = 0x42ea71 "auth-master"
         c = <optimized out>


More information about the dovecot mailing list