Panic: file mail-transaction-log-file.c: line 105 (mail_transaction_log_file_free): assertion failed: (!file->locked)

[Arkadiusz Miśkiewicz]

On 27/03/2019 16:12, Timo Sirainen wrote:
> On 27 Mar 2019, at 14.58, Timo Sirainen via dovecot <dovecot at dovecot.org
> <mailto:dovecot at dovecot.org>> wrote:
>>
>>> dovecot isn't able to auto fix the indexes and manual deletion is
>>> required in all such cases
>>
>> So if it keeps repeating, it's very strange. Could you send me such
>> broken dovecot.index and dovecot.index.log files (without
>> dovecot.index.cache)? They shouldn't contain anything sensitive (only
>> message flags).
> 
> Tested with the index files you sent. It gets fixed automatically in my
> tests.
> 
> The backtrace shows that after fsck it fails to write the fixed index to
> the disk, because mail_index_write() fails for some reason. Except
> there's no error logged about it, which is rather weird. Do you still
> have the lmtp core? Could you do:
> 
> fr 9
> p *log.index

(gdb) f 9
#9  0x00007f25fc9e709d in mail_transaction_log_move_to_memory
(log=0x55e3e2b81eb0) at mail-transaction-log.c:171
171			mail_transaction_log_close(log);
(gdb) *log.index
Undefined command: "".  Try "help".
(gdb) print *log.index
There is no member named index.
(gdb) print *log
$8 = {
  0x55e3e2b81c20,
  views = 0x0,
  filepath = 0x55e3e2c2adc0 "/var/mail/piast_efaktury/dovecot.index.log",
  filepath2 = 0x55e3e2b6f380 "/var/mail/piast_efaktury/dovecot.index.log.2",
  files = 0x55e3e2b7ab20,
  head = 0x55e3e2b7ab20,
  open_file = 0x0,
  dotlock_count = 0,
  dotlock = 0x0,
  nfs_flush = false,
  log_2_unlink_checked = true
}
(gdb) print *(struct mail_index *)0x55e3e2b81c20
$15 = {
  dir = 0x55e3e2ba8970 "/var/mail/piast_efaktury",
  prefix = 0x55e3e2baa1a0 "dovecot.index",
  cache_dir = 0x55e3e2b888c0 "/var/mail/piast_efaktury",
  event = 0x55e3e2b7a930,
  cache = 0x0,
  log = 0x55e3e2b81eb0,
  open_count = 0,
  flags = (MAIL_INDEX_OPEN_FLAG_CREATE |
MAIL_INDEX_OPEN_FLAG_DOTLOCK_USE_EXCL | MAIL_INDEX_OPEN_FLAG_SAVEONLY),
  fsync_mode = FSYNC_MODE_OPTIMIZED,
  fsync_mask = (unknown: 0),
  mode = 384,
  gid = 4294967295,
  gid_origin = 0x55e3e2c2ad60 "/var/mail/piast_efaktury",
  optimization_set = {
    {
      rewrite_min_log_bytes = 8192,
      rewrite_max_log_bytes = 131072
    },
    log = {
      min_size = 32768,
      max_size = 1048576,
      min_age_secs = 300,
      log2_max_age_secs = 172800
    },
    cache = {
      unaccessed_field_drop_secs = 2592000,
      record_max_size = 65536,
      compress_min_size = 32768,
      compress_delete_percentage = 20,
      compress_continued_percentage = 200,
      compress_header_continue_count = 4
    }
  },
  pending_log2_rotate_time = 0,
  extension_pool = 0x55e3e2c2bf90,
  extensions = {
    arr = {
      buffer = 0x55e3e2c2bfb8,
      element_size = 48
    },
    v = 0x55e3e2c2bfb8,
    v_modifiable = 0x55e3e2c2bfb8
  },
  ext_hdr_init_id = 0,
  ext_hdr_init_data = 0x0,
  sync_lost_handlers = {
    arr = {
      buffer = 0x55e3e2b41900,
      element_size = 8
    },
    v = 0x55e3e2b41900,
    v_modifiable = 0x55e3e2b41900
--Type <RET> for more, q to quit, c to continue without paging--c
  },
  filepath = 0x55e3e2c2ad90 "/var/mail/piast_efaktury/dovecot.index",
  fd = 16,
  map = 0x55e3e2c2c380,
  last_mmap_error_time = 0,
  indexid = 1553597144,
  inconsistency_id = 0,
  last_read_log_file_seq = 13,
  last_read_log_file_tail_offset = 25648,
  fsck_log_head_file_seq = 15,
  fsck_log_head_file_offset = 40,
  sync_commit_result = 0x0,
  lock_method = FILE_LOCK_METHOD_FCNTL,
  max_lock_timeout_secs = 4294967295,
  keywords_pool = 0x55e3e2c2a400,
  keywords = {
    arr = {
      buffer = 0x55e3e2c2a5f0,
      element_size = 8
    },
    v = 0x55e3e2c2a5f0,
    v_modifiable = 0x55e3e2c2a5f0
  },
  keywords_hash = {
    _table = 0x55e3e2c2a6c0,
    _key = 0x55e3e2c2a6c0 "",
    _keyp = 0x55e3e2c2a6c0,
    _const_key = 0x55e3e2c2a6c0 "",
    _value = 0x55e3e2c2a6c0,
    _valuep = 0x55e3e2c2a6c0
  },
  keywords_ext_id = 0,
  modseq_ext_id = 1,
  views = 0x0,
  module_contexts = {
    arr = {
      buffer = 0x55e3e2b41940,
      element_size = 8
    },
    v = 0x55e3e2b41940,
    v_modifiable = 0x55e3e2b41940
  },
  error = 0x55e3e2b40ac0 "Fixed index file
/var/mail/piast_efaktury/dovecot.index: log_file_seq 13 -> 15",
  nodiskspace = true,
  index_lock_timeout = false,
  index_delete_requested = false,
  index_deleted = false,
  log_sync_locked = true,
  readonly = false,
  mapping = true,
  syncing = false,
  need_recreate = false,
  index_min_write = false,
  modseqs_enabled = false,
  initial_create = false,
  initial_mapped = false,
  fscked = true
}
(gdb)

-- 
Arkadiusz Miśkiewicz, arekm / ( maven.pl | pld-linux.org )