More information about - Dovecot 2.2.x quota mysql and dict

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|

More information about - Dovecot 2.2.x quota mysql and dict

Simon
I some add information about bug...


Dovecot 2.2.19 version on server FreeBSD 10.2 Release.
Config quota (dict + mysql)
Database create Postfixadmin 2.3.7

Old version Dovecot 2.2.13 use method UPDATE in MySQL base + dict
example mysql.log
-----------------
Connect   postfix@localhost on postfix
            134 Query     SELECT bytes FROM quota2 WHERE username = 'user@mydomain.lan'
            135 Query     SELECT bytes FROM quota2 WHERE username = 'user@mydomain.lan'
            135 Query     BEGIN
            135 Query     UPDATE quota2 SET bytes=bytes+2570,messages=messages+1 WHERE username = 'user@mydomain.lan'
            136 Connect   postfix@localhost on postfix
            136 Query     BEGIN
            136 Query     UPDATE domain SET quota=quota+2570 WHERE domain = 'mydomain.lan'
            134 Query     BEGIN
            134 Query     UPDATE quota2 SET bytes=bytes+1723,messages=messages+1 WHERE username = 'user@mydomain.lan'
            137 Connect   postfix@localhost on postfix
            137 Query     BEGIN
            137 Query     UPDATE domain SET quota=quota+1723 WHERE domain = 'mydomain.lan'
            136 Query     UPDATE quota2 SET messages=messages+1 WHERE username = 'mydomain.lan'
            - - -
            137 Query     COMMIT
151004  3:12:27   128 Quit
-----------------

# cat dovecot-2.2.13/src/lib-dict/dict-sql.c
=== some text delete ===

static const char *
sql_dict_update_query(const struct dict_sql_build_query *build)
{
      struct sql_dict *dict = build->dict;
      const struct dict_sql_build_query_field *fields;
      unsigned int i, field_count;
      string_t *query;

      i_assert(build->inc);

      fields = array_get(&build->fields, &field_count);
      i_assert(field_count > 0);

      query = t_str_new(64);
      str_printfa(query, "UPDATE %s SET ", fields[0].map->table); #### this in code, work excellent
      for (i = 0; i < field_count; i++) {
              if (i > 0)
                      str_append_c(query, ',');
              str_printfa(query, "%s=%s", fields[i].map->value_field,
                          fields[i].map->value_field);
              if (fields[i].value[0] != '-')
                      str_append_c(query, '+');
              str_append(query, fields[i].value);
      }

      sql_dict_where_build(dict, fields[0].map, build->extra_values,
                           build->key1, SQL_DICT_RECURSE_NONE, query);
      return str_c(query);
}

=== === ===


Latest version Dovecot 2.2.19 use method DELETE/INSERT in MySQL base + dict

            140 Connect   postfix@localhost on postfix
            140 Query     SELECT quota FROM domain WHERE domain = 'mydomain.lan'
            140 Query     SELECT quota FROM domain WHERE domain = 'mydomain.lan'
            140 Query     SELECT messages FROM quota2 WHERE username = 'mydomain.lan'
            140 Query     BEGIN
            140 Query     DELETE FROM domain WHERE domain = 'mydomain.lan'
            140 Query     DELETE FROM quota2 WHERE username = 'mydomain.lan'
            140 Query     INSERT INTO domain (quota,domain) VALUES ('8581','mydomain.lan') ON DUPLICATE KEY UPDATE quota='8581'
151004 15:18:45  140 Quit

# cat dovecot-2.2.19/src/lib-dict/dict-sql.c
=== some text delete ===

static void sql_dict_unset(struct dict_transaction_context *_ctx,
                         const char *key)
{
      struct sql_dict_transaction_context *ctx =
              (struct sql_dict_transaction_context *)_ctx;
      struct sql_dict *dict = (struct sql_dict *)_ctx->dict;
      const struct dict_sql_map *map;
      ARRAY_TYPE(const_string) values;

      if (ctx->prev_inc_map != NULL)
              sql_dict_prev_inc_flush(ctx);

      map = sql_dict_find_map(dict, key, &values);
      if (map == NULL) {
              i_error("sql dict unset: Invalid/unmapped key: %s", key);
              ctx->failed = TRUE;
              return;
      }

      T_BEGIN {
              string_t *query = t_str_new(256);
              const char *error;

              str_printfa(query, "DELETE FROM %s", map->table);   #### here deleted all information about domain, this code i think need change
              if (sql_dict_where_build(dict, map, &values, key[0],
                                       SQL_DICT_RECURSE_NONE, query, &error) < 0) {
                      i_error("dict-sql: Failed to delete %s: %s", key, error);
                      ctx->failed = TRUE;
              } else {
                      sql_update(ctx->sql_ctx, str_c(query));
              }
      } T_END;
}
=== === ===



