Server starts, but request issues "Message to long" error

[macosforgebot]

st.uf@… originally submitted this as ticket:448

• Owner: @glyph

---

Hi, I have CalendarServer running on OpenSuse 11.3. It runs as its own user, so may it is a privileges problem... Nevertheless, the server starts up well (see below), but when I try to access it, I get an error message like "Message too long" (also see below).

Is this some kind of misconfiguration?

Best wishes,

Stefan

---Log File---

Starting server...
/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/mail/smtp.py:10: DeprecationWarning: the MimeWriter module is deprecated; use the email package instead

  import MimeWriter, tempfile, rfc822

Reading configuration from file: /home/calendar/DarwinCalDAVServer/CalendarServer/conf/caldavd-dev.plist

2011-05-22 21:23:08+0200 [-] Log opened.

2011-05-22 21:23:08+0200 [-] twistd 10.1.0 (/usr/bin/python2.6 2.6.5) starting up.

2011-05-22 21:23:08+0200 [-] reactor class: twisted.internet.selectreactor.SelectReactor.

2011-05-22 21:23:08+0200 [-] calendarserver.accesslog.AMPLoggingFactory starting on "'/home/didsrv/CalendarServerData/Logs/state/caldavd.sock'"

2011-05-22 21:23:08+0200 [-] calendarserver.tap.caldav.CalDAVStatisticsServer starting on "'/home/didsrv/CalendarServerData/Logs/state/caldavd-stats.sock'"

2011-05-22 21:23:08+0200 [-] [txdav.base.datastore.subpostgres#info] received postgres stdout 'waiting for server to start...'

2011-05-22 21:23:08+0200 [-] [txdav.base.datastore.subpostgres#info] received postgres stdout '.'

2011-05-22 21:23:09+0200 [-] [txdav.base.datastore.subpostgres#info] received postgres stdout ' done\nserver started\n'

2011-05-22 21:23:09+0200 [-] [txdav.base.datastore.subpostgres#info] postgres process ended <twisted.python.failure.Failure <class 'twisted.internet.error.ProcessDone'>>

2011-05-22 21:23:09+0200 [-] <class 'twext.web2.metafd.LimitingInheritingProtocolFactory'> starting on 8008

2011-05-22 21:23:09+0200 [-] <class 'twext.web2.metafd.LimitingInheritingProtocolFactory'> starting on 8443

2011-05-22 21:23:09+0200 [-] <class 'twext.web2.metafd.LimitingInheritingProtocolFactory'> starting on 8008

2011-05-22 21:23:09+0200 [-] <class 'twext.web2.metafd.LimitingInheritingProtocolFactory'> starting on 8443

2011-05-22 21:23:10+0200 [-] [caldav-0] /home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/mail/smtp.py:10: DeprecationWarning: the MimeWriter module is deprecated; use the email package instead

2011-05-22 21:23:10+0200 [-] [caldav-0]   import MimeWriter, tempfile, rfc822

2011-05-22 21:23:10+0200 [-] [caldav-0] Reading configuration from file: /home/calendar/DarwinCalDAVServer/CalendarServer/conf/caldavd-dev.plist

2011-05-22 21:23:10+0200 [-] [caldav-0]  [-] Log opened.

2011-05-22 21:23:10+0200 [-] [caldav-0]  [-] twistd 10.1.0 (/usr/bin/python2.6 2.6.5) starting up.

2011-05-22 21:23:10+0200 [-] [caldav-0]  [-] reactor class: twisted.internet.selectreactor.SelectReactor.

2011-05-22 21:23:10+0200 [calendarserver.accesslog.AMPLoggingFactory] AMPLoggingProtocol connection established (HOST:UNIXAddress('/home/didsrv/CalendarServerData/Logs/state/caldavd.sock') PEER:UNIXAddress(''))

2011-05-22 21:23:10+0200 [-] [caldav-0]  [-] AMP connection established (HOST:UNIXAddress(None) PEER:UNIXAddress('/home/didsrv/CalendarServerData/Logs/state/caldavd.sock'))

2011-05-22 21:23:14+0200 [-] Unhandled Error

    Traceback (most recent call last):
      File "/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/python/log.py", line 84, in callWithLogger
        return callWithContext({"system": lp}, func, *args, **kw)
      File "/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/python/log.py", line 69, in callWithContext
        return context.call({ILogContext: newCtx}, func, *args, **kw)
      File "/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/python/context.py", line 59, in callWithContext
        return self.currentContext().callWithContext(ctx, func, *args, **kw)
      File "/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/python/context.py", line 37, in callWithContext
        return func(*args,**kw)
    --- <exception caught here> ---
      File "/home/calendar/DarwinCalDAVServer/Twisted/build/lib.linux-x86_64-2.6/twisted/internet/selectreactor.py", line 146, in _doReadOrWrite
        why = getattr(selectable, method)()
      File "/home/calendar/DarwinCalDAVServer/CalendarServer/twext/internet/sendfdport.py", line 139, in doWrite
        sendfd(self.skt.fileno(), skt.fileno(), desc)
      File "/home/calendar/DarwinCalDAVServer/CalendarServer/twext/python/sendfd.py", line 42, in sendfd
        socketfd, description, 0, [(SOL_SOCKET, SCM_RIGHTS, pack("i", fd))]
    socket.error: [Errno 90] Message too long

[macosforgebot]

ical@… originally submitted this as comment:1:⁠ticket:448

---

I am having the exact same issue on a recent checkout of calendarserver r7517, on FreeBSD 8.2 using python 2.7.1, also with a specific user and group set in the plist file.

Except that the error is "socket.error: [Errno 40] Message too long", but otherwise the same traceback.

Is there any known resolution to this problem?

Thanks in advance

Lars

[macosforgebot]

ical@… originally submitted this as comment:2:⁠ticket:448

---

Hi

It seems to be a a problem with the sendfdport branch that was merged in r5425. If I start up the server using

<key>UseMetaFD</key> <false/>

I can get it up an running. So at lease there is a workaround.

[macosforgebot]

@wsanchez originally submitted this as comment:3:⁠ticket:448

• Owner changed from @wsanchez to @glyph
• Priority changed from 5: Not set to 2: Expected

[macosforgebot]

@glyph originally submitted this as comment:4:⁠ticket:448

• Description modified

[macosforgebot]

@glyph originally submitted this as comment:5:⁠ticket:448

• Status changed from new to closed
• Resolution changed from to Software changed

---

I believe that this bug was fixed r9700. I was never able to reproduce this symptom, but there was a bug in the sendfd module that may have caused certain values to be set incorrectly in that function. Please give it another try, and reopen if it's still causing you a problem with UseMetaFD set to true.