Kolab 3.4 on CentOS 6.7 (freebusy question/troubleshooting)

Soliva Andrea soliva at comcept.ch
Thu Aug 20 15:20:10 CEST 2015


Hi

I recognized that always if I create over roundcubemail a calender entry 
and use Invitation in the Background there is shown in the freebusy.log 
following entry:

==> /var/log/kolab-freebusy/freebusy.log <==
[2015-08-20 12:31:13] imap.WARNING: Failed to connect to IMAP server: -1 
{"scheme":"imaps","host":"andrea.soliva at comcept.ch","path":"/444 at localhost:993/","query":"proxy_auth=cyrus-admin","url":"imaps://andrea.soliva%40comcept.ch:MyPassword/444@localhost:993/?proxy_auth=cyrus-admin","cacheto":"/var/cache/kolab-freebusy/andrea.soliva at comcept.ch.ifb","loglevel":"300","expires":"15m","bind_dn":"uid=kolab-service,ou=Special 
Users,dc=comcept,dc=ch","fbsource":"imaps://andrea.soliva%40comcept.ch:MyPassword/444@localhost:993/?proxy_auth=cyrus-admin","filter":"(&(objectClass=kolabInetOrgPerson)(|(mail=andrea.soliva at comcept.ch)(alias=andrea.soliva at comcept.ch)))","primary_domain":"comcept.ch","lc_attributes":"mail","base_dn":"dc=comcept,dc=ch","bind_pw":"MyPassword/444","attributes":"mail","type":"ldap","mail_attributes":"mail","proxy_auth":"cyrus-admin"} 
[]

 From this point of view I recognized that in following dir there is 
nothing:

/var/cache/kolab-freebusy

After that I found following conversation: 
http://comments.gmane.org/gmane.comp.kde.kolab.user/14015

Even this conversation is not the newest one I have given a try which 
means:

vi /etc/kolab/kolab-freebusy.conf

[cyrus-imap]
admin_login = cyrus-admin
uri = imap://localhost:143
admin_password = MyPassword/444

After that I created a cron job or actually was testing it by command 
line as following:

[ $(pgrep kolab-freebusyd >/dev/null 2>&1; echo $?) -ne 0 ] && 
kolab-freebusyd --generateall -c /etc/kolab/kolab-freebusy.conf >> 
/var/log/kolab-freebusy/freebusy.log 2>&1

The files are after this command created -if the users have some 
calender entries-:

ls -la /var/lib/kolab-freebusy/
total 16
drwxr-x---.  2 root apache 4096 Aug 20 14:17 .
drwxr-xr-x. 27 root root   4096 Aug 20 03:15 ..
-rw-r--r--   1 root root   1210 Aug 20 15:00 
andrea.soliva at comcept.ch.ifb

in the log of /var/log/kolab-freebusy/freebusy.log is shown following:

(14:17:48) fbcoordinator.cpp(126):      Starting generation for user:  
"andrea.soliva at comcept.ch"
(14:17:48) kolabjob.cpp(47):    
===========================================================
(14:17:48) kolabjob.cpp(48):    starting kolab job:  
"andrea.soliva at comcept.ch"  on  "localhost" : 143
(14:17:48) authenticationjob.cpp(35):   logging in as  
"andrea.soliva at comcept.ch"  using  "cyrus-admin"
kolab-freebusyd(25997) KTcpSocket::showSslErrors: "The host name did not 
match any of the valid hosts for this certificate"
Initial SSL handshake failed. cipher.isNull() is false , 
cipher.usedBits() is 256 , the socket says: "Unknown error" and the list 
of SSL errors contains 1 items.
kolab-freebusyd(25997) KIMAP::LoginJob::handleResponse: Capabilities 
updated:  ("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", 
"AUTH=LOGIN", "AUTH=PLAIN", "SASL-IR", "COMPRESS=DEFLATE", 
"X-QUOTA=STORAGE", "X-QUOTA=MESSAGE", "X-QUOTA=X-ANNOTATION-STORAGE", 
"X-QUOTA=X-NUM-FOLDERS", "IDLE")
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
sasl_interact
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16385
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_[USER|AUTHNAME]: ' "andrea.soliva at comcept.ch" '
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16386
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_[AUTHNAME]: ' "cyrus-admin" '
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16388
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_PASS: [hidden]
(14:17:48) authenticationjob.cpp(71):   authentication successful
(14:17:48) fetchmessagesjob.cpp(61):    Fetching messages from 
Mailbox.......  "Freebusy"
(14:17:48) fetchmessagesjob.cpp(89):    no messages available, nothing 
to do
kolab-freebusyd(25997) FBGeneratorJob::onFetchFBDone: 0
(14:17:48) generatefbjob.cpp(41):       Generate f/b from mailbox:  
"Calendar/Personal Calendar"
(14:17:48) generatefbjob.cpp(42):       from:  "2015-08-20T12:17:48Z"  
to:  "2015-11-18T12:17:48Z"
(14:17:48) fetchmessagesjob.cpp(61):    Fetching messages from 
Mailbox.......  "Calendar/Personal Calendar"
(14:17:48) fetchmessagesjob.cpp(89):    no messages available, nothing 
to do
(14:17:48) generatefbjob.cpp(90):       found  0  messages
(14:17:48) generatefbjob.cpp(41):       Generate f/b from mailbox:  
"Calendar"
(14:17:48) generatefbjob.cpp(42):       from:  "2015-08-20T12:17:48Z"  
to:  "2015-11-18T12:17:48Z"
(14:17:48) fetchmessagesjob.cpp(61):    Fetching messages from 
Mailbox.......  "Calendar"
(14:17:48) fetchmessagesjob.cpp(94):    Found  258  messages
(14:17:50) generatefbjob.cpp(90):       found  258  messages
(14:17:50) mimeutils.cpp(281):  "cid:Planung_2015.1438073317.4022.xlsx"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) kolabobject.cpp(305):        MessageId:  ""
(14:17:50) kolabobject.cpp(306):        Subject:  
"E2FC0384770E3434ADC5A8D36577B99D-F031D0BEB2686934"
(14:17:50) generatefbjob.cpp(56):       Error occurrend, skipping
(14:17:50) mimeutils.cpp(281):  
"cid:Sponsorenl.Infoblatt15-16.1438073461.6251.pdf"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) kolabobject.cpp(305):        MessageId:  ""
(14:17:50) kolabobject.cpp(306):        Subject:  
"EDD42C17FAB5554D730560714E1D5F43-F031D0BEB2686934"
(14:17:50) generatefbjob.cpp(56):       Error occurrend, skipping
kolab-freebusyd(25997) KSystemTimeZonesPrivate::readConfig: 
readConfig(): local zone= "UTC"
kolab-freebusyd(25997) KSystemTimeZonesPrivate::readZoneTab: 
readZoneTab( "/usr/share/zoneinfo/zone.tab" )
(14:17:50) mimeutils.cpp(281):  "cid:CADKanadaInfo.1438324301.8946.pdf"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) mimeutils.cpp(281):  "cid:USDUSAInfo.1438324301.8947.pdf"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) kolabobject.cpp(305):        MessageId:  ""
(14:17:50) kolabobject.cpp(306):        Subject:  
"70C13862DC2695BEEE4B2E3C340A47F4-F031D0BEB2686934"
(14:17:50) generatefbjob.cpp(56):       Error occurrend, skipping
(14:17:50) mimeutils.cpp(281):  
"cid:Flyer-Abschlussfest-Canada.1439890452.1971.png"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) kolabobject.cpp(305):        MessageId:  ""
(14:17:50) kolabobject.cpp(306):        Subject:  
"BE054D6CC02F99B43C1C5443DB6EA684-F031D0BEB2686934"
(14:17:50) generatefbjob.cpp(56):       Error occurrend, skipping
(14:17:50) mimeutils.cpp(281):  "cid:EinladungGV2.1439890620.7502.doc"
(14:17:50) mimeutils.cpp(290):  could not find attachment:  "" ""
(14:17:50) kolabobject.cpp(305):        MessageId:  ""
(14:17:50) kolabobject.cpp(306):        Subject:  
"AF8D5358C47EB7C4E76387E6B2C007C6-F031D0BEB2686934"
(14:17:50) generatefbjob.cpp(56):       Error occurrend, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
event is not within the fb range, skipping
(14:17:50) generatefbjob.cpp(110):      Generating is done
(14:17:50) generatefbjob.cpp(111):      elapsed time [s]:  2.008
kolab-freebusyd(25997) MessageModifyJob::start: Writing item:  -1
(14:17:51) kolabjob.cpp(41):    lost connenction
(14:17:51) kolabjob.cpp(47):    
===========================================================
(14:17:51) kolabjob.cpp(48):    starting kolab job:  
"andrea.soliva at comcept.ch"  on  "localhost" : 143
(14:17:51) authenticationjob.cpp(35):   logging in as  
"andrea.soliva at comcept.ch"  using  "cyrus-admin"
kolab-freebusyd(25997) KTcpSocket::showSslErrors: "The host name did not 
match any of the valid hosts for this certificate"
Initial SSL handshake failed. cipher.isNull() is false , 
cipher.usedBits() is 256 , the socket says: "Unknown error" and the list 
of SSL errors contains 1 items.
kolab-freebusyd(25997) KIMAP::LoginJob::handleResponse: Capabilities 
updated:  ("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", 
"AUTH=LOGIN", "AUTH=PLAIN", "SASL-IR", "COMPRESS=DEFLATE", 
"X-QUOTA=STORAGE", "X-QUOTA=MESSAGE", "X-QUOTA=X-ANNOTATION-STORAGE", 
"X-QUOTA=X-NUM-FOLDERS", "IDLE")
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
sasl_interact
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16385
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_[USER|AUTHNAME]: ' "andrea.soliva at comcept.ch" '
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16386
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_[AUTHNAME]: ' "cyrus-admin" '
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_INTERACT id: 16388
kolab-freebusyd(25997) KIMAP::LoginJobPrivate::sasl_interact: 
SASL_CB_PASS: [hidden]
(14:17:51) authenticationjob.cpp(71):   authentication successful
(14:17:51) fbaggregatorjob.cpp(44):     starting aggregator job for  
"andrea.soliva at comcept.ch"
(14:17:51) fetchmessagesjob.cpp(61):    Fetching messages from 
Mailbox.......  "Freebusy"
(14:17:51) fetchmessagesjob.cpp(94):    Found  1  messages
(14:17:51) fbaggregatorjob.cpp(73):     aggregating fb object:  
"95979e89-3046-49eb-a35a-ada64cae7900"
(14:17:51) fbaggregatorjob.cpp(103):    wrote  
"/var/lib/kolab-freebusy/andrea.soliva at comcept.ch.ifb"
(14:17:51) kolabjob.cpp(41):    lost connenction
(14:17:51) fbcoordinator.cpp(166):      Time elapsed for user [s]:  
3.081
(14:17:51) fbcoordinator.cpp(167):      5  out of  9

 From this point of view it logs more or less ok and as mentioned the 
file was created but not the Cache:

# ls -la /var/cache/kolab-freebusy/
total 8
drwxrwx---.  2 root apache 4096 Aug 20 14:31 .
drwxr-xr-x. 12 root root   4096 Jul 15 04:33 ..

If after this config I try to use again Invitation etc. I receive again 
the following Warning:

==> /var/log/kolab-freebusy/freebusy.log <==
[2015-08-20 12:31:13] imap.WARNING: Failed to connect to IMAP server: -1 
{"scheme":"imaps","host":"andrea.soliva at comcept.ch","path":"/444 at localhost:993/","query":"proxy_auth=cyrus-admin","url":"imaps://andrea.soliva%40comcept.ch:MyPasswort/444@localhost:993/?proxy_auth=cyrus-admin","cacheto":"/var/cache/kolab-freebusy/andrea.soliva at comcept.ch.ifb","loglevel":"300","expires":"15m","bind_dn":"uid=kolab-service,ou=Special 
Users,dc=comcept,dc=ch","fbsource":"imaps://andrea.soliva%40comcept.ch:MyPasswort/444@localhost:993/?proxy_auth=cyrus-admin","filter":"(&(objectClass=kolabInetOrgPerson)(|(mail=andrea.soliva at comcept.ch)(alias=andrea.soliva at comcept.ch)))","primary_domain":"comcept.ch","lc_attributes":"mail","base_dn":"dc=comcept,dc=ch","bind_pw":"MyPasswort/444","attributes":"mail","type":"ldap","mail_attributes":"mail","proxy_auth":"cyrus-admin"} 
[]

What Looks for me funny is the first line which means shown as

{"scheme":"imaps","host":"andrea.soliva at comcept.ch","path":"/444 at localhost:993/",

Why "path":"/444 at localhost:993/" it must be shown as from my point of 
view as:

"path":"MyPassword/444 at localhost:993/"
because my Password ist not "/444" my Password is "MyPassword/444" using 
Special character "/".

Can it be that we have here a Special character Problem as for the 
Password used for "MySQL kolab Password" within the Setup from Kolab. 
This means if you use here Special character it does not work and it has 
to be changed. If Special character is use following is shown in the 
logs:

             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name: Traceback (most recent call last):
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File "/usr/libexec/postfix/kolab_smtp_access_policy", 
line 1588, in <module>
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     cache
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File "/usr/libexec/postfix/kolab_smtp_access_policy", 
line 1190, in cache_init
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     engine
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File 
"/usr/lib/python2.6/site-packages/sqlalchemy/engine/__init__.py", line 
332, in create_engine
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     return strategy.create(*args, **kwargs)
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File 
"/usr/lib/python2.6/site-packages/sqlalchemy/engine/strategies.py", line 
48, in create
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     u
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File 
"/usr/lib/python2.6/site-packages/sqlalchemy/engine/url.py", line 154, 
in make_url
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     return _parse_rfc1738_args(name_or_url)
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File 
"/usr/lib/python2.6/site-packages/sqlalchemy/engine/url.py", line 193, 
in       _parse_rfc1738_args
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     return URL(name, **components)
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:   File 
"/usr/lib/python2.6/site-packages/sqlalchemy/engine/url.py", line 59, in 
__init__
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name:     self.port
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: input 
attribute name: ValueError: invalid literal for int() with base 10: 
'*******'
             Jul  3 11:48:14 kolab postfix/submission/smtpd[8585]: 
private/submission_policy: wanted attribute: action
             Jul  3 11:48:14 kolab postfix/spawn[8592]: warning: command 
/usr/libexec/postfix/kolab_smtp_access_policy exit status 1

to change Password use:

             # mysql -u root -h localhost -p
             Password:
             > use mysql
             > UPDATE mysql.user SET Password=PASSWORD('[New Password]') 
WHERE User='kolab';
             > FLUSH PRIVILEGES;
             > Exit


             # vi /etc/kolab/kolab.conf

             ---------------- /etc/kolab/kolab.conf ----------------

             cache_uri = mysql://kolab:[Your Password]@localhost/kolab"

             ---------------- /etc/kolab/kolab.conf ----------------

Can somebody point me in the right direction meaning why is still poping 
up the WARNING in "freebusy.log" for Invitation and of course this 
Information is not shown for the user hosted on the Server as myself 
etc.

Andrea Soliva

Email: andrea.soliva at comcept.ch


More information about the users mailing list