Now dic + mysql doesn’t work in Dovecot 2.2.19, because first DELETE operator delete information from base about my domain mydomain.lan  

Thanks!

Simon.
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Simon
I am sorry... but may be already somebody solved this bug ?
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Timo Sirainen
In reply to this post by Simon
On 07 Oct 2015, at 01:34, Simon <[hidden email]> wrote:

>
> I some add information about bug...
>
>
> Dovecot 2.2.19 version on server FreeBSD 10.2 Release.
> Config quota (dict + mysql)
> Database create Postfixadmin 2.3.7
>
> Old version Dovecot 2.2.13 use method UPDATE in MySQL base + dict
> example mysql.log
> -----------------
> Connect   postfix@localhost on postfix
>            134 Query     SELECT bytes FROM quota2 WHERE username =
> '[hidden email]'
>            135 Query     SELECT bytes FROM quota2 WHERE username =
> '[hidden email]'
>            135 Query     BEGIN
>            135 Query     UPDATE quota2 SET
> bytes=bytes+2570,messages=messages+1 WHERE username = '[hidden email]'

Here's it's updating quota with [hidden email]

>            140 Query     SELECT messages FROM quota2 WHERE username =
> 'mydomain.lan'
>            140 Query     BEGIN
>            140 Query     DELETE FROM domain WHERE domain = 'mydomain.lan'
>            140 Query     DELETE FROM quota2 WHERE username = 'mydomain.lan'
>            140 Query     INSERT INTO domain (quota,domain) VALUES
> ('8581','mydomain.lan') ON DUPLICATE KEY UPDATE quota='8581'
> 151004 15:18:45  140 Quit

Here it's only mydomain.lan. So something's not right.

> Now dic + mysql doesn’t work in Dovecot 2.2.19, because first DELETE
> operator delete information from base about my domain mydomain.lan  

I can't reproduce this. What's your doveconf -n output? And what's in the dovecot-dict-sql.conf.ext?
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Simon
Thanks for your answer, Timo! :)

I send to you my configoration for reproducing.
Please, follow the link, because configuration is a very big, there will be more easy to read and understand
My configuration Dovecot 2.2.19

Below the same my configuration Dovecot 2.2.19 here.
BEGIN of configuration
---------------------

# doveconf -n

# 2.2.19: /usr/local/etc/dovecot/dovecot.conf
# OS: FreeBSD 10.2-RELEASE amd64  ufs
auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = plain login cram-md5
auth_verbose = yes
base_dir = /var/run/dovecot/

first_valid_gid = 1983
first_valid_uid = 1983
listen = *
log_path = /var/log/dovecot.log
mail_debug = yes
mail_gid = virtual
mail_location = maildir:/var/spool/mail/%d/%u
mail_uid = virtual

passdb {
  args = /usr/local/etc/dovecot/dovecot-sql.conf
  driver = sql
}

dict {
  sqluserquota = mysql:/usr/local/etc/dovecot/dovecot-dict-sql-user.conf
  sqldomainquota = mysql:/usr/local/etc/dovecot/dovecot-dict-sql-domain.conf
}

plugin {
  quota = dict:domain_quota:%d:proxy::sqldomainquota
  quota2 = dict:user_quota::proxy::sqluserquota
  quota2_rule2 = Trash:storage=+20%%
  quota2_rule3 = Junk:storage=+20%%
  quota2_grace = 10%%
  quota2_warning = storage=100%% quota-exceeded 100 %u
  quota2_warning2 = storage=95%% quota-warning 95 %u
  quota2_warning3 = storage=90%% quota-warning 90 %u
  quota2_warning4 = storage=75%% quota-warning 75 %u
}

service quota-warning {
  executable = script /usr/local/etc/dovecot/quota_warning.sh
  unix_listener quota-warning {
    mode = 0660
    user = virtual
  }
}

protocols = imap pop3
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
  unix_listener auth-master {
    group = virtual
    mode = 0660
    user = virtual
  }
  unix_listener auth-userdb {
    group = virtual
    mode = 0660
    user = virtual
  }
}
service dict {
  unix_listener dict {
    mode = 0660
    user = virtual
  }
}

