CALDAV server writes constantly too much into error log

Question

Level 2

150 points

CALDAV server writes constantly too much into error log

Hi,

i managed to set up the OS X Server and CALDAV server, everything works fine, events can be synced to devices, macs, etc.

The firewall (Cisco RV042G) allows only SSL traffic and everythings works fine.

... but then I checked the error log:

2 strange entries are written several times in a minute:

1. APNProviderFactory#error

2013-04-25 11:20:47+0200 [-] [notifications] 2013-04-25 11:20:47+0200 [-] [calendarserver.push.applepush.APNProviderFactory#error] Unable to connect to APN server: [Failure instance: Traceback: <class 'socket.gaierror'>: [Errno 8] nodename nor servname provided, or not known

I can remove this entry if I open the firewall to allow all traffic from my OS X Server machine to ANY

But I don't like to do so, only open the ports I need.

Does anybody know, what else needs to be opened from OS X Server to stop this error entry?

Currently I allow the following outgoing traffic:

Service	Port	Source	Destination
SMTP	25 TCP	OS X Server	Any
IMAP	143 TCP	OS X Server	Any
Device Enrollment	1640 TCP	OS X Server	Any
Device Management	2195 TCP	OS X Server	Any
Push Feedback Service	2196 TCP	OS X Server	Any
CALDAV SSL	8443 TCP	OS X Server	Any
CARDDAV SSL	8843 TCP	OS X Server	Any

2. every 5 seconds I see the following added to the error log:

2013-04-25 12:16:24+0200 [-] [notifications] 2013-04-25 12:16:24+0200 [-] Starting factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3cc128>

2013-04-25 12:16:24+0200 [-] [notifications] 2013-04-25 12:16:24+0200 [APNProviderProtocol (TLSMemoryBIOProtocol),client] <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3cc128> will retry in 2 seconds

2013-04-25 12:16:24+0200 [-] [notifications] 2013-04-25 12:16:24+0200 [APNProviderProtocol (TLSMemoryBIOProtocol),client] Stopping factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3cc128>

any idea what needs to be done?

Thanks a lot for any idea to get the log quiet.

~ Markus

Mac mini, OS X Server, 16GB RAM

Posted on Apr 25, 2013 3:23 AM

Reply

Answer 1

Best reply

MrHoffman

Community+ 2024

Level 10

116,199 points

Apr 25, 2013 5:33 AM in response to Markus Guske1

The nodename nor servname provided, or not known implies there's either a missing or incorrect or unknown host targeted for push notifications, or possibly errant DNS services, or there's a firewall block preventing access to the Apple servers. I'd check the push certificate is valid and current, too, but that shouldn't generate that error.

Reply

Answer 2

Markus Guske1 Author

Level 2

150 points

Apr 25, 2013 8:02 AM in response to MrHoffman

Hello MrHoffman,

yes, there is a firewall block preventing access to the Apple servers, right.

This is why it works when I open all ports from OS Server to the outside.

The question is: what else do I need to open? The list above are the current ports that I used in first place.

Regarding the "official port list" from Apple, this should be sufficient, but it isn't.

..... you inspired me to double check again and I added: Port 53 | UDP | DNS - Service,

stupid me ;-)

This was the missing port.

Any idea regarding the second issue?

Anyway thanks a lot for the reply,

~ Markus

Reply

Answer 3

Apr 25, 2013 9:54 AM in response to Markus Guske1

I am having a similar issue with my error log constantly spitting out:

2013-04-25 09:13:55-0700 [-] [notifications] 2013-04-25 09:13:55-0700 [APNProviderProtocol (TLSMemoryBIOProtocol),client] <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x1040382d8> will retry in 2 seconds

2013-04-25 09:13:55-0700 [-] [notifications] 2013-04-25 09:13:55-0700 [APNProviderProtocol (TLSMemoryBIOProtocol),client] Stopping factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x1040382d8>

2013-04-25 09:13:56-0700 [-] [notifications] 2013-04-25 09:13:56-0700 [-] Starting factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x104038518>

And now my clienst using calnedar cant even connect!

Reply

Answer 4

Markus Guske1 Author

Level 2

150 points

Apr 25, 2013 12:46 PM in response to SeanWells

Hi Sean,

mmh, are you sure, that has nothing to do with your other issue you described on "Password reset issue for users"?

Even with this constantly flooding message, my users can connect and create Events and so on.

I will write more in the other entry.

~ Markus

Reply

Answer 5

Apr 25, 2013 4:09 PM in response to Markus Guske1

I am hoping they arent linked. To that end I have no problems logging into the server from say FTP or AFP with my account yet I cannot reach the calendar server. In fact I tried toying around with things and since APNProviderProtocol is linked to the enable push notifications I disabled that option.

Now the errors I am getting consistantly are:

2013-04-25 16:01:08-0700 [-] [mailgateway] 2013-04-25 16:01:08-0700 [IMAP4DownloadProtocol,client] [twistedcaldav.mail.IMAP4DownloadProtocol#error] IMAP login failed for server@myserver.com

Whats even weirder is that when I pull up the calendar app on the server machine and try to login to my account it returns an error of no response. Checking the calendar access log it doesnt show any new connection entries. Any ideas?

I might post this as a new thread since this has gone from weird errors to just non-responsive.

Reply

Answer 6

Markus Guske1 Author

Level 2

150 points

Apr 26, 2013 3:46 AM in response to Markus Guske1

Hi,

i checked again and found, that TCP 5223 is no longer only associated to iCHAT SSL, it is now associated to Push-Notification.

I added IN - OUT for TCP 5223 and this seems to help a lot.

I updated the ports list I'm using - added that traffic is allowed incoming and outgoing to each of the ports (only DNS is outgoing)

Service	Port	In/Out	In/Out
SMTP	25 TCP	OS X Server	Any
IMAP	143 TCP	OS X Server	Any
Device Enrollment	1640 TCP	OS X Server	Any
Device Management	2195 TCP	OS X Server	Any
Push Feedback Service	2196 TCP	OS X Server	Any
CALDAV SSL	8443 TCP	OS X Server	Any
CARDDAV SSL	8843 TCP	OS X Server	Any
Push Notification	5223 TCP	OS X Server	Any
DNS	53 UDP	OS X Server [out only]	Any

The messages are no longer written constantly, they are now happing rarely.

At: 10:46 I got one new entry and the last at:

2013-04-26 12:13:30+0200 [-] [notifications] 2013-04-26 12:13:30+0200 [APNProviderProtocol (TLSMemoryBIOProtocol),client] <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3c6ea8> will retry in 2 seconds

2013-04-26 12:13:30+0200 [-] [notifications] 2013-04-26 12:13:30+0200 [APNProviderProtocol (TLSMemoryBIOProtocol),client] Stopping factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3c6ea8>

2013-04-26 12:13:33+0200 [-] [notifications] 2013-04-26 12:13:33+0200 [-] Starting factory <twext.internet.adaptendpoint.LegacyClientFactoryWrapper instance at 0x10b3c6ea8>

I'm not sure under which circumstances this happens.

First guess was adding an event or a reminder on an iPhone, but this cannot be verified.

Maybe this is because I allow only SSL in/out for CARD/CALDAV. I don't know.

But the log is more or less growing is an expected way.

So I can check other logs... I think there are some more suspicious growings out there ;-)

~ Markus

Reply