search

lanmo / javapns

Automatically exported from code.google.com/p/javapns
0 stars 0 forks source link

Library should re-send all notifications pushed after an invalid notification referred to by an error-response packet #69

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
This works:
List<Device> devices = 
Push.alert(apm.getMessage(),"./conf/certs/keystore.apple", "password", 
true,"[token]");

This doesn't:
List<String> pushTokens = applePnsService.getTokens();
List<Device> devices = Push.alert(apm.getMessage(), 
"./conf/certs/keystore.apple", "password", true, pushTokens.toArray(new 
String[0]));

Here is the debug output:
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come back again!"}}
DEBUG: javapns.notification.PushNotificationManager -   to device: [TOKEN]
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt

What version of the product are you using? On what operating system?
2.0b4

Please provide any additional information below.
I am sending over a list of 6 tokens.  My test device is the 6th.

All 6 tokens are returned by the alert method.

What am I missing?

Original issue reported on code.google.com by amez...@gmail.com on 26 Sep 2011 at 4:57

GoogleCodeExporter commented 9 years ago 
The debug output you provided seems to be the one for the attempt that works 
(single token).  Could you provide the output for the attempt that doesn't work 
(token list)?  Thank you!

Original comment by sype...@gmail.com on 26 Sep 2011 at 5:23

GoogleCodeExporter commented 9 years ago 
That same series of messages repeats six times with the only change being the 
token.  Sorry for not being more clear.

Original comment by amez...@gmail.com on 26 Sep 2011 at 5:26

GoogleCodeExporter commented 9 years ago 
Just to be sure I understand correctly, are you simply asking why the alert 
method is returning 6 devices instead of just 1, since you are providing 5 
invalid tokens and only 1 valid token corresponding to your test device?  If 
that is what you are asking, the answer is that this method simply returns a 
list of devices that the notification was *presumably* sent to (ie tokens that 
were processed by the library).  But as stated in the 2.0 wiki page (useful 
note #3), you must not rely on that list to detect errors.  That list simply 
contains the devices that the library processed (successfully or not).

There are two ways to detect errors with APNS:  the first is the Feedback 
Service, which is fully supported;  the second is with the optional 
error-response packets (which only report malformed tokens, malformed payloads 
and such).  At this time, javapns 2.0 b4 does not support error-response 
packets (see issue #47).  I believe that the next beta release will though.

Original comment by sype...@gmail.com on 26 Sep 2011 at 5:42

GoogleCodeExporter commented 9 years ago 
All the tokens are good.  I only have access to one of the devices.  The rest 
are with the guys writing the app.  But! they just told me that I have been 
spamming them all morning with popups.  I am now going to try to reorder the 
tokens and see if that has an impact.

Original comment by amez...@gmail.com on 26 Sep 2011 at 5:44

GoogleCodeExporter commented 9 years ago 
Order seems to matter in this case.  I moved my device's token to the front and 
it worked.  Now to narrow this down more.  

Oh. I also check the feedback service every time before I send.  Nothing from 
that.
DEBUG: javapns.communication.ConnectionToAppleServer - Creating SSLSocket to 
feedback.push.apple.com:2196
DEBUG: javapns.feedback.FeedbackServiceManager - Found: [0]

Original comment by amez...@gmail.com on 26 Sep 2011 at 5:53

GoogleCodeExporter commented 9 years ago 
So, you are calling Push.alert() with a list of 6 valid tokens, and if I 
understand correctly your last comment, the notifications reach the devices.  I 
don't quite understand what exactly is the problem you are reporting, sorry :)

Or are you saying that notifications are reaching some, but not all devices?  
Are they reaching the first devices in the list, but not the last ones 
(including your own)?  Please be more specific, as it is difficult to 
understand what the issue is since you are reporting that devices do receive 
notifications.. :) Thank you.

Original comment by sype...@gmail.com on 26 Sep 2011 at 5:56

GoogleCodeExporter commented 9 years ago 
Could you please provide a full debug output (not just a clip) of your latest 
attempt, and indicate which devices do and which devices don't receive 
notifications?  Your test results are imprecise, thus difficult to get an idea 
of what is going on...  Thank you!

Original comment by sype...@gmail.com on 26 Sep 2011 at 6:38

GoogleCodeExporter commented 9 years ago 
Sorry for not being clear.  I have narrowed this down.  Some devices get the 
message, some don't.

I just hand crafted an array list of my tokens for testing.
Results:
1) My token first - success.
2) token 1 first, my token second - fail.
3) token 2 first, my token second - fail.
4) token 3 first, my token second - my device receives.
5) token 4 first, my token second - my device receives.
6) token 5 first, my token second - my device receives.
7) tokens 3 and 4 first, my token third - my device receives.

I have a feeling that I really need to see those error-response packets.  
Something is going on that is killing the message back to me.  My best guess is 
that two of my tokens are bad.  Then those errors are killing the whole 
request. I just got "lucky" because my device was at the end of the list.

Original comment by amez...@gmail.com on 26 Sep 2011 at 6:59