service imap-login {
  client_limit = 256
  inet_listener imap {
    address = *
    port = 143
  }
  inet_listener imaps {
    address = *
    port = 993
  }
  process_limit = 64
  process_min_avail = 8
  service_count = 1
}

service pop3-login {
  inet_listener pop3 {
    address = *
    port = 110
  }
  inet_listener pop3s {
    address = *
    port = 995
  }
}

ssl_cert = </usr/local/etc/postfix/cert.pem
ssl_key = </usr/local/etc/postfix/key.pem
ssl_parameters_regenerate = 1 hours
ssl_require_crl = no
userdb {
  args = /usr/local/etc/dovecot/dovecot-sql.conf
  driver = sql
}

verbose_proctitle = yes
verbose_ssl = yes
protocol imap {
  imap_client_workarounds = delay-newmail tb-lsub-flags tb-extra-mailbox-sep
  imap_idle_notify_interval = 2 mins
  mail_max_userip_connections = 10
  mail_plugin_dir = /usr/local/lib/dovecot
  mail_plugins = " quota imap_quota"
  quota_full_tempfail = yes
}

protocol pop3 {
  pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
  pop3_uidl_format = %08Xu%08Xv
}

protocol lda {
  auth_socket_path = /var/run/dovecot/auth-master
  hostname = mydomain.lan
  lda_mailbox_autocreate = yes
  lda_mailbox_autosubscribe = yes
  lda_original_recipient_header =
  mail_plugins = " quota"
  postmaster_address = postmaster@mydomain.lan
}


--------------------------
-= END of dovecot.conf  =-
-------------------------------------------------------------------------


# cat dovecot-sql.conf | grep -v ^# | grep -v ^$

driver = mysql
connect = host=localhost dbname=postfix user=postfix password=mypassword
default_pass_scheme = CRAM-MD5

password_query = SELECT username, domain, password \
FROM mailbox WHERE username = '%u' and domain = '%d' and active='1' \

user_query = SELECT '/var/spool/mail/%d/%u' AS home, \
'maildir:/var/spool/mail/%d/%u' AS mail, 1983 AS uid, 1983 AS gid, \
CONCAT('*:bytes=', domain.maxquota*1048576) AS quota_rule, \
CONCAT('*:bytes=', mailbox.quota) AS quota2_rule \
FROM mailbox, domain WHERE username = '%u' AND mailbox.active = '1' \
AND domain.domain = '%d' AND domain.active = '1'


-------------------------------------------------------------------------


# cat dovecot-dict-sql-domain.conf

connect = host=localhost dbname=postfix user=postfix password=mypassword
map {
    pattern = priv/quota/storage
    table = domain
    username_field = domain
    value_field = quota
}
map {
    pattern = priv/quota/messages
    table = quota2
    username_field = username
    value_field = messages
}


-------------------------------------------------------------------------


# cat dovecot-dict-sql-user.conf

connect = host=localhost dbname=postfix user=postfix password=mypassword
map {
  pattern = priv/quota/storage
  table = quota2
  username_field = username
  value_field = bytes
}
map {
  pattern = priv/quota/messages
  table = quota2
  username_field = username
  value_field = messages
}

-------------------------
-= END of configuration =-
-------------------------

If need anymore about configuration, please write me.
Today I can respond quickly.
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Timo Sirainen
On 17 Oct 2015, at 13:29, Simon <[hidden email]> wrote:
>
> Thanks for your answer, Timo! :)
>
> I send to you my configoration for reproducing.
..
> If need anymore about configuration, please write me.
> Today I can respond quickly.

What does Dovecot log when you deliver a new mail (with auth_debug=yes and mail_debug=yes enabled)?
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Simon
192.168.7.184 -Client - Mozilla Thunderbird (latest version)
192.168.7.185 - Server Dovecot 2.2.19

