apns2 occasionally doesn't send any requests to apple

[Nenblereeyw]

I have a daemon process that just forwards push notifications to apple using apns2.

A handful of times when the process has started no push notifications were sent to apple. Restarting the apns2 daemon process fixes this. The contents of the apns2 successful and unsuccessful requests are exactly the same.

During the time when delivery of these push notifications failed the devices receive other push notifications. Also during this time the devices are able to directly communicate with the host that the apns2 daemon is running on.

Is there any way to enable detailed trace logging of apns2's http2 communications? For example, was it able to tcp connect, negotiate ssl, or actually send the http request?

Is there any way to enable timeouts of its requests or connection attempts?

[sideshow]

Hey @chimpmaster72 , Are you able to share more information about your setup.

1. What version of go are you running and what platform?
2. How many pushes are you sending at once?
3. Are you keeping a handle on the apns2 client and not reinitiating it for each push? Ie, you should only need do this once client := apns.NewClient(cert) not once for every push.
4. When you say no push notifications were sent to Apple, are you getting back a response from Apple or is the connection just stalling?
5. Is your daemon blocking any subsequent pushes or just one every so often? The httpclient should work in such a way that one request could block or timeout due to network conditions etc but others should work if you are using it as per (3) above.

For debugging purposes you can set the GODEBUG environment variable as follows, before you run your code, which will log out the http2 communications;

GODEBUG=http2debug=2 go run _example/main.go

[Nenblereeyw]

Thank you for the quick response!

1. go version go1.6 linux/amd64
2. In these failures the daemon sent only one push every few minutes. In these cases it did send more than one push at a time in the sense that since no response was received in several minutes the next push was sent while the previous were outstanding.
3. Yes, the client is only created once when the daemon starts up.
4. There is no response from apple and the notification is never delivered to the device.. The go routing hangs in apnsClient.Push(notification).
5. Each apnsClient.Push(notification) is called with a new go routine so I think the later requests are not blocked by lack of response to earlier requests.
6. Thank you for the pointer to that env variable. I will try it out.

This code sends the push to a go routine that really sends the request:

     notification := &apns2.Notification{
        DeviceToken: deviceId,
        ApnsID: notificationId,
        Topic: "Topic",
        Payload: payload }

      go sendRequestToApple(notification, apnsClient)

This is that go routine that really sends the request:

func sendRequestToApple(notification *apns2.Notification,
  apnsClient *apns2.Client {

  log.Println("Sending request")
  response, err := apnsClient.Push(notification)

  log.Println("Got response from apns", response, err)
}

[sideshow]

Cool thanks for the info. This is definitely strange. I have tried to reproduce here by adding extremely long delays to the time between pushes and by killing the underlying internet connection but can't yet reproduce. Any logging info that you can get from GODEBUG and paste here may help us get to the bottom of it.

Also, the following will set a timeout on the HTTPClient;

client := apns2.NewClient(cert)
client.HTTPClient.Timeout = 10 * time.Second

[Nenblereeyw]

Thanks!

This issue has only happened twice. I'll continue to try to reproduce it (without the timeout).

[Nenblereeyw]

I just managed to reproduce this twice in my development environment.

The go version, environment variables and my apns2 executable are the same as in my production environment. The main difference is that it connects to the dev apple apns2 service.

1. I started the apns2 executable and forwarded a push request through it and got no response.
2. After a minute I restarted it and forwarded another push request through it and got no response.
3. A minute later I restarted it again and forwarded a push notification that worked without issue.

During all 3 runs of the executable this was exported GODEBUG=http2debug=2.

Interestingly during the first 2 runs not a single line of go's http2 debug logging was printed.
Only my own executable's logging was printed.
Not even a http2: Transport creating client conn to ... was printed.

I don't know if there is any evidence to support this, but my gut wants to think that there may be some initialization race condition.

[imhoffd]

To add to this, I'm seeing the exact same intermittent behavior. I've also discovered that setting the timeout on the HTTPClient never triggers an actual timeout. It just hangs forever as if locked.

[sideshow]

@chimpmaster72 do you mind if i close this in favour of #20 as this now has slightly more information and they seem to be the same issue.

[sideshow]

Closed in favour of #20 which has more details