GoogleCodeExporter commented 9 years ago 
DEBUG: javapns.communication.ConnectionToAppleServer - Creating SSLSocketFactory
DEBUG: javapns.communication.ConnectionToAppleServer - Creating SSLSocket to 
gateway.push.apple.com:2195
DEBUG: javapns.notification.PushNotificationManager - Initialized Connection to 
Host: [gateway.push.apple.com] Port: [2195]: 1f12d4f[SSL_NULL_WITH_NULL_NULL: 
Socket[addr=gateway.push.apple.com/17.172.238.214,port=2195,localport=2802]]
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
4FA46DF130D6B0CD9BA87775D9C4FC351D04B25FD4036343A48F43C6D37A073C
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
085EE6ACB1FC8800082576108DB68F3FA08E0E010DDCA1EE65C868FD351AAD2F
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
F77EA802B7A03FAD57FCF7A8E82618C882FFB24886F3BBD52CB25C0F5207486C
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
8BFFEECBAEF80A42282B1D0492F706C8311DAC51CACE86CDEBD6976BD87DD64E
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
ABA51BE1E6494CE89E0CD09FAACDB3FD409201AC2731DF0F70E9199066F17095
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Building Raw message from 
deviceToken and payload
DEBUG: javapns.notification.PushNotificationManager - Attempting to send 
notification: {"aps":{"alert":"Come and visit the Lumber app.  We have lots of 
hardwood."}}
DEBUG: javapns.notification.PushNotificationManager -   to device: 
0D3BBE2E6381F16E9E806091DEACAE90EB0F5AC2CA9687F0BFDEDA7F7361CF81
DEBUG: javapns.notification.PushNotificationManager - Flushing
DEBUG: javapns.notification.PushNotificationManager - Notification sent on 
first attempt
DEBUG: javapns.notification.PushNotificationManager - Closing connection

Original comment by amez...@gmail.com on 26 Sep 2011 at 7:07

GoogleCodeExporter commented 9 years ago 
This is quite strange, to say the least.  Since these results seem to show 
everything's working fine, yet only some of your devices get notifications and 
apparently depending on the order they were listed in, I have added support for 
error-response packets and committed the changes as 2.0 Beta 5 (which I'm 
hoping will be a release candidate) so we can get a better understanding of 
what's going on...

Could you try the following with Beta 5 and come back here with the result:
----------------------
List<String> pushTokens = applePnsService.getTokens();
List<PushedNotifications> notifications = Push.alert(apm.getMessage(), 
"./conf/certs/keystore.apple", "password", true, pushTokens.toArray(new 
String[0]));
NotificationTest.printPushedNotifications(notifications);
----------------------

This should print detailed information about each push attempt, along with any 
error-response packet Apple replies (if any).

Thank you!

Original comment by sype...@gmail.com on 27 Sep 2011 at 1:31

GoogleCodeExporter commented 9 years ago 
Pushed notifications:
  [1] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 4FA46..A073C
  [2] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 085EE..AAD2F
  [3] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token F77EA..7486C
  [4] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 8BFFE..DD64E  APNS: Invalid token
  [5] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token ABA51..17095
  [6] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 0D3BB..1CF81

That seems to work.  F77 is the device I have in-house.  The rest were added by 
the guys making the app (outside vendor).  Maybe 8BFF was just test data for 
when they were testing my token collecting web service.

Another Run, Switched tokens 4 and 5:
Pushed notifications:
  [1] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token 4FA46..A073C
  [2] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token 085EE..AAD2F
  [3] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token F77EA..7486C
  [4] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token ABA51..17095  APNS: Invalid token
  [5] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token 8BFFE..DD64E
  [6] transmitted {"aps":{"alert":"Come and visit the Lumber app.  We have lots of hardwood."}} on first attempt to token 0D3BB..1CF81

And another test.  I put OD3BB Above ABA51:
Pushed notifications:
  [1] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 4FA46..A073C
  [2] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 085EE..AAD2F
  [3] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token F77EA..7486C
  [4] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 0D3BB..1CF81  APNS: Invalid token
  [5] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token ABA51..17095
  [6] transmitted {"aps":{"alert":"Come back again!"}} on first attempt to token 8BFFE..DD64E

Looks like only the first error is being reported!  That is really bad!

Original comment by amez...@gmail.com on 27 Sep 2011 at 2:02

GoogleCodeExporter commented 9 years ago 
Interesting!  I did some tests internally, and it does seem that Apple is 
returning an error-response packet only for the first invalid notification it 
encounters during that connection!  Looking back at Apple's documentation, it 
doesn't say if multiple error-response packets should be received for multiple 
invalid notifications, or if we should consider all notifications sent after an 
invalid one to have been ignored by Apple and we should send them again...

Since error-response packets are received only prior to disconnecting, and 
having been able to send dozens or hundreds of notifications on that same 
connection prior to disconnecting, it doesn't make any sense that all 
notifications attempted after an invalid one would be ignored.  Yet that seems 
to be what is happening.

If you remove invalid tokens from your list, I assume that your notifications 
reach all valid devices fine?

Original comment by sype...@gmail.com on 27 Sep 2011 at 2:42

GoogleCodeExporter commented 9 years ago 
You assume correctly.  Only notifications following an invalid token are 
ignored.

Original comment by amez...@gmail.com on 27 Sep 2011 at 2:43

GoogleCodeExporter commented 9 years ago 
Looking through the docs I see this line:
Figure 5-2 depicts the enhanced format for notification packets. With this 
format, if APNs encounters an unintelligible command, it returns an error 
response before disconnecting. 

I wonder when the disconnecting actually happens... On the first error?

Original comment by amez...@gmail.com on 27 Sep 2011 at 3:13

GoogleCodeExporter commented 9 years ago 
I am on a roll... 

More clues...
http://stackoverflow.com/questions/2583957/apple-push-notification-sending-high-
volumes-of-messages

Should there be a single write to the socket instead of multiple writes and 
flushes?  Sounds odd but maybe...

Another thought:
When do responses get sent back from Apple?  As we are sending tokens?  If so, 
could we check for the response after each token is sent?

Original comment by amez...@gmail.com on 27 Sep 2011 at 3:46

GoogleCodeExporter commented 9 years ago 
Disconnecting doesn't happen at the first error and is not initiated by Apple.  
It is up to the library to read response packets prior to disconnecting from 
Apple.  

Since read and write are asynchronous, and since Apple doesn't return anything 
if no error occurs, we can't check for response packets while pushing 
notifications anyway, as this would block the thread.  We could do this in a 
separate thread, but many more notifications would have time to be pushed 
before the response monitoring thread would have time to react and stop 
everything, hence we get the same problem anyway.

As for the idea about write/flush, the socket already flushes data periodically 
based on an internal buffer and other factors, so manually flushing data simply 
controls when that flushing occurs instead of relying on the socket's way of 
doing it.

This issue is a rather critical detail that Apple should have clearly 
documented... (sigh).  Consequently, when an error-response packet is received 
for a failed notification, it should automatically retry all following 
notifications because they were definitely ignored by Apple's service even 
though no error was reported about them.  Considering Apple encourages 
providers to push as many notifications as possible over a single connection, 
but then decides to ignore all notifications after a single problematic 
notification which we only know about prior to disconnecting, that's a very odd 
way of doing things....

So, I guess the library should be enhanced to support the following scenario:
* push to 3 tokens over a single connection:  [1-valid token], [2-INVALID 
token], [3-valid token]
* read response packets and disconnect
* receive an error-response packet for [2-INVALID token]
* library should start a new connection and push [3-valid token] because we 
assume it was ignored.

I will investigate how the library can be enhanced to solve this nicely.

Original comment by sype...@gmail.com on 27 Sep 2011 at 3:56

GoogleCodeExporter commented 9 years ago 
Additional note:  the following page details more experiences with the 
error-response mechanism, and does suggest that all notifications following an 
invalid one are ignored by Apple, that no error-response packets will be 
received for those ignored notifications, and that we should re-send all 
notifications following an invalid one:

http://www.make-awesome.com/2010/10/hey-apple-your-push-notifications-api-sucks/

Original comment by sype...@gmail.com on 27 Sep 2011 at 3:58

GoogleCodeExporter commented 9 years ago 
Ok, I've worked on the problem and made a lot of changes to the library to add 
an "auto re-send" feature.  Basically, the library will now try to re-send 
immediately all notifications sent AFTER a notification that was referred to by 
an error-response packet, assuming that all those notifications were ignored by 
Apple anyway (which is what we're apparently both seeing from our tests).

Could you try Beta 5 Revision 4 directly from SVN 
(http://code.google.com/p/javapns/source/browse/branches/javapns2/javapns_2.0_Be
ta_5.jar) and let me know here how it goes?  You should see a LOT more activity 
now, as the library will retry all post-error notifications until none is left 
to try.  You should also see a better summary at the end of the process, where 
devices will be grouped by failed and successful attempts.

Original comment by sype...@gmail.com on 27 Sep 2011 at 8:23

GoogleCodeExporter commented 9 years ago 
I just noticed that in my previous comment, the words "Revision 4" have been 
automatically linked to a very old code commit which has nothing to do with my 
latest release.  To avoid confusion, ignore that clickable "Revision 4" label 
and simply click the full URL on the line immediately after.

Original comment by sype...@gmail.com on 28 Sep 2011 at 1:48

GoogleCodeExporter commented 9 years ago 
It WORKS!  I moved my device's token to the end of the list of 6 (with 3 bad 
tokens).  My device received the message and there was a LOT of logging about 
retrying from after each broken token.  Now to change my code to remove/flag 
bad tokens.

Thank you VERY much for all your hard work.  I REALLY appreciate your efforts!

Original comment by amez...@gmail.com on 28 Sep 2011 at 2:16

GoogleCodeExporter commented 9 years ago 
Outstanding! :)  Thank you for your efforts in identify the real issue, this 
helped a lot in finding a solution quickly and an implementation soon after.

Closing as Fixed! :)

Original comment by sype...@gmail.com on 28 Sep 2011 at 2:59