# vim dovecot.log
===============

Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 auth: Debug: auth client connected (pid=14842)
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Oct 04 15:17:45 auth: Debug: auth client connected (pid=14843)
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [192.168.7.184]
Oct 04 15:17:45 auth: Debug: client in: AUTH    1       CRAM-MD5        service=imap    secured session=Zt5gYkYhjQDAqAe4        lip=192.168.7.185       rip=192.168.7.184       lport=143       rport=59277
Oct 04 15:17:45 auth: Debug: client passdb out: CONT    1       PDU2NzIwMjE3OTU1MDYwMjguMTQ0Mzk2MTA2NUBzZXJ2Nz4=
Oct 04 15:17:45 auth: Debug: client in: CONT    1       c2VtZmx5QGZseTc3Ny5uZXQgNmY2Y2FiNTc3YjQ4ZTE1OGE4NzU4NzkwZjdkNzhmN2U= (previous base64 data may contain sensitive data)
Oct 04 15:17:45 auth-worker(14845): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth
Oct 04 15:17:45 auth-worker(14845): Debug: sql(simon@mydomain.lan,192.168.7.184): query: SELECT username as user, password FROM mailbox WHERE username = 'simon@mydomain.lan' and active='1'
Oct 04 15:17:45 auth: Debug: sql(simon@mydomain.lan,192.168.7.184,<Zt5gYkYhjQDAqAe4>): Credentials: 6df356c95df134db8c7ad557c31c752ed2ffcb7a9ff613748af3c43036a7370c
Oct 04 15:17:45 auth: Debug: client passdb out: OK      1       user=simon@mydomain.lan
Oct 04 15:17:45 auth: Debug: master in: REQUEST 3765567489      14836   1       982fc0b6f6ecf6098e257ccac0abbe3d        session_pid=14846       request_auth_token
Oct 04 15:17:45 auth-worker(14845): Debug: sql(simon@mydomain.lan,192.168.7.184): SELECT '/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS home, 'maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS mail, 1983 AS uid, 1983 AS gid, CONCAT('*:bytes=', domain.maxquota*1048576) AS quota_rule, CONCAT('*:bytes=', mailbox.quota) AS quota2_rule FROM mailbox, domain WHERE username = 'simon@mydomain.lan' AND mailbox.active = '1' AND domain.domain = 'mydomain.lan' AND domain.active = '1'
Oct 04 15:17:45 auth: Debug: master userdb out: USER    3765567489      simon@mydomain.lan       home=/var/spool/mail/mydomain.lan/simon@mydomain.lan       mail=maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan       uid=1983        gid=1983        quota_rule=*:bytes=7516192768   quota2_rule=*:bytes=7516192768  auth_token=71e913f2c5640c009de725f121c5bf5a5aa31198
Oct 04 15:17:45 imap-login: Info: Login: user=<simon@mydomain.lan>, method=CRAM-MD5, rip=192.168.7.184, lip=192.168.7.185, mpid=14846, TLS, session=<Zt5gYkYhjQDAqAe4>
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [192.168.7.184]
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Loading modules from directory: /usr/local/lib/dovecot
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting: mail=maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting: plugin/quota2_rule=*:bytes=7516192768
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Added userdb setting: plugin/quota_rule=*:bytes=7516192768
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Effective uid=1983, gid=1983, home=/var/spool/mail/mydomain.lan/simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota root: name=domain_quota backend=dict args=mydomain.lan:proxy::sqldomainquota
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=domain_quota mailbox=* bytes=7516192768 messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota grace: root=domain_quota bytes=751619276 (10%)
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota root: name=user_quota backend=dict args=:proxy::sqluserquota
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota mailbox=* bytes=7516192768 messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota mailbox=Trash bytes=+1503238553 (20%) messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota rule: root=user_quota mailbox=Junk bytes=+1503238553 (20%) messages=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning: bytes=7516192768 (100%) messages=0 reverse=no command=quota-exceeded 100 simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning: bytes=7140383129 (95%) messages=0 reverse=no command=quota-warning 95 simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning: bytes=6764573491 (90%) messages=0 reverse=no command=quota-warning 90 simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota warning: bytes=5637144576 (75%) messages=0 reverse=no command=quota-warning 75 simon@mydomain.lan
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: Quota grace: root=user_quota bytes=751619276 (10%)
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: dict quota: user=mydomain.lan, uri=proxy::sqldomainquota, noenforcing=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: dict quota: user=simon@mydomain.lan, uri=proxy::sqluserquota, noenforcing=0
Oct 04 15:17:45 imap(simon@mydomain.lan): Debug: maildir++: root=/var/spool/mail/mydomain.lan/simon@mydomain.lan, index=, indexpvt=, control=, inbox=/var/spool/mail/mydomain.lan/simon@mydomain.lan, alt=
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client certificate A [192.168.7.184]
Oct 04 15:17:45 dict: Error: sql dict: commit failed: Field 'description' doesn't have a default value
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [192.168.7.184]
Oct 04 15:17:45 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [192.168.7.184]
Oct 04 15:17:45 auth: Debug: client in: AUTH    1       CRAM-MD5        service=imap    secured session=gPtjYkYhjgDAqAe4        lip=192.168.7.185       rip=192.168.7.184       lport=143       rport=59278
Oct 04 15:17:45 auth: Debug: client passdb out: CONT    1       PDYwNDQwODUxNzAwMzE2NDEuMTQ0Mzk2MTA2NUBzZXJ2Nz4=
Oct 04 15:17:45 auth: Debug: client in: CONT    1       c2VtZmx5QGZseTc3Ny5uZXQgZTAzYzdjY2I3OGRmMDE1MmZmOTMzNTdmMzMyMmFmZmU= (previous base64 data may contain sensitive data)
Oct 04 15:17:45 auth-worker(14845): Debug: sql(simon@mydomain.lan,192.168.7.184): query: SELECT username as user, password FROM mailbox WHERE username = 'simon@mydomain.lan' and active='1'
Oct 04 15:17:45 auth: Debug: sql(simon@mydomain.lan,192.168.7.184,<gPtjYkYhjgDAqAe4>): Credentials: 6df356c95df134db8c7ad557c31c752ed2ffcb7a9ff613748af3c43036a7370c
Oct 04 15:17:45 auth: Debug: client passdb out: OK      1       user=simon@mydomain.lan
Oct 04 15:17:45 auth: Debug: master in: REQUEST 592969729       13563   1       eda35ea2307a82f2dec1b894530f1d09        session_pid=14849       request_auth_token
Oct 04 15:17:45 auth-worker(14845): Debug: sql(simon@mydomain.lan,192.168.7.184): SELECT '/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS home, 'maildir:/var/spool/mail/mydomain.lan/simon@mydomain.lan' AS mail, 1983 AS uid, 1983 AS gid, CONCAT('*:bytes=', domain.maxquota*1048576) AS quota_rule, CONCAT('*:bytes=', mailbox.quota) AS quota2_rule FROM mailbox, domain WHERE username = 'simon@mydomain.lan' AND mailbox.active = '1' AND domain.domain = 'mydomain.lan' AND domain.active = '1'
Oct 04 15:17:45 auth-worker(14845): Info: sql(simon@mydomain.lan,192.168.7.184): unknown user
Oct 04 15:17:45 auth: Error: sql(simon@mydomain.lan,192.168.7.184,<gPtjYkYhjgDAqAe4>): user not found from userdb
Oct 04 15:17:45 auth: Debug: master userdb out: NOTFOUND        592969729
Oct 04 15:17:45 imap: Error: Authenticated user not found from userdb, auth lookup id=592969729 (client-pid=13563 client-id=1)
Oct 04 15:17:45 imap-login: Info: Internal login failure (pid=13563 id=1) (internal failure, 1 successful auths): user=<simon@mydomain.lan>, method=CRAM-MD5, rip=192.168.7.184, lip=192.168.7.185, mpid=14849, TLS, session=<gPtjYkYhjgDAqAe4>
Oct 04 15:17:45 imap-login: Debug: SSL alert: close notify [192.168.7.184]
Oct 04 15:17:52 imap(simon@mydomain.lan): Info: Disconnected: Logged out in=184 out=1432
Oct 04 15:17:52 imap-login: Debug: SSL alert: close notify [192.168.7.184]

-= END of dovecot.log =-
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Timo Sirainen
In reply to this post by Timo Sirainen
On 17 Oct 2015, at 12:41, Timo Sirainen <[hidden email]> wrote:

>
>> Connect   postfix@localhost on postfix
>>           134 Query     SELECT bytes FROM quota2 WHERE username =
>> '[hidden email]'
>>           135 Query     SELECT bytes FROM quota2 WHERE username =
>> '[hidden email]'
>>           135 Query     BEGIN
>>           135 Query     UPDATE quota2 SET
>> bytes=bytes+2570,messages=messages+1 WHERE username = '[hidden email]'
>
> Here's it's updating quota with [hidden email]
>
>>           140 Query     SELECT messages FROM quota2 WHERE username =
>> 'mydomain.lan'
>>           140 Query     BEGIN
>>           140 Query     DELETE FROM domain WHERE domain = 'mydomain.lan'
>>           140 Query     DELETE FROM quota2 WHERE username = 'mydomain.lan'
>>           140 Query     INSERT INTO domain (quota,domain) VALUES
>> ('8581','mydomain.lan') ON DUPLICATE KEY UPDATE quota='8581'
>> 151004 15:18:45  140 Quit
>
> Here it's only mydomain.lan. So something's not right.

After seeing your configs, this makes more sense now, although it's a bit confusing. You're updating quota bytes to "domain" table, but quota messages to "quota2" table where both domain and user quotas are mixed.

>> Now dic + mysql doesn’t work in Dovecot 2.2.19, because first DELETE
>> operator delete information from base about my domain mydomain.lan  
>
> I can't reproduce this. What's your doveconf -n output? And what's in the dovecot-dict-sql.conf.ext?

I still couldn't reproduce this with your exact config. I think that there is no bug or change in behavior in v2.2.19. There are some situations when Dovecot wants to recalculate the quota (e.g. a message is expunged but its size isn't known). In these situations Dovecot recalculates the quota and does a DELETE + INSERT to dict. This code has been there since the beginning. Maybe you just happened to be finally triggering this situation. So it's not safe to place the quota updates to a table that has other information also. Also this means that the domain-quota doesn't work 100% in all situations and I guess some kind of a daily recalculation for them would be a good idea..
Reply | Threaded
Open this post in threaded view
|

Re: More information about - Dovecot 2.2.x quota mysql and dict

Timo Sirainen
On 19 Oct 2015, at 13:31, Timo Sirainen <[hidden email]> wrote:

>
> On 17 Oct 2015, at 12:41, Timo Sirainen <[hidden email]> wrote:
>>
>>> Connect   postfix@localhost on postfix
>>>          134 Query     SELECT bytes FROM quota2 WHERE username =
>>> '[hidden email]'
>>>          135 Query     SELECT bytes FROM quota2 WHERE username =
>>> '[hidden email]'
>>>          135 Query     BEGIN
>>>          135 Query     UPDATE quota2 SET
>>> bytes=bytes+2570,messages=messages+1 WHERE username = '[hidden email]'
>>
>> Here's it's updating quota with [hidden email]
>>
>>>          140 Query     SELECT messages FROM quota2 WHERE username =
>>> 'mydomain.lan'
>>>          140 Query     BEGIN
>>>          140 Query     DELETE FROM domain WHERE domain = 'mydomain.lan'
>>>          140 Query     DELETE FROM quota2 WHERE username = 'mydomain.lan'
>>>          140 Query     INSERT INTO domain (quota,domain) VALUES
>>> ('8581','mydomain.lan') ON DUPLICATE KEY UPDATE quota='8581'
>>> 151004 15:18:45  140 Quit
>>
>> Here it's only mydomain.lan. So something's not right.
>
> After seeing your configs, this makes more sense now, although it's a bit confusing. You're updating quota bytes to "domain" table, but quota messages to "quota2" table where both domain and user quotas are mixed.

This is pretty much the issue here. The current code works exactly as it should, so I think the old code was buggy.. So what's happening with domain quota is:

 - priv/quota/storage maps to domain.quota field
 - priv/quota/messages maps to quota2.messages field

The domain table has all the domains, so updating it has worked fine. But apparently there were no domain entries in quota2 table? And apparently the old Dovecot code was simply ignoring this and never writing anything in there? So that would be a bug. When either the storage or the messages don't exist, Dovecot does a quota recalculation and writes the resulting recalculated fields. This recalculation does a DELETE + INSERT internally.

So there are 2 things you could do now..:

1) If you manually INSERT all the missing domains to quota table, the existing code continues to work. Because the domains exist there, there's no need for Dovecot to do a quota recalculation and DELETE anything.

2) This has never been 100% safe though. There has always been the possibility of quota recalculation deleting the domain. I've now added a "no-unset" parameter to dict:

  quota = dict:domain_quota:%d:no-unset:proxy::sqldomainquota

This disables the DELETEs completely. However quota recalculation still attempts to do:

INSERT INTO domain (quota,domain) VALUES ('5404','postdomain.lan') ON DUPLICATE KEY UPDATE quota='5404'

Which fails in your case, because MySQL wants the INSERT to be valid as well. You can kludge around it by changing MySQL schema with:

alter table domain alter description set default '';
alter table domain alter transport set default 'dovecot';

Now quota recalculation works as well. Except of course domain quota recalculation doesn't actually work correctly, because it calculates only the single user's quota and places it to the domain quota.