Fault 500: 'Connection to the APNS server could not be made.'

[aht]

The XML-RPC client got error <Fault 500: 'Connection to the APNS server could not be made.'>

Server logs:

2012-06-05 04:45:03+0000 [Uninitialized] "errback in apns-service-write : [Failure instance: Traceback: <type 'exceptions.AttributeError'>: 'NoneType' object h
as no attribute 'sendMessage'\n/opt/lib/python2.7/site-packages/pyapns/server.py:74:connectionMade\n/opt/lib/python2.7/site-packages/pyapns/server.py:141:addCl
ient\n/opt/lib/python2.7/site-packages/twisted/internet/defer.py:368:callback\n/opt/lib/python2.7/site-packages/twisted/internet/defer.py:464:_startRunCallback
s\n--- <exception caught here> ---\n/opt/lib/python2.7/site-packages/twisted/internet/defer.py:551:_runCallbacks\n/opt/lib/python2.7/site-packages/pyapns/serve
r.py:210:<lambda>\n]"
2012-06-05 04:45:03+0000 [HTTPChannel,388658,50.18.191.88] 50.18.191.88 - - [05/Jun/2012:04:45:03 +0000] "POST / HTTP/1.1" 500 7058 "-" "xmlrpclib.py/1.0.1 (by
 www.pythonware.com)"
2012-06-05 04:45:03+0000 [HTTPChannel,388659,50.18.191.88] Unhandled Error
        Traceback (most recent call last):
          File "/opt/lib/python2.7/site-packages/twisted/web/http.py", line 1349, in dataReceived
            finishCallback(data[contentLength:])
          File "/opt/lib/python2.7/site-packages/twisted/web/http.py", line 1563, in _finishRequestBody
            self.allContentReceived()
          File "/opt/lib/python2.7/site-packages/twisted/web/http.py", line 1618, in allContentReceived
            req.requestReceived(command, path, version)
          File "/opt/lib/python2.7/site-packages/twisted/web/http.py", line 773, in requestReceived
            self.process()
        --- <exception caught here> ---
          File "/opt/lib/python2.7/site-packages/twisted/web/server.py", line 132, in process
            self.render(resrc)
          File "/opt/lib/python2.7/site-packages/twisted/web/server.py", line 167, in render
            body = resrc.render(self)
          File "/opt/lib/python2.7/site-packages/twisted/web/resource.py", line 216, in render
            return m(request)
          File "/opt/lib/python2.7/site-packages/twisted/web/xmlrpc.py", line 160, in render_POST
            function = self.lookupProcedure(functionPath)
          File "/opt/lib/python2.7/site-packages/twisted/web/xmlrpc.py", line 232, in lookupProcedure
            handler = self.getSubHandler(prefix)
          File "/opt/lib/python2.7/site-packages/twisted/web/xmlrpc.py", line 140, in getSubHandler
            return self.subHandlers.get(prefix, None)
        exceptions.AttributeError: APNSServer instance has no attribute 'subHandlers'

2012-06-05 04:45:03+0000 [HTTPChannel,388659,50.18.191.88] 50.18.191.88 - - [05/Jun/2012:04:45:03 +0000] "POST / HTTP/1.1" 500 7058 "-" "xmlrpclib.py/1.0.1 (by www.pythonware.com)"

I suspect the relevant piece is <type 'exceptions.AttributeError'>: 'NoneType' object has no attribute 'sendMessage'

[gfreezy]

Installing python-epoll fixed it for me.

[nhooey]

Installing python-epoll didn't fix it for me.

I can reproduce the error by running the example listed in the README.md after checking out the repository at that version.

[nhooey]

When I run the example, the first request comes back with an error, the second request times out, and every subsequent request prints 'NoneType' object has no attribute 'sendMessage' because the callback being added on this line doesn't check if its variable is None or not.

It seems that it's possible for Twisted to invoke a callback with a None client. The pyapns code needs to be changed to account for this.

[lamenramen]

Will this work with py-kqueue? Maybe that is my problem.

[AlBlanc]

kqueue is the BSD/Os X equivalent for Linux epoll, so yes it should solved your problem if you are running mac os x or a BSD OS

[dkrol-basis]

I get this error, but only on occasion. Usually the messages go through. Is that anybody else's experience, or does this library just not work at all for those of you with the error?

python-epoll didn't fix it for me either. It seems to come up when the load is high enough. It also has the 'NoneType' object has no attribute 'sendMessage' error.

@nhooey Do you mean to say that this only happens after an error and a timeout? I wonder if this means that I'm having errors and timeouts right before this error.

Here's one thing I just discovered looking a bit more closely at my logs. This happened to me 5 times today. All 5 times, it had the following sequence:

2015-06-23 20:08:20+0000 [Uninitialized] APNSProtocol connectionMade
2015-06-23 20:08:20+0000 [Uninitialized] APNSProtocol sendMessage msg=[REDACTED]
2015-06-23 20:08:20+0000 [Uninitialized] "127.0.0.1" - - [23/Jun/2015:20:08:20 +0000] "POST / HTTP/1.1" 200 114 "-" "xmlrpclib.py/1.0.1 (by www.pythonware.com)"
2015-06-23 20:08:20+0000 [Uninitialized] "errback in apns-service-write : [Failure instance: Traceback: <type 'exceptions.AttributeError'>: 'NoneType' object has no attribute 'sendMessage'\n[REDACTED]/pyapns/server.py:74:connectionMade\n[REDACTED]/pyapns/server.py:141:addClient\n[REDACTED]/twisted/internet/defer.py:382:callback\n[REDACTED]/twisted/internet/defer.py:490:_startRunCallbacks\n--- <exception caught here> ---\n[REDACTED]/twisted/internet/defer.py:577:_runCallbacks\n[REDACTED]/pyapns/server.py:210:<lambda>\n]"

Of note: it's just starting up (connectionMade), it's [Uninitialized].

Unfortunately (for the sake of clarity), even though all 5 sendMessages with an error was in the [Uninitialized] state, there were plenty of sendMessage in [Uninitialized] state that were not errors.

I'll keep looking into what [Uninitialized] implies. I'm not familiar with Twistd. However I wanted to report this in case somebody else with insight could pick things up from here.

[dkrol-basis]

I dug in a bit and figured out the following:

When you register a callback with Twisted, the value passed into your callback function is the return value of the previously registered callback function. The exception of course is the first callback, which gets its argument from the call to .callback. In our case it passes a client object to .callback in the addClient method. See here for details on all that.

In our case the callback function is a lambda which calls sendMessage but doesn't return anything, which in Python of course defaults to None. My suspicion is that there is a race condition, causing the addCallback function to be called multiple times before being fired off by .callback. It's fired off in the addClient function, which also sets clientProtocol. With clientProtocol set, the addCallback logic is skipped in subsequent calls to write, and instead the sendMessage is called directly.

I think the idea here is that one message can be sent to the server and queued up to be executed when we finally have a client established. What was not considered is the possibility that two or more messages can be similarly queued. Or if it was considered, it wasn't handled properly.

So, bottom line, what needs to happen is for the lambda to be replaced with a function that does the same, but also returns the same client that was passed in.

[scari]

Got same problem Today.
@dkrol-basis How was your case end up with?

[dkrol-basis]

Haven't really resolved it.

[dkrol-basis]

@scari ^

[scari]

Thanks for the update @dkrol-basis