*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((17, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:12,311 pykolab.auth DEBUG [32659]: No results for address muster2@quetzalsailing.ch found
2016-06-05 18:23:12,311 pykolab.auth DEBUG [32659]: Recipient policy composed the following set of secondary email addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch']
2016-06-05 18:23:12,311 pykolab.auth DEBUG [32659]: Secondary mail addresses that we want is not None: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,311 pykolab.auth DEBUG [32659]: Avoiding the duplication of the primary mail address 'muster2@quetzalsailing.ch' in the list of secondary mail addresses
2016-06-05 18:23:12,311 pykolab.auth DEBUG [32659]: Entry is getting secondary mail addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,315 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,315 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,315 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:12,315 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:12,317 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,317 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,318 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:12,318 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:12,324 sqlalchemy.engine.base.Engine INFO INSERT INTO entry (uniqueid, result_attribute, last_change) VALUES (?, ?, ?)
2016-06-05 18:23:12,324 sqlalchemy.engine.base.Engine INFO INSERT INTO entry (uniqueid, result_attribute, last_change) VALUES (?, ?, ?)
2016-06-05 18:23:12,324 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 'muster2@quetzalsailing.ch', '2016-06-05 16:23:11.000000')
2016-06-05 18:23:12,324 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 'muster2@quetzalsailing.ch', '2016-06-05 16:23:11.000000')
2016-06-05 18:23:12,325 sqlalchemy.engine.base.Engine INFO COMMIT
2016-06-05 18:23:12,325 sqlalchemy.engine.base.Engine INFO COMMIT
2016-06-05 18:23:12,361 sqlalchemy.engine.base.Engine INFO BEGIN (implicit)
2016-06-05 18:23:12,361 sqlalchemy.engine.base.Engine INFO BEGIN (implicit)
2016-06-05 18:23:12,362 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,362 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:12,362 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:12,362 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
23:16.93 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB8', 'NO', 'Quota root does not exist')
23:16.93 NO response: Quota root does not exist
[GETQUOTA user/muster2@quetzalsailing.ch] BAD: Quota root does not exist
2016-06-05 18:23:16,934 pykolab.auth DEBUG [32659]: About to consider the user quota for 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch' (used: None, imap: None, ldap: None, default: 0
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((25, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((25, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((25, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((25, False, 0, 0, 0, 0), {})
2016-06-05 18:23:17,548 pykolab.auth DEBUG [32659]: Entry type: user
2016-06-05 18:23:17,550 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,550 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,550 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,550 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,552 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,552 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,552 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,552 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,553 pykolab.auth DEBUG [32659]: _bind called, but already bound
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((30, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,581 pykolab.auth DEBUG [32659]: No results for address muster2@quetzalsailing.ch found
2016-06-05 18:23:17,581 pykolab.auth DEBUG [32659]: Recipient policy composed the following set of secondary email addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch']
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: Secondary mail addresses that we want is not None: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: Avoiding the duplication of the primary mail address 'muster2@quetzalsailing.ch' in the list of secondary mail addresses
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: Entry is getting secondary mail addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,585 pykolab.imap DEBUG [32659]: Looking for folder 'user/muster2@quetzalsailing.ch', we found folders: [u'user/muster2@quetzalsailing.ch']
2016-06-05 18:23:17,585 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,585 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,588 pykolab.auth DEBUG [32659]: About to consider the user quota for 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch' (used: None, imap: None, ldap: '0', default: 0
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((32, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((32, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((32, False, 0, 0, 0, 0), {})
2016-06-05 18:23:17,594 pykolab.auth DEBUG [32659]: Entry type: user
2016-06-05 18:23:17,595 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,595 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,596 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,596 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,597 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,597 sqlalchemy.engine.base.Engine INFO SELECT entry.id AS entry_id, entry.uniqueid AS entry_uniqueid, entry.result_attribute AS entry_result_attribute, entry.last_change AS entry_last_change
FROM entry
WHERE entry.uniqueid = ?
LIMIT ? OFFSET ?
2016-06-05 18:23:17,597 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,597 sqlalchemy.engine.base.Engine INFO ('b8817181-2b3911e6-b4b7ab7b-af958009', 1, 0)
2016-06-05 18:23:17,598 pykolab.auth DEBUG [32659]: _bind called, but already bound
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((37, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: No results for address muster2@quetzalsailing.ch found
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: Recipient policy composed the following set of secondary email addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch']
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: Secondary mail addresses that we want is not None: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: Avoiding the duplication of the primary mail address 'muster2@quetzalsailing.ch' in the list of secondary mail addresses
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: Entry is getting secondary mail addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,628 pykolab.imap DEBUG [32659]: Looking for folder 'user/muster2@quetzalsailing.ch', we found folders: [u'user/muster2@quetzalsailing.ch']
2016-06-05 18:23:17,628 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,628 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,631 pykolab.auth DEBUG [32659]: About to consider the user quota for 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch' (used: None, imap: None, ldap: '0', default: 0