calendar emails being rejected by postfix

[Mark Berndt]

On Mon, 21 Jun 2010 04:41:41 pm you wrote:
> Quoting Mark Berndt <marko at mechtron.com.au>:
> > Hello,
> > 
> > I've set up a group user grouptest at myserver.  I'm connected to kolab 2.3
> > by toltec connector and outlook 2003.
> > 
> > At first my grouptest at myserver would happily accept calendar invitations
> > but now it is not working.  I set up a new user, anothergroup at myserver
> > and it works fine.  I've set both up according to doc3 and I have a
> > kontact client for other testing.  The group users are set to reject if
> > conflicts, but also fail on always accept.
> > 
> > I can send emails to grouptest at myserver and they pass through postfix and
> > are collected by the client.
> > 
> > When  I have outlook generate a calendar invitation, postfix always
> > fails with
> > 5.3.0 service unavailable
> > 
> > Jun 17 18:20:59 kolab <info> postfix/smtp[29137]: 6CA0E516221:
> > to=<grouptest at myserver>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.48,
> > delays=0.06/0.04/0.02/0.36, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued
> > as D8DCF5161EB)
> > Jun 17 18:20:59 kolab <info> postfix/qmgr[26624]: 6CA0E516221: removed
> > Jun 17 18:21:00 kolab <info> postfix/pipe[29142]: D8DCF5161EB:
> > to=<grouptest at myserver>, relay=kolabmailboxfilter, delay=0.54,
> > delays=0.01/0.03/0/0.49, dsn=5.3.0, status=bounced (service unavailable)
> > 
> > When I send from kontact, I always get a grouptest declines meeting
> > invitation
> > message.
> > 
> > I've checked the ldap account details and they are the same for
> > grouptest at myserver and anothergroup at myserver
> > 
> > 
> > Has anyone seen this happen before?
> > 
> > Why does kolabmailboxfilter reject my outlook invitation email?
> > 
> > Why does the kontact invitation pass through ok but always be rejected?
> > 
> > Where do  I look for further information?
> 
> The information from the files in /kolab/var/kolab-filter/log will
> give you more information. Can you provide us with the (anonymized)
> lines from those log files? That would help us to help you analyze
> (and solve) the problem.
> 

Gunnar,

Slightly different error now, but still not working!

Action: failed

Status: 5.3.0

Diagnostic-Code: x-unix; unknown mail system error 255

nothing is being written to kolab-filter.log

from /kolab/var/kolab-filter/fatal.log

[23-Jun-2010 16:19:51] PHP Warning:  DOMDocument::createTextNode() expects 
parameter 1 to be string, array given in /kolab/lib/php/Horde/DOM.php on line 
223
[23-Jun-2010 16:19:51] PHP Catchable fatal error:  Argument 1 passed to 
DOMNode::appendChild() must be an instance of DOMNode, null given, called in 
/kolab/lib/php/Horde/Kolab/Format/XML.php on line 798 and defined in 
/kolab/lib/php/Horde/DOM.php on line 397
[23-Jun-2010 16:19:51] PHP Notice:  Unknown: SECURITY PROBLEM: insecure server 
advertised AUTH=PLAIN (errflg=1) in Unknown on line 0


filter.log

kolab:/kolab/var/kolab-filter/log# tail -n 3222  filter.log | grep 16:19
Jun 23 16:19:50 Kolab Filter [debug] [horde] Arguments: Horde_Argv_Values 
Object
Jun 23 16:19:50 Kolab Filter [debug] [horde] Found iCal data in message [on 
line 128 of "/kolab/lib/php/Horde/Kolab/Filter/Content.php"]
Jun 23 16:19:50 Kolab Filter [info] [horde] Horde_Kolab_Filter_Content 
successfully completed (sender=moc at myserver.com.au, recipients=performance-
space at myserver.com.au, studio1 at myserver.com.au, studio2 at myserver.com.au, 
client_address=192.168.1.192, id=<75FBB921F889450E9506D64D5D93FD4D at mocoffice>) 
[on line 141 of "/kolab/lib/php/Horde/Kolab/Filter/Base.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Arguments: Horde_Argv_Values 
Object
Jun 23 16:19:51 Kolab Filter [debug] [horde] Found iCal data in message [on 
line 78 of "/kolab/lib/php/Horde/Kolab/Filter/Incoming.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Calling 
resmgr_filter(kolab.myserver.com.au, moc at myserver.com.au, performance-
space at myserver.com.au, /tmp/IN.Horde_Kolab_Filter_Incoming.FJnQE7) [on line 
144 of "/kolab/lib/php/Horde/Kolab/Filter/Incoming.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Action for moc at myserver.com.au is 
ACT_REJECT_IF_CONFLICTS [on line 355 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Processing REQUEST method for 
performance-space at myserver.com.au [on line 387 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Event has UID 
040000008200E00074C5B7101A82E00800000000600D95E7EF12CB01000000000000000010000000DE9407DCF8754E46A757FDDB075536F4 
[on line 392 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Request made by 
moc at myserver.com.au [on line 397 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to epoch Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converted <1277337600> [on line 
1085 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to epoch Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converted <1277424000> [on line 
1085 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to kolab format 
1277337600 [on line 1034 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] To <2010-06-24T00:00:00Z> [on 
line 1059 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to kolab format 
1277424000 [on line 1034 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] To <2010-06-25T00:00:00Z> [on 
line 1059 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Event starts on <1277337600> 
2010-06-24T00:00:00Z and ends on <1277424000> 2010-06-25T00:00:00Z. [on line 
407 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to epoch Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converted <1277337600> [on line 
1085 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to epoch Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converted <1277424000> [on line 
1085 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Assembled event object: Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] URL = 
https://kolab.myserver.com.au/freebusy/performance-space@myserver.com.au.xfb 
[on line 782 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to kolab format 
1276092000 [on line 1034 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] To <2010-06-09T14:00:00Z> [on 
line 1059 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to kolab format 
1308492000 [on line 1034 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] To <2011-06-19T14:00:00Z> [on 
line 1059 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Free/busy info starts on 
<1276092000> 2010-06-09T14:00:00Z and ends on <1308492000> 
2011-06-19T14:00:00Z [on line 484 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converting to epoch 1308492000 
[on line 1074 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Converted <1308492000> [on line 
1085 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busyperiods: Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Extraparams: Array
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busy period from Fri, 18 Jun 2010 
10:30:00 +1000 to Fri, 18 Jun 2010 11:00:00 +1000 [on line 526 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busy period from Sat, 19 Jun 2010 
16:00:00 +1000 to Sat, 19 Jun 2010 18:00:00 +1000 [on line 526 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busy period from Sun, 20 Jun 2010 
17:00:00 +1000 to Sun, 20 Jun 2010 19:00:00 +1000 [on line 526 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busy period from Wed, 23 Jun 2010 
18:00:00 +1000 to Wed, 23 Jun 2010 21:00:00 +1000 [on line 526 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Busy period from Sun, 27 Jun 2010 
18:00:00 +1000 to Sun, 27 Jun 2010 19:30:00 +1000 [on line 526 of 
"/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [info] [horde] Adding event 
040000008200E00074C5B7101A82E00800000000600D95E7EF12CB01000000000000000010000000DE9407DCF8754E46A757FDDB075536F4 
[on line 568 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [error] [horde] PHP Error: 
DOMDocument::createTextNode() expects parameter 1 to be string, array given; 
Code: 0 [on line 146 of "/kolab/lib/php/Horde/Kolab/Filter/Response.php"]
Jun 23 16:19:51 Kolab Filter [error] [horde] PHP Error: Argument 1 passed to 
DOMNode::appendChild() must be an instance of DOMNode, null given, called in 
/kolab/lib/php/Horde/Kolab/Format/XML.php on line 798 and defined; Code: 0 [on 
line 146 of "/kolab/lib/php/Horde/Kolab/Filter/Response.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Arguments: Horde_Argv_Values 
Object
Jun 23 16:19:51 Kolab Filter [debug] [horde] Calling 
resmgr_filter(kolab.myserver.com.au, , moc at myserver.com.au, 
/tmp/IN.Horde_Kolab_Filter_Incoming.br5bj5) [on line 144 of 
"/kolab/lib/php/Horde/Kolab/Filter/Incoming.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Action for  is ACT_MANUAL [on 
line 355 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [info] [horde] Passing through message to 
moc at myserver.com.au [on line 360 of "/kolab/lib/php/Horde/Kolab/Resource.php"]
Jun 23 16:19:51 Kolab Filter [debug] [horde] Filter_Incoming successfully 
completed. [on line 174 of "/kolab/lib/php/Horde/Kolab/Filter/Incoming.php"]
Jun 23 16:19:51 Kolab Filter [info] [horde] Horde_Kolab_Filter_Incoming 
successfully completed (sender=, recipients=moc at myserver.com.au, 
client_address=, id=<20100623061951.BC2FC516265 at kolab.myserver.com.au>) [on 
line 141 of "/kolab/lib/php/Horde/Kolab/Filter/Base.php"]


Cheers,

Marko

> Cheers,
> 
> Gunnar
> 
> > Thanks
> > 
> > Marko
> > 
> > _______________________________________________
> > Kolab-users mailing list
> > Kolab-users at kolab.org
> > https://kolab.org/mailman/listinfo/kolab-users
> > 
>     >> Mail at ease - Rent a kolab groupware server at p at rdus <<
> 
> --------------------------------------------------------------------