Page MenuHomePhorge
Files F165980

kolabd-create-new-account.log
tobru (Tobias Brunner)
Actions

Authored By
tobru
Jun 5 2016, 6:43 PM
Size
112 KB
Referenced Files
None
Subscribers
None

kolabd-create-new-account.log
View Options

2016-06-05 18:23:12,268 pykolab.auth DEBUG [32659]: LDAP Search Result Data Entry:
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: Entry: {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162311Z'], 'uid': ['muster2']}
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: Entry Change Notification attributes:
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: Change Type: 1 ('add')
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: Previous DN: None
2016-06-05 18:23:12,269 pykolab.auth DEBUG [32659]: auth.ldap.LDAP._synchronize_callback(args (), kw {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'change_type': 1, 'primary_domain': None, 'secondary_domains': [], 'entry': {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162311Z'], 'uid': ['muster2']}, 'previous_dn': None, 'change_number': None})
2016-06-05 18:23:12,270 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,270 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,270 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:12,270 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((11, False, 0, 0, 0, 0), {})
2016-06-05 18:23:12,273 pykolab.auth DEBUG [32659]: Entry type: user
2016-06-05 18:23:12,273 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,274 pykolab.auth DEBUG [32659]: Entry ID: {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'domain': 'quetzalsailing.ch', 'displayname': 'Muster2, Peter2', 'cn': 'Peter2 Muster2', 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'preferredlanguage': 'en_US', 'userpassword': '{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw==', 'nsuniqueid': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'id': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'objectclass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'sn': 'Muster2', 'mail': 'muster2@quetzalsailing.ch', 'surname': 'Muster2', 'givenname': 'Peter2', 'type': 'user', 'modifytimestamp': '20160605162311Z', 'uid': 'muster2'}
2016-06-05 18:23:12,274 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:12,274 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailhost']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailhost'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((12, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:12,275 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,275 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,275 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:12,275 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((13, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((13, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((13, False, 0, 0, 0, 0), {})
2016-06-05 18:23:12,276 pykolab.auth DEBUG [32659]: Applying recipient policy to 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:12,277 pykolab.auth DEBUG [32659]: Using mail attributes: ['mail', 'alias'], with primary 'mail' and secondary 'alias'
2016-06-05 18:23:12,277 pykolab.plugins DEBUG [32659]: Executing hook set_primary_mail for plugin recipientpolicy
2016-06-05 18:23:12,277 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2@quetzalsailing.ch' with locale 'en_US'
2016-06-05 18:23:12,277 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:12,277 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:12,278 pykolab.utils DEBUG [32659]: Executing 'Muster2@quetzalsailing.ch | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:12,286 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,287 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:12,287 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,287 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((14, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:12,288 pykolab.auth DEBUG [32659]: No results for mail address muster2@quetzalsailing.ch found
2016-06-05 18:23:12,289 pykolab.plugins DEBUG [32659]: Executing hook set_secondary_mail for plugin recipientpolicy
2016-06-05 18:23:12,289 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:12,289 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:12,289 pykolab.utils DEBUG [32659]: Transliterating string 'Peter2' with locale 'en_US'
2016-06-05 18:23:12,290 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:12,290 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:12,290 pykolab.utils DEBUG [32659]: Executing 'Peter2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:12,294 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:12,294 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:12,294 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:12,294 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:12,297 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:12,298 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:12,298 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:12,298 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:12,301 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:12,301 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:12,301 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:12,301 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:12,302 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:12,302 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:12,302 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,303 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:12,303 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,303 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((15, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:12,305 pykolab.auth DEBUG [32659]: No results for address peter2.muster2@quetzalsailing.ch found
2016-06-05 18:23:12,305 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,306 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:12,306 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,306 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((16, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:12,307 pykolab.auth DEBUG [32659]: No results for address p.muster2@quetzalsailing.ch found
2016-06-05 18:23:12,308 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:12,309 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:12,309 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:12,309 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <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,312 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,312 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,312 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,312 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:12,312 pykolab.auth DEBUG [32659]: Entry modifications list: {}
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,318 pykolab.auth_cache DEBUG [32659]: Inserting cache entry 'b8817181-2b3911e6-b4b7ab7b-af958009'
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:12.36 untagged responses dump:
CAPABILITY: "IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE"
23:12.36 > IOJM10 NOOP
23:12.36 < IOJM10 OK Completed
23:12.36 matched r'(?P<tag>IOJM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IOJM10', 'OK', 'Completed')
2016-06-05 18:23:12,365 pykolab.imap DEBUG [32659]: Reusing existing IMAP server connection to localhost
23:12.36 untagged responses dump:
CAPABILITY: "IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE"
23:12.36 > IOJM11 NOOP
23:12.36 < IOJM11 OK Completed
23:12.36 matched r'(?P<tag>IOJM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IOJM11', 'OK', 'Completed')
2016-06-05 18:23:12,366 pykolab.imap DEBUG [32659]: Reusing existing IMAP server connection to localhost
23:12.36 > IOJM12 LIST "" "user/muster2@quetzalsailing.ch"
23:12.36 < IOJM12 OK Completed (0.000 secs)
23:12.36 matched r'(?P<tag>IOJM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IOJM12', 'OK', 'Completed (0.000 secs)')
[LIST] No results
2016-06-05 18:23:12,368 pykolab.imap DEBUG [32659]: Looking for folder 'user/muster2@quetzalsailing.ch', we found folders: []
23:12.36 untagged responses dump:
CAPABILITY: "IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE"
23:12.36 > IOJM13 NOOP
23:12.36 < IOJM13 OK Completed
23:12.36 matched r'(?P<tag>IOJM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IOJM13', 'OK', 'Completed')
2016-06-05 18:23:12,369 pykolab.imap DEBUG [32659]: Reusing existing IMAP server connection to localhost
2016-06-05 18:23:12,369 pykolab.imap INFO Creating new mailbox for user muster2@quetzalsailing.ch
23:12.36 > IOJM14 CREATE "user/muster2@quetzalsailing.ch"
23:12.45 < IOJM14 OK Completed
23:12.45 matched r'(?P<tag>IOJM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IOJM14', 'OK', 'Completed')
[CREATE user/muster2@quetzalsailing.ch partition=None] OK: Completed
2016-06-05 18:23:12,458 pykolab.auth DEBUG [32659]: Called for domain None
2016-06-05 18:23:12,458 pykolab.auth DEBUG [32659]: Using section itigo.tech and domain itigo.tech
2016-06-05 18:23:12,458 pykolab.auth DEBUG [32659]: Using section itigo.tech and domain itigo.tech
2016-06-05 18:23:12,459 pykolab.auth DEBUG [32659]: Connecting to Authentication backend for domain itigo.tech
2016-06-05 18:23:12,459 pykolab.auth DEBUG [32659]: Section kolab has auth_mechanism: 'ldap'
2016-06-05 18:23:12,459 pykolab.auth DEBUG [32659]: Starting LDAP...
2016-06-05 18:23:12,460 pykolab.auth DEBUG [32659]: Connecting to LDAP...
2016-06-05 18:23:12,460 pykolab.auth DEBUG [32659]: Attempting to use LDAP URI ldap://localhost:389
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.set_option
((17, 3), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.set_option
((17, 3), {})
2016-06-05 18:23:12,461 pykolab.auth DEBUG [32659]: Called for domain None
2016-06-05 18:23:12,462 pykolab.auth DEBUG [32659]: Listing domains...
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.simple_bind
(('cn=Directory Manager', '4c4xcjmc7lNALwpRapVd', None, None), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((1, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:13,319 pykolab.auth DEBUG [32659]: Searching with filter '(&(objectclass=domainrelatedobject)(associatedDomain=quetzalsailing.ch))'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('cn=kolab,cn=config',
2,
'(&(objectclass=domainrelatedobject)(associatedDomain=quetzalsailing.ch))',
['associateddomain'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.result4
((2, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x273c998> ldap://localhost:389 - ReconnectLDAPObject.unbind_ext
((None, None), {})
2016-06-05 18:23:13,326 pykolab.plugins DEBUG [32659]: Executing hook create_user_folders for plugin defaultfolders
2016-06-05 18:23:13,327 pykolab.imap DEBUG [32659]: Creating additional folders for user muster2@quetzalsailing.ch
23:13.40 > KJHM1 AUTHENTICATE PLAIN bXVzdGVyMkBxdWV0emFsc2FpbGluZy5jaABjeXJ1cy1hZG1pbgB2dWRRQ04zazQ3YlZMaVVHcGh1SQ==
23:14.46 < KJHM1 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (tls protection) SESSIONID=<kolab1.itigo.cust.vshn.net-32679-1465143793-1-17672005539434634148>
23:14.46 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM1', 'OK', '[CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (tls protection) SESSIONID=<kolab1.itigo.cust.vshn.net-32679-1465143793-1-17672005539434634148>')
23:14.46 matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('CAPABILITY', ' IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE', 'IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE')
23:14.46 untagged_responses[CAPABILITY] 0 += ["IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE"]
[AUTHENTICATE PLAIN cyrus-admin] OK: [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] Success (tls protection) SESSIONID=<kolab1.itigo.cust.vshn.net-32679-1465143793-1-17672005539434634148>
23:14.46 > KJHM2 LIST "" ""
23:14.46 < * LIST (\Noselect) "/" ""
23:14.46 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\Noselect) "/" ""', '(\\Noselect) "/" ""')
23:14.46 untagged_responses[LIST] 0 += ["(\Noselect) "/" """]
23:14.46 < KJHM2 OK Completed (0.000 secs)
23:14.46 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM2', 'OK', 'Completed (0.000 secs)')
23:14.46 untagged_responses[LIST] => ['(\\Noselect) "/" ""']
23:14.46 > KJHM3 NAMESPACE
23:14.46 < * NAMESPACE (("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))
23:14.46 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('NAMESPACE', ' (("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))', '(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))')
23:14.46 untagged_responses[NAMESPACE] 0 += ["(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))"]
23:14.46 < KJHM3 OK Completed
23:14.46 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM3', 'OK', 'Completed')
23:14.46 untagged_responses[NAMESPACE] => ['(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))']
23:14.46 > KJHM4 CREATE "Calendar/Personal Calendar"
23:14.55 < KJHM4 OK Completed
23:14.55 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM4', 'OK', 'Completed')
[CREATE Calendar/Personal Calendar partition=None] OK: Completed
23:14.55 > KJHM5 LIST "" "Calendar/Personal Calendar"
23:14.55 < * LIST (\HasNoChildren) "/" "Calendar/Personal Calendar"
23:14.55 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" "Calendar/Personal Calendar"', '(\\HasNoChildren) "/" "Calendar/Personal Calendar"')
23:14.55 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" "Calendar/Personal Calendar""]
23:14.55 < KJHM5 OK Completed (0.000 secs 2 calls)
23:14.55 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM5', 'OK', 'Completed (0.000 secs 2 calls)')
23:14.55 untagged_responses[LIST] => ['(\\HasNoChildren) "/" "Calendar/Personal Calendar"']
2016-06-05 18:23:14,555 pykolab.imap DEBUG [32659]: Looking for folder 'Calendar/Personal Calendar', we found folders: [u'Calendar/Personal Calendar']
2016-06-05 18:23:14,556 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Calendar/Personal Calendar
23:14.55 > KJHM6 SETANNOTATION "Calendar/Personal Calendar" "/vendor/kolab/folder-type" ("value.shared" "event")
23:14.61 < KJHM6 OK Completed
23:14.61 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM6', 'OK', 'Completed')
[SETANNOTATION Calendar/Personal Calendar] OK: None
23:14.61 > KJHM7 CREATE Drafts
23:14.68 < KJHM7 OK Completed
23:14.68 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM7', 'OK', 'Completed')
[CREATE Drafts partition=None] OK: Completed
23:14.68 > KJHM8 LIST "" Drafts
23:14.68 < * LIST (\HasNoChildren) "/" Drafts
23:14.68 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Drafts', '(\\HasNoChildren) "/" Drafts')
23:14.68 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Drafts"]
23:14.68 < KJHM8 OK Completed (0.000 secs 2 calls)
23:14.68 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM8', 'OK', 'Completed (0.000 secs 2 calls)')
23:14.68 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Drafts']
2016-06-05 18:23:14,690 pykolab.imap DEBUG [32659]: Looking for folder 'Drafts', we found folders: [u'Drafts']
2016-06-05 18:23:14,690 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Drafts
23:14.69 > KJHM9 SETANNOTATION Drafts "/vendor/kolab/folder-type" ("value.priv" "mail.drafts")
23:14.74 < KJHM9 OK Completed
23:14.74 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM9', 'OK', 'Completed')
[SETANNOTATION Drafts] OK: None
23:14.74 > KJHM10 CREATE Contacts
23:14.83 < KJHM10 OK Completed
23:14.83 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM10', 'OK', 'Completed')
[CREATE Contacts partition=None] OK: Completed
23:14.83 > KJHM11 LIST "" Contacts
23:14.83 < * LIST (\HasNoChildren) "/" Contacts
23:14.83 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Contacts', '(\\HasNoChildren) "/" Contacts')
23:14.83 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Contacts"]
23:14.83 < KJHM11 OK Completed (0.000 secs 2 calls)
23:14.83 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM11', 'OK', 'Completed (0.000 secs 2 calls)')
23:14.83 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Contacts']
2016-06-05 18:23:14,835 pykolab.imap DEBUG [32659]: Looking for folder 'Contacts', we found folders: [u'Contacts']
2016-06-05 18:23:14,836 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Contacts
23:14.83 > KJHM12 SETANNOTATION Contacts "/vendor/kolab/folder-type" ("value.priv" "contact.default")
23:14.89 < KJHM12 OK Completed
23:14.89 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM12', 'OK', 'Completed')
[SETANNOTATION Contacts] OK: None
2016-06-05 18:23:14,899 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Contacts
23:14.89 > KJHM13 SETANNOTATION Contacts "/vendor/kolab/folder-type" ("value.shared" "contact")
23:14.95 < KJHM13 OK Completed
23:14.95 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM13', 'OK', 'Completed')
[SETANNOTATION Contacts] OK: None
23:14.95 > KJHM14 CREATE Notes
23:15.04 < KJHM14 OK Completed
23:15.04 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM14', 'OK', 'Completed')
[CREATE Notes partition=None] OK: Completed
23:15.04 > KJHM15 LIST "" Notes
23:15.04 < * LIST (\HasNoChildren) "/" Notes
23:15.04 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Notes', '(\\HasNoChildren) "/" Notes')
23:15.04 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Notes"]
23:15.04 < KJHM15 OK Completed (0.000 secs 2 calls)
23:15.04 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM15', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.04 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Notes']
2016-06-05 18:23:15,045 pykolab.imap DEBUG [32659]: Looking for folder 'Notes', we found folders: [u'Notes']
2016-06-05 18:23:15,045 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Notes
23:15.04 > KJHM16 SETANNOTATION Notes "/vendor/kolab/folder-type" ("value.priv" "note.default")
23:15.09 < KJHM16 OK Completed
23:15.09 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM16', 'OK', 'Completed')
[SETANNOTATION Notes] OK: None
2016-06-05 18:23:15,097 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Notes
23:15.09 > KJHM17 SETANNOTATION Notes "/vendor/kolab/folder-type" ("value.shared" "note")
23:15.14 < KJHM17 OK Completed
23:15.14 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM17', 'OK', 'Completed')
[SETANNOTATION Notes] OK: None
23:15.14 > KJHM18 CREATE "Contacts/Personal Contacts"
23:15.22 < KJHM18 OK Completed
23:15.22 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM18', 'OK', 'Completed')
[CREATE Contacts/Personal Contacts partition=None] OK: Completed
23:15.22 > KJHM19 LIST "" "Contacts/Personal Contacts"
23:15.22 < * LIST (\HasNoChildren) "/" "Contacts/Personal Contacts"
23:15.22 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" "Contacts/Personal Contacts"', '(\\HasNoChildren) "/" "Contacts/Personal Contacts"')
23:15.22 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" "Contacts/Personal Contacts""]
23:15.22 < KJHM19 OK Completed (0.000 secs 2 calls)
23:15.22 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM19', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.22 untagged_responses[LIST] => ['(\\HasNoChildren) "/" "Contacts/Personal Contacts"']
2016-06-05 18:23:15,226 pykolab.imap DEBUG [32659]: Looking for folder 'Contacts/Personal Contacts', we found folders: [u'Contacts/Personal Contacts']
2016-06-05 18:23:15,226 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Contacts/Personal Contacts
23:15.22 > KJHM20 SETANNOTATION "Contacts/Personal Contacts" "/vendor/kolab/folder-type" ("value.shared" "contact")
23:15.27 < KJHM20 OK Completed
23:15.27 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM20', 'OK', 'Completed')
[SETANNOTATION Contacts/Personal Contacts] OK: None
23:15.27 > KJHM21 CREATE Trash
23:15.34 < KJHM21 OK Completed
23:15.34 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM21', 'OK', 'Completed')
[CREATE Trash partition=None] OK: Completed
23:15.34 > KJHM22 LIST "" Trash
23:15.34 < * LIST (\HasNoChildren) "/" Trash
23:15.34 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Trash', '(\\HasNoChildren) "/" Trash')
23:15.34 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Trash"]
23:15.34 < KJHM22 OK Completed (0.000 secs 2 calls)
23:15.34 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM22', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.34 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Trash']
2016-06-05 18:23:15,342 pykolab.imap DEBUG [32659]: Looking for folder 'Trash', we found folders: [u'Trash']
2016-06-05 18:23:15,343 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Trash
23:15.34 > KJHM23 SETANNOTATION Trash "/vendor/kolab/folder-type" ("value.priv" "mail.wastebasket")
23:15.38 < KJHM23 OK Completed
23:15.38 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM23', 'OK', 'Completed')
[SETANNOTATION Trash] OK: None
23:15.38 > KJHM24 CREATE Sent
23:15.46 < KJHM24 OK Completed
23:15.46 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM24', 'OK', 'Completed')
[CREATE Sent partition=None] OK: Completed
23:15.46 > KJHM25 LIST "" Sent
23:15.46 < * LIST (\HasNoChildren) "/" Sent
23:15.46 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Sent', '(\\HasNoChildren) "/" Sent')
23:15.46 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Sent"]
23:15.46 < KJHM25 OK Completed (0.000 secs 2 calls)
23:15.46 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM25', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.46 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Sent']
2016-06-05 18:23:15,465 pykolab.imap DEBUG [32659]: Looking for folder 'Sent', we found folders: [u'Sent']
2016-06-05 18:23:15,465 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Sent
23:15.46 > KJHM26 SETANNOTATION Sent "/vendor/kolab/folder-type" ("value.priv" "mail.sentitems")
23:15.51 < KJHM26 OK Completed
23:15.51 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM26', 'OK', 'Completed')
[SETANNOTATION Sent] OK: None
23:15.51 > KJHM27 CREATE Files
23:15.60 < KJHM27 OK Completed
23:15.60 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM27', 'OK', 'Completed')
[CREATE Files partition=None] OK: Completed
23:15.60 > KJHM28 LIST "" Files
23:15.60 < * LIST (\HasNoChildren) "/" Files
23:15.60 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Files', '(\\HasNoChildren) "/" Files')
23:15.60 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Files"]
23:15.60 < KJHM28 OK Completed (0.000 secs 2 calls)
23:15.60 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM28', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.60 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Files']
2016-06-05 18:23:15,604 pykolab.imap DEBUG [32659]: Looking for folder 'Files', we found folders: [u'Files']
2016-06-05 18:23:15,604 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Files
23:15.60 > KJHM29 SETANNOTATION Files "/vendor/kolab/folder-type" ("value.priv" "file.default")
23:15.65 < KJHM29 OK Completed
23:15.65 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM29', 'OK', 'Completed')
[SETANNOTATION Files] OK: None
23:15.65 > KJHM30 CREATE Tasks
23:15.73 < KJHM30 OK Completed
23:15.73 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM30', 'OK', 'Completed')
[CREATE Tasks partition=None] OK: Completed
23:15.73 > KJHM31 LIST "" Tasks
23:15.73 < * LIST (\HasNoChildren) "/" Tasks
23:15.73 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Tasks', '(\\HasNoChildren) "/" Tasks')
23:15.73 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Tasks"]
23:15.73 < KJHM31 OK Completed (0.000 secs 2 calls)
23:15.73 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM31', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.73 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Tasks']
2016-06-05 18:23:15,733 pykolab.imap DEBUG [32659]: Looking for folder 'Tasks', we found folders: [u'Tasks']
2016-06-05 18:23:15,733 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Tasks
23:15.73 > KJHM32 SETANNOTATION Tasks "/vendor/kolab/folder-type" ("value.priv" "task.default")
23:15.78 < KJHM32 OK Completed
23:15.78 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM32', 'OK', 'Completed')
[SETANNOTATION Tasks] OK: None
2016-06-05 18:23:15,781 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Tasks
23:15.78 > KJHM33 SETANNOTATION Tasks "/vendor/kolab/folder-type" ("value.shared" "task")
23:15.82 < KJHM33 OK Completed
23:15.82 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM33', 'OK', 'Completed')
[SETANNOTATION Tasks] OK: None
23:15.82 > KJHM34 CREATE Journal
23:15.89 < KJHM34 OK Completed
23:15.89 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM34', 'OK', 'Completed')
[CREATE Journal partition=None] OK: Completed
23:15.89 > KJHM35 LIST "" Journal
23:15.89 < * LIST (\HasNoChildren) "/" Journal
23:15.89 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Journal', '(\\HasNoChildren) "/" Journal')
23:15.89 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Journal"]
23:15.89 < KJHM35 OK Completed (0.000 secs 2 calls)
23:15.89 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM35', 'OK', 'Completed (0.000 secs 2 calls)')
23:15.89 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Journal']
2016-06-05 18:23:15,897 pykolab.imap DEBUG [32659]: Looking for folder 'Journal', we found folders: [u'Journal']
2016-06-05 18:23:15,897 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Journal
23:15.89 > KJHM36 SETANNOTATION Journal "/vendor/kolab/folder-type" ("value.priv" "journal.default")
23:15.94 < KJHM36 OK Completed
23:15.94 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM36', 'OK', 'Completed')
[SETANNOTATION Journal] OK: None
2016-06-05 18:23:15,941 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Journal
23:15.94 > KJHM37 SETANNOTATION Journal "/vendor/kolab/folder-type" ("value.shared" "journal")
23:15.98 < KJHM37 OK Completed
23:15.98 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM37', 'OK', 'Completed')
[SETANNOTATION Journal] OK: None
23:15.98 > KJHM38 CREATE Spam
23:16.06 < KJHM38 OK Completed
23:16.06 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM38', 'OK', 'Completed')
[CREATE Spam partition=None] OK: Completed
23:16.06 > KJHM39 LIST "" Spam
23:16.06 < * LIST (\HasNoChildren) "/" Spam
23:16.06 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Spam', '(\\HasNoChildren) "/" Spam')
23:16.06 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Spam"]
23:16.06 < KJHM39 OK Completed (0.000 secs 2 calls)
23:16.06 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM39', 'OK', 'Completed (0.000 secs 2 calls)')
23:16.06 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Spam']
2016-06-05 18:23:16,067 pykolab.imap DEBUG [32659]: Looking for folder 'Spam', we found folders: [u'Spam']
2016-06-05 18:23:16,068 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Spam
23:16.06 > KJHM40 SETANNOTATION Spam "/vendor/kolab/folder-type" ("value.priv" "mail.junkemail")
23:16.11 < KJHM40 OK Completed
23:16.11 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM40', 'OK', 'Completed')
[SETANNOTATION Spam] OK: None
23:16.11 > KJHM41 CREATE Calendar
23:16.20 < KJHM41 OK Completed
23:16.20 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM41', 'OK', 'Completed')
[CREATE Calendar partition=None] OK: Completed
23:16.20 > KJHM42 LIST "" Calendar
23:16.20 < * LIST (\HasChildren) "/" Calendar
23:16.20 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" Calendar', '(\\HasChildren) "/" Calendar')
23:16.20 untagged_responses[LIST] 0 += ["(\HasChildren) "/" Calendar"]
23:16.20 < KJHM42 OK Completed (0.000 secs 2 calls)
23:16.20 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM42', 'OK', 'Completed (0.000 secs 2 calls)')
23:16.20 untagged_responses[LIST] => ['(\\HasChildren) "/" Calendar']
2016-06-05 18:23:16,207 pykolab.imap DEBUG [32659]: Looking for folder 'Calendar', we found folders: [u'Calendar']
2016-06-05 18:23:16,208 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Calendar
23:16.20 > KJHM43 SETANNOTATION Calendar "/vendor/kolab/folder-type" ("value.priv" "event.default")
23:16.26 < KJHM43 OK Completed
23:16.26 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM43', 'OK', 'Completed')
[SETANNOTATION Calendar] OK: None
2016-06-05 18:23:16,264 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Calendar
23:16.26 > KJHM44 SETANNOTATION Calendar "/vendor/kolab/folder-type" ("value.shared" "event")
23:16.31 < KJHM44 OK Completed
23:16.31 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM44', 'OK', 'Completed')
[SETANNOTATION Calendar] OK: None
23:16.31 > KJHM45 CREATE Configuration
23:16.40 < KJHM45 OK Completed
23:16.40 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM45', 'OK', 'Completed')
[CREATE Configuration partition=None] OK: Completed
23:16.40 > KJHM46 LIST "" Configuration
23:16.40 < * LIST (\HasNoChildren) "/" Configuration
23:16.40 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Configuration', '(\\HasNoChildren) "/" Configuration')
23:16.40 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Configuration"]
23:16.40 < KJHM46 OK Completed (0.000 secs 2 calls)
23:16.40 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM46', 'OK', 'Completed (0.000 secs 2 calls)')
23:16.40 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Configuration']
2016-06-05 18:23:16,408 pykolab.imap DEBUG [32659]: Looking for folder 'Configuration', we found folders: [u'Configuration']
2016-06-05 18:23:16,408 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Configuration
23:16.40 > KJHM47 SETANNOTATION Configuration "/vendor/kolab/folder-type" ("value.priv" "configuration.default")
23:16.45 < KJHM47 OK Completed
23:16.45 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM47', 'OK', 'Completed')
[SETANNOTATION Configuration] OK: None
2016-06-05 18:23:16,460 pykolab.imap DEBUG [32659]: Setting annotation /vendor/kolab/folder-type on folder Configuration
23:16.46 > KJHM48 SETANNOTATION Configuration "/vendor/kolab/folder-type" ("value.shared" "configuration.default")
23:16.50 < KJHM48 OK Completed
23:16.50 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM48', 'OK', 'Completed')
[SETANNOTATION Configuration] OK: None
23:16.50 > KJHM49 CREATE Archive
23:16.58 < KJHM49 OK Completed
23:16.58 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM49', 'OK', 'Completed')
[CREATE Archive partition=None] OK: Completed
23:16.58 > KJHM50 LIST "" Archive
23:16.58 < * LIST (\HasNoChildren) "/" Archive
23:16.58 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Archive', '(\\HasNoChildren) "/" Archive')
23:16.58 untagged_responses[LIST] 0 += ["(\HasNoChildren) "/" Archive"]
23:16.58 < KJHM50 OK Completed (0.000 secs 2 calls)
23:16.58 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM50', 'OK', 'Completed (0.000 secs 2 calls)')
23:16.58 untagged_responses[LIST] => ['(\\HasNoChildren) "/" Archive']
2016-06-05 18:23:16,586 pykolab.imap DEBUG [32659]: Looking for folder 'Archive', we found folders: [u'Archive']
2016-06-05 18:23:16,586 pykolab.imap DEBUG [32659]: Subscribing user to the additional folders
23:16.58 > KJHM51 NAMESPACE
23:16.58 < * NAMESPACE (("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))
23:16.58 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('NAMESPACE', ' (("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))', '(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))')
23:16.58 untagged_responses[NAMESPACE] 0 += ["(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))"]
23:16.58 < KJHM51 OK Completed
23:16.58 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM51', 'OK', 'Completed')
23:16.58 untagged_responses[NAMESPACE] => ['(("" "/")) (("Other Users/" "/")) (("Shared Folders/" "/"))']
2016-06-05 18:23:16,587 pykolab.imap DEBUG [32659]: Using the following tests for folder subscriptions:
2016-06-05 18:23:16,588 pykolab.imap DEBUG [32659]: 'Other Users/'
2016-06-05 18:23:16,588 pykolab.imap DEBUG [32659]: 'Shared Folders/'
23:16.58 > KJHM52 LIST "" *
23:16.59 < * LIST (\Noinferiors \HasNoChildren) "/" INBOX
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\Noinferiors \\HasNoChildren) "/" INBOX', '(\\Noinferiors \\HasNoChildren) "/" INBOX')
23:16.59 untagged_responses[LIST] 0 += ["(\Noinferiors \HasNoChildren) "/" INBOX"]
23:16.59 < * LIST (\HasNoChildren) "/" Archive
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Archive', '(\\HasNoChildren) "/" Archive')
23:16.59 untagged_responses[LIST] 1 += ["(\HasNoChildren) "/" Archive"]
23:16.59 < * LIST (\HasNoChildren) "/" Drafts
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Drafts', '(\\HasNoChildren) "/" Drafts')
23:16.59 untagged_responses[LIST] 2 += ["(\HasNoChildren) "/" Drafts"]
23:16.59 < * LIST (\HasNoChildren) "/" Files
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Files', '(\\HasNoChildren) "/" Files')
23:16.59 untagged_responses[LIST] 3 += ["(\HasNoChildren) "/" Files"]
23:16.59 < * LIST (\HasNoChildren) "/" Sent
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Sent', '(\\HasNoChildren) "/" Sent')
23:16.59 untagged_responses[LIST] 4 += ["(\HasNoChildren) "/" Sent"]
23:16.59 < * LIST (\HasNoChildren) "/" Spam
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Spam', '(\\HasNoChildren) "/" Spam')
23:16.59 untagged_responses[LIST] 5 += ["(\HasNoChildren) "/" Spam"]
23:16.59 < * LIST (\HasNoChildren) "/" Trash
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" Trash', '(\\HasNoChildren) "/" Trash')
23:16.59 untagged_responses[LIST] 6 += ["(\HasNoChildren) "/" Trash"]
23:16.59 < * LIST (\HasNoChildren) "/" "Other Users/muster/info"
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" "Other Users/muster/info"', '(\\HasNoChildren) "/" "Other Users/muster/info"')
23:16.59 untagged_responses[LIST] 7 += ["(\HasNoChildren) "/" "Other Users/muster/info""]
23:16.59 < * LIST (\HasNoChildren) "/" "Shared Folders/shared/info"
23:16.59 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasNoChildren) "/" "Shared Folders/shared/info"', '(\\HasNoChildren) "/" "Shared Folders/shared/info"')
23:16.59 untagged_responses[LIST] 8 += ["(\HasNoChildren) "/" "Shared Folders/shared/info""]
23:16.59 < KJHM52 OK Completed (0.000 secs 25 calls)
23:16.59 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM52', 'OK', 'Completed (0.000 secs 25 calls)')
23:16.59 untagged_responses[LIST] => ['(\\Noinferiors \\HasNoChildren) "/" INBOX', '(\\HasNoChildren) "/" Archive', '(\\HasNoChildren) "/" Drafts', '(\\HasNoChildren) "/" Files', '(\\HasNoChildren) "/" Sent', '(\\HasNoChildren) "/" Spam', '(\\HasNoChildren) "/" Trash', '(\\HasNoChildren) "/" "Other Users/muster/info"', '(\\HasNoChildren) "/" "Shared Folders/shared/info"']
2016-06-05 18:23:16,597 pykolab.imap DEBUG [32659]: Folder INBOX
2016-06-05 18:23:16,597 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder INBOX
23:16.59 > KJHM53 SUBSCRIBE INBOX
23:16.61 < KJHM53 OK Completed
23:16.61 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM53', 'OK', 'Completed')
[SUBSCRIBE INBOX] OK: Completed
2016-06-05 18:23:16,610 pykolab.imap DEBUG [32659]: Folder Archive
2016-06-05 18:23:16,610 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Archive
23:16.61 > KJHM54 SUBSCRIBE Archive
23:16.62 < KJHM54 OK Completed
23:16.62 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM54', 'OK', 'Completed')
[SUBSCRIBE Archive] OK: Completed
2016-06-05 18:23:16,621 pykolab.imap DEBUG [32659]: Folder Drafts
2016-06-05 18:23:16,621 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Drafts
23:16.62 > KJHM55 SUBSCRIBE Drafts
23:16.63 < KJHM55 OK Completed
23:16.63 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM55', 'OK', 'Completed')
[SUBSCRIBE Drafts] OK: Completed
2016-06-05 18:23:16,633 pykolab.imap DEBUG [32659]: Folder Files
2016-06-05 18:23:16,633 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Files
23:16.63 > KJHM56 SUBSCRIBE Files
23:16.64 < KJHM56 OK Completed
23:16.64 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM56', 'OK', 'Completed')
[SUBSCRIBE Files] OK: Completed
2016-06-05 18:23:16,644 pykolab.imap DEBUG [32659]: Folder Sent
2016-06-05 18:23:16,644 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Sent
23:16.64 > KJHM57 SUBSCRIBE Sent
23:16.65 < KJHM57 OK Completed
23:16.65 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM57', 'OK', 'Completed')
[SUBSCRIBE Sent] OK: Completed
2016-06-05 18:23:16,654 pykolab.imap DEBUG [32659]: Folder Spam
2016-06-05 18:23:16,654 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Spam
23:16.65 > KJHM58 SUBSCRIBE Spam
23:16.66 < KJHM58 OK Completed
23:16.66 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM58', 'OK', 'Completed')
[SUBSCRIBE Spam] OK: Completed
2016-06-05 18:23:16,666 pykolab.imap DEBUG [32659]: Folder Trash
2016-06-05 18:23:16,666 pykolab.imap DEBUG [32659]: Subscribing muster2@quetzalsailing.ch to folder Trash
23:16.66 > KJHM59 SUBSCRIBE Trash
23:16.67 < KJHM59 OK Completed
23:16.67 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM59', 'OK', 'Completed')
[SUBSCRIBE Trash] OK: Completed
2016-06-05 18:23:16,678 pykolab.imap DEBUG [32659]: Folder Other Users/muster/info
2016-06-05 18:23:16,678 pykolab.imap DEBUG [32659]: Folder Shared Folders/shared/info
23:16.67 > KJHM60 LOGOUT
23:16.68 < * BYE LOGOUT received
23:16.68 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('BYE', ' LOGOUT received', 'LOGOUT received')
23:16.68 untagged_responses[BYE] 0 += ["LOGOUT received"]
23:16.68 BYE response: LOGOUT received
23:16.68 < KJHM60 OK Completed
23:16.68 matched r'(?P<tag>KJHM\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('KJHM60', 'OK', 'Completed')
[LOGOUT] BYE: LOGOUT received
2016-06-05 18:23:16,748 pykolab.imap DEBUG [32659]: Logging on to Cyrus IMAP server localhost
23:16.74 > IAAB1 LOGIN cyrus-admin "vudQCN3k47bVLiUGphuI"
23:16.79 < IAAB1 OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<kolab1.itigo.cust.vshn.net-32694-1465143796-1-2718289832741650383>
23:16.79 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB1', 'OK', '[CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<kolab1.itigo.cust.vshn.net-32694-1465143796-1-2718289832741650383>')
23:16.79 matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('CAPABILITY', ' IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE', 'IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE')
23:16.79 untagged_responses[CAPABILITY] 0 += ["IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE"]
23:16.80 > IAAB2 DUMP NIL
23:16.80 < IAAB2 NO Mailbox does not exist
23:16.80 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB2', 'NO', 'Mailbox does not exist')
23:16.80 NO response: Mailbox does not exist
23:16.80 > IAAB3 LIST "" ""
23:16.80 < * LIST (\Noselect) "/" ""
23:16.80 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\Noselect) "/" ""', '(\\Noselect) "/" ""')
23:16.80 untagged_responses[LIST] 0 += ["(\Noselect) "/" """]
23:16.80 < IAAB3 OK Completed (0.000 secs)
23:16.80 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB3', 'OK', 'Completed (0.000 secs)')
23:16.80 untagged_responses[LIST] => ['(\\Noselect) "/" ""']
[LOGIN cyrus-admin] OK: [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE ACL RIGHTS=kxten QUOTA MAILBOX-REFERRALS NAMESPACE UIDPLUS NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY CATENATE CONDSTORE ESEARCH SORT SORT=MODSEQ SORT=DISPLAY SORT=UID THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE ANNOTATE-EXPERIMENT-1 METADATA LIST-EXTENDED LIST-STATUS LIST-MYRIGHTS WITHIN QRESYNC SCAN XLIST XMOVE MOVE SPECIAL-USE CREATE-SPECIAL-USE URLAUTH URLAUTH=BINARY X-NETSCAPE LOGINDISABLED AUTH=PLAIN AUTH=LOGIN COMPRESS=DEFLATE X-QUOTA=STORAGE X-QUOTA=MESSAGE X-QUOTA=X-ANNOTATION-STORAGE X-QUOTA=X-NUM-FOLDERS IDLE] User logged in SESSIONID=<kolab1.itigo.cust.vshn.net-32694-1465143796-1-2718289832741650383>
2016-06-05 18:23:16,802 pykolab.imap DEBUG [32659]: Continuing with separator: '/'
2016-06-05 18:23:16,802 pykolab.imap DEBUG [32659]: This system is not part of a murder topology
23:16.80 > IAAB4 SETQUOTA "user/muster2/Archive@quetzalsailing.ch" ()
23:16.86 < IAAB4 OK Completed
23:16.86 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB4', 'OK', 'Completed')
[SETQUOTA user/muster2/Archive@quetzalsailing.ch 0] OK: Completed
23:16.86 > IAAB5 LIST "" "user/muster2@quetzalsailing.ch"
23:16.86 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:16.86 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:16.86 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:16.86 < IAAB5 OK Completed (0.000 secs 15 calls)
23:16.86 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB5', 'OK', 'Completed (0.000 secs 15 calls)')
23:16.86 untagged_responses[LIST] => ['(\\HasChildren) "/" user/muster2@quetzalsailing.ch']
2016-06-05 18:23:16,869 pykolab.imap DEBUG [32659]: Moving INBOX folder user/muster2/Archive@quetzalsailing.ch to user/muster2/Archive@quetzalsailing.ch on partition archive
23:16.87 > IAAB6 RENAME "user/muster2/Archive@quetzalsailing.ch" "user/muster2/Archive@quetzalsailing.ch" "archive"
23:16.87 < IAAB6 BAD Invalid partition name in Rename
23:16.87 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB6', 'BAD', 'Invalid partition name in Rename')
23:16.87 BAD response: Invalid partition name in Rename
2016-06-05 18:23:16,871 pykolab.imap ERROR Could not rename user/muster2/Archive@quetzalsailing.ch to reside on partition archive
23:16.87 > IAAB7 LIST "" "user/muster2@quetzalsailing.ch"
23:16.87 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:16.87 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:16.87 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:16.87 < IAAB7 OK Completed (0.000 secs 15 calls)
23:16.87 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB7', 'OK', 'Completed (0.000 secs 15 calls)')
23:16.87 untagged_responses[LIST] => ['(\\HasChildren) "/" user/muster2@quetzalsailing.ch']
2016-06-05 18:23:16,872 pykolab.imap DEBUG [32659]: Server for mailbox 'user/muster2@quetzalsailing.ch' is 'localhost'
2016-06-05 18:23:16,872 pykolab.auth DEBUG [32659]: Entry mailhost attribute value: None
2016-06-05 18:23:16,872 pykolab.auth DEBUG [32659]: imap.user_mailbox_server('user/muster2@quetzalsailing.ch') result: 'localhost'
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: Setting entry attribute 'mailhost' to 'localhost' for {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'domain': 'quetzalsailing.ch', 'displayname': 'Muster2, Peter2', 'cn': 'Peter2 Muster2', 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'preferredlanguage': 'en_US', 'userpassword': '{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw==', 'nsuniqueid': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'id': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'objectclass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'mailhost': None, 'sn': 'Muster2', 'mail': 'muster2@quetzalsailing.ch', 'surname': 'Muster2', 'givenname': 'Peter2', 'type': 'user', 'modifytimestamp': '20160605162311Z', 'uid': 'muster2'}
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,873 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['*']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', '*'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((18, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:16,874 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,875 pykolab.auth DEBUG [32659]: Entry ID: {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'domain': 'quetzalsailing.ch', 'displayname': 'Muster2, Peter2', 'cn': 'Peter2 Muster2', 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'preferredlanguage': 'en_US', 'userpassword': '{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw==', 'nsuniqueid': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'id': 'b8817181-2b3911e6-b4b7ab7b-af958009', 'objectclass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'mailhost': None, 'sn': 'Muster2', 'mail': 'muster2@quetzalsailing.ch', 'surname': 'Muster2', 'givenname': 'Peter2', 'type': 'user', 'modifytimestamp': '20160605162311Z', 'uid': 'muster2'}
2016-06-05 18:23:16,875 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,875 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailhost']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailhost'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((19, 1, -1, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.modify_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
[(0, 'mailhost', 'localhost')],
None,
None),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((20, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:16,891 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,891 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,891 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,892 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,892 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailquota']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailquota'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((21, 1, -1, 0, 0, 0), {})
23:16.93 > IAAB8 GETQUOTA "user/muster2@quetzalsailing.ch"
23:16.93 < IAAB8 NO Quota root does not exist
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
2016-06-05 18:23:16,934 pykolab.plugins DEBUG [32659]: Executing hook set_user_folder_quota for plugin dynamicquota
2016-06-05 18:23:16,934 pykolab.auth DEBUG [32659]: Setting entry attribute 'mailquota' to '0' for 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,934 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,935 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,935 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,935 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,935 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['*']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', '*'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((22, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:16,936 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:16,937 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,937 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:16,937 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailquota']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailquota'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((23, 1, -1, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.modify_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
[(0, 'mailquota', '0')],
None,
None),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((24, 1, -1, 0, 0, 0), {})
23:16.95 > IAAB9 LIST "" "user/muster2@quetzalsailing.ch"
23:16.95 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:16.95 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:16.95 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:16.95 < IAAB9 OK Completed (0.000 secs 15 calls)
23:16.95 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB9', 'OK', 'Completed (0.000 secs 15 calls)')
23:16.95 untagged_responses[LIST] => ['(\\HasChildren) "/" user/muster2@quetzalsailing.ch']
2016-06-05 18:23:16,956 pykolab.imap DEBUG [32659]: Setting quota for folder user/muster2@quetzalsailing.ch to 0
23:16.95 > IAAB10 SETQUOTA "user/muster2@quetzalsailing.ch" ()
23:17.54 < IAAB10 OK Completed
23:17.54 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB10', 'OK', 'Completed')
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((3, 0, -1, 1, 1, 0), {})
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: LDAP Search Result Data Entry:
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: Entry: {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'mailHost': ['localhost'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162316Z'], 'uid': ['muster2']}
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: Entry Change Notification attributes:
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: Change Type: 4 ('modify')
2016-06-05 18:23:17,546 pykolab.auth DEBUG [32659]: Previous DN: None
2016-06-05 18:23:17,547 pykolab.auth DEBUG [32659]: auth.ldap.LDAP._synchronize_callback(args (), kw {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'change_type': 4, 'primary_domain': None, 'secondary_domains': [], 'entry': {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'mailHost': ['localhost'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162316Z'], 'uid': ['muster2']}, 'previous_dn': None, 'change_number': None})
2016-06-05 18:23:17,547 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,547 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,547 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,547 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
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
2016-06-05 18:23:17,553 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,553 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,553 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((26, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((26, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((26, False, 0, 0, 0, 0), {})
2016-06-05 18:23:17,554 pykolab.auth DEBUG [32659]: Applying recipient policy to 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,555 pykolab.auth DEBUG [32659]: Using mail attributes: ['mail', 'alias'], with primary 'mail' and secondary 'alias'
2016-06-05 18:23:17,555 pykolab.plugins DEBUG [32659]: Executing hook set_primary_mail for plugin recipientpolicy
2016-06-05 18:23:17,555 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2@quetzalsailing.ch' with locale 'en_US'
2016-06-05 18:23:17,555 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,555 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,555 pykolab.utils DEBUG [32659]: Executing 'Muster2@quetzalsailing.ch | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,560 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,560 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,560 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,560 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((27, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,562 pykolab.auth DEBUG [32659]: No results for mail address muster2@quetzalsailing.ch found
2016-06-05 18:23:17,562 pykolab.plugins DEBUG [32659]: Executing hook set_secondary_mail for plugin recipientpolicy
2016-06-05 18:23:17,562 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:17,562 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:17,563 pykolab.utils DEBUG [32659]: Transliterating string 'Peter2' with locale 'en_US'
2016-06-05 18:23:17,563 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,563 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,563 pykolab.utils DEBUG [32659]: Executing 'Peter2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,567 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:17,567 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,567 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,567 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,570 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:17,571 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,571 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,571 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,574 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,574 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,574 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:17,574 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:17,575 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,575 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,575 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,575 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,576 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,576 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((28, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,577 pykolab.auth DEBUG [32659]: No results for address peter2.muster2@quetzalsailing.ch found
2016-06-05 18:23:17,577 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,578 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,578 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,578 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((29, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,579 pykolab.auth DEBUG [32659]: No results for address p.muster2@quetzalsailing.ch found
2016-06-05 18:23:17,580 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,580 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,580 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,580 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <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,582 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,582 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,583 pykolab.auth DEBUG [32659]: Entry modifications list: {}
2016-06-05 18:23:17,583 pykolab.auth DEBUG [32659]: Result from recipient policy: {}
23:17.58 > IAAB11 LIST "" "user/muster2@quetzalsailing.ch"
23:17.58 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:17.58 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:17.58 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:17.58 < IAAB11 OK Completed (0.000 secs 15 calls)
23:17.58 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB11', 'OK', 'Completed (0.000 secs 15 calls)')
23:17.58 untagged_responses[LIST] => ['(\\HasChildren) "/" user/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,585 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,585 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,586 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailquota']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailquota'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((31, 1, -1, 0, 0, 0), {})
23:17.58 > IAAB12 GETQUOTA "user/muster2@quetzalsailing.ch"
23:17.58 < * QUOTA user/muster2@quetzalsailing.ch ()
23:17.58 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('QUOTA', ' user/muster2@quetzalsailing.ch ()', 'user/muster2@quetzalsailing.ch ()')
23:17.58 untagged_responses[QUOTA] 0 += ["user/muster2@quetzalsailing.ch ()"]
23:17.58 < IAAB12 OK Completed
23:17.58 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB12', 'OK', 'Completed')
23:17.58 untagged_responses[QUOTA] => ['user/muster2@quetzalsailing.ch ()']
[GETQUOTA user/muster2@quetzalsailing.ch] QUOTA (Unlimited)
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
2016-06-05 18:23:17,588 pykolab.plugins DEBUG [32659]: Executing hook set_user_folder_quota for plugin dynamicquota
23:17.58 > IAAB13 LIST "" "user/muster2@quetzalsailing.ch"
23:17.58 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:17.58 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:17.58 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:17.58 < IAAB13 OK Completed (0.000 secs 15 calls)
23:17.58 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB13', 'OK', 'Completed (0.000 secs 15 calls)')
23:17.58 untagged_responses[LIST] => ['(\\HasChildren) "/" user/muster2@quetzalsailing.ch']
2016-06-05 18:23:17,589 pykolab.imap DEBUG [32659]: Setting quota for folder user/muster2@quetzalsailing.ch to 0
23:17.59 > IAAB14 SETQUOTA "user/muster2@quetzalsailing.ch" ()
23:17.59 < IAAB14 OK Completed
23:17.59 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB14', 'OK', 'Completed')
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((3, 0, -1, 1, 1, 0), {})
2016-06-05 18:23:17,591 pykolab.auth DEBUG [32659]: LDAP Search Result Data Entry:
2016-06-05 18:23:17,591 pykolab.auth DEBUG [32659]: DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,591 pykolab.auth DEBUG [32659]: Entry: {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'mailQuota': ['0'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'mailHost': ['localhost'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162316Z'], 'uid': ['muster2']}
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: Entry Change Notification attributes:
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: Change Type: 4 ('modify')
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: Previous DN: None
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: auth.ldap.LDAP._synchronize_callback(args (), kw {'dn': 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 'change_type': 4, 'primary_domain': None, 'secondary_domains': [], 'entry': {'displayName': ['Muster2, Peter2'], 'cn': ['Peter2 Muster2'], 'mailQuota': ['0'], 'preferredLanguage': ['en_US'], 'userPassword': ['{SSHA}Co1kzLfv7CAld+y1dtwBn0qX72b2lYrOCiB2mw=='], 'nsuniqueid': ['b8817181-2b3911e6-b4b7ab7b-af958009'], 'objectClass': ['top', 'inetorgperson', 'kolabinetorgperson', 'mailrecipient', 'organizationalperson', 'person'], 'alias': ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch'], 'mailHost': ['localhost'], 'sn': ['Muster2'], 'mail': ['muster2@quetzalsailing.ch'], 'givenName': ['Peter2'], 'modifytimestamp': ['20160605162316Z'], 'uid': ['muster2']}, 'previous_dn': None, 'change_number': None})
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,592 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,593 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
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
2016-06-05 18:23:17,598 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,598 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,598 pykolab.auth DEBUG [32659]: Searching with filter '(objectclass=kolabinetorgperson)'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
2,
'(objectclass=kolabinetorgperson)',
None,
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((33, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((33, False, 0, 0, 0, 0), {})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((33, False, 0, 0, 0, 0), {})
2016-06-05 18:23:17,599 pykolab.auth DEBUG [32659]: Applying recipient policy to 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,600 pykolab.auth DEBUG [32659]: Using mail attributes: ['mail', 'alias'], with primary 'mail' and secondary 'alias'
2016-06-05 18:23:17,600 pykolab.plugins DEBUG [32659]: Executing hook set_primary_mail for plugin recipientpolicy
2016-06-05 18:23:17,600 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2@quetzalsailing.ch' with locale 'en_US'
2016-06-05 18:23:17,600 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,600 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,600 pykolab.utils DEBUG [32659]: Executing 'Muster2@quetzalsailing.ch | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,604 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,605 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,605 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,605 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((34, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,606 pykolab.auth DEBUG [32659]: No results for mail address muster2@quetzalsailing.ch found
2016-06-05 18:23:17,607 pykolab.plugins DEBUG [32659]: Executing hook set_secondary_mail for plugin recipientpolicy
2016-06-05 18:23:17,607 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:17,607 pykolab.plugins.recipientpolicy DEBUG [32659]: Alternative mail routines: {0: {'{0}.{1}@{2}': "format('%(givenname)s'[0:1].capitalize(), '%(surname)s', '%(domain)s')"}, 1: {'{0}@{1}': "format('%(uid)s', '%(domain)s')"}, 2: {'{0}@{1}': "format('%(givenname)s.%(surname)s', '%(domain)s')"}}
2016-06-05 18:23:17,607 pykolab.utils DEBUG [32659]: Transliterating string 'Peter2' with locale 'en_US'
2016-06-05 18:23:17,607 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,607 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,608 pykolab.utils DEBUG [32659]: Executing 'Peter2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,610 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:17,611 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,611 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,611 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,614 pykolab.utils DEBUG [32659]: Transliterating string 'Muster2' with locale 'en_US'
2016-06-05 18:23:17,614 pykolab.utils DEBUG [32659]: Attempting to set locale
2016-06-05 18:23:17,614 pykolab.utils DEBUG [32659]: Success setting locale
2016-06-05 18:23:17,614 pykolab.utils DEBUG [32659]: Executing 'Muster2 | /usr/bin/iconv -f UTF-8 -t ASCII//TRANSLIT -s'
2016-06-05 18:23:17,617 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,617 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: P.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,618 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:17,618 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: muster2@quetzalsailing.ch
2016-06-05 18:23:17,618 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,618 pykolab.plugins.recipientpolicy DEBUG [32659]: Appending additional mail address: Peter2.Muster2@quetzalsailing.ch
2016-06-05 18:23:17,618 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,619 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,619 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,619 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=peter2.muster2@quetzalsailing.ch)(alias=peter2.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((35, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,620 pykolab.auth DEBUG [32659]: No results for address peter2.muster2@quetzalsailing.ch found
2016-06-05 18:23:17,621 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,621 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,621 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,621 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=p.muster2@quetzalsailing.ch)(alias=p.muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((36, 1, -1, 0, 0, 0), {})
2016-06-05 18:23:17,623 pykolab.auth DEBUG [32659]: No results for address p.muster2@quetzalsailing.ch found
2016-06-05 18:23:17,623 pykolab.auth DEBUG [32659]: _bind called, but already bound
2016-06-05 18:23:17,623 pykolab.auth DEBUG [32659]: Finding recipient with filter '(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))'
2016-06-05 18:23:17,623 pykolab.auth DEBUG [32659]: Searching root dn for domain 'quetzalsailing.ch'
2016-06-05 18:23:17,623 pykolab.auth DEBUG [32659]: Returning from cache: 'dc=quetzalsailing,dc=ch'
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('dc=quetzalsailing,dc=ch',
2,
'(&(|(mail=muster2@quetzalsailing.ch)(alias=muster2@quetzalsailing.ch))(!(nsuniqueid=b8817181-2b3911e6-b4b7ab7b-af958009)))',
['mail', 'alias', 'nsuniqueid'],
True,
None,
None,
-1,
0),
{})
*** <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,625 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['peter2.muster2@quetzalsailing.ch', 'p.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,625 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,626 pykolab.auth DEBUG [32659]: secondary_mail_addresses: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,626 pykolab.auth DEBUG [32659]: entry[alias]: ['p.muster2@quetzalsailing.ch', 'peter2.muster2@quetzalsailing.ch']
2016-06-05 18:23:17,626 pykolab.auth DEBUG [32659]: Entry modifications list: {}
2016-06-05 18:23:17,626 pykolab.auth DEBUG [32659]: Result from recipient policy: {}
23:17.62 > IAAB15 LIST "" "user/muster2@quetzalsailing.ch"
23:17.62 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:17.62 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:17.62 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:17.62 < IAAB15 OK Completed (0.000 secs 15 calls)
23:17.62 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB15', 'OK', 'Completed (0.000 secs 15 calls)')
23:17.62 untagged_responses[LIST] => ['(\\HasChildren) "/" user/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,628 pykolab.auth DEBUG [32659]: Entry ID: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,628 pykolab.auth DEBUG [32659]: Entry DN: 'uid=muster2,ou=People,dc=quetzalsailing,dc=ch'
2016-06-05 18:23:17,629 pykolab.auth DEBUG [32659]: ldap search: ('uid=muster2,ou=People,dc=quetzalsailing,dc=ch', 0, filterstr='(objectclass=*)', attrlist=[ 'dn' ] + ['mailquota']
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.search_ext
(('uid=muster2,ou=People,dc=quetzalsailing,dc=ch',
0,
'(objectclass=*)',
['dn', 'mailquota'],
0,
None,
None,
-1,
0),
{})
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((38, 1, -1, 0, 0, 0), {})
23:17.63 > IAAB16 GETQUOTA "user/muster2@quetzalsailing.ch"
23:17.63 < * QUOTA user/muster2@quetzalsailing.ch ()
23:17.63 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('QUOTA', ' user/muster2@quetzalsailing.ch ()', 'user/muster2@quetzalsailing.ch ()')
23:17.63 untagged_responses[QUOTA] 0 += ["user/muster2@quetzalsailing.ch ()"]
23:17.63 < IAAB16 OK Completed
23:17.63 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB16', 'OK', 'Completed')
23:17.63 untagged_responses[QUOTA] => ['user/muster2@quetzalsailing.ch ()']
[GETQUOTA user/muster2@quetzalsailing.ch] QUOTA (Unlimited)
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
2016-06-05 18:23:17,631 pykolab.plugins DEBUG [32659]: Executing hook set_user_folder_quota for plugin dynamicquota
23:17.63 > IAAB17 LIST "" "user/muster2@quetzalsailing.ch"
23:17.63 < * LIST (\HasChildren) "/" user/muster2@quetzalsailing.ch
23:17.63 matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('LIST', ' (\\HasChildren) "/" user/muster2@quetzalsailing.ch', '(\\HasChildren) "/" user/muster2@quetzalsailing.ch')
23:17.63 untagged_responses[LIST] 0 += ["(\HasChildren) "/" user/muster2@quetzalsailing.ch"]
23:17.63 < IAAB17 OK Completed (0.000 secs 15 calls)
23:17.63 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB17', 'OK', 'Completed (0.000 secs 15 calls)')
23:17.63 untagged_responses[LIST] => ['(\\HasChildren) "/" user/muster2@quetzalsailing.ch']
2016-06-05 18:23:17,632 pykolab.imap DEBUG [32659]: Setting quota for folder user/muster2@quetzalsailing.ch to 0
23:17.63 > IAAB18 SETQUOTA "user/muster2@quetzalsailing.ch" ()
23:17.63 < IAAB18 OK Completed
23:17.63 matched r'(?P<tag>IAAB\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('IAAB18', 'OK', 'Completed')
*** <ldap.ldapobject.ReconnectLDAPObject instance at 0x2575c68> ldap://localhost:389 - ReconnectLDAPObject.result4
((3, 0, -1, 1, 1, 0), {})

File Metadata

Mime Type
text/plain
Storage Engine
blob
Storage Format
Raw Data
Storage Handle
154120
Default Alt Text
kolabd-create-new-account.log (112 KB)

Event Timeline