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