Hi!
I have developed IIS web service to send PAP messages using Blackberry Push API over MDS.
And there is an application installed on device, configured to receive push messages on appropriate port.
Everything works well on MDS simulator.
But it's not working well in real environment:
I have installed BES Express and register several devices.
I can browse MDS url with appropriate port, so url is correct.
Also port enabled for reliable pushes is used in push message and in device application.
Here is MDS simulator log:
<2011-01-12 14:00:03.456 EET>:[272]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = PapServlet: request from 0:0:0:0:0:0:0:1 564 bytes...>
<2011-01-12 14:00:03.476 EET>:[273]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Mapping PAP request to push request for pushID:pushID:asdas>
<2011-01-12 14:00:03.479 EET>:[274]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = PushServlet: POST request from [UNKNOWN @ 0:0:0:0:0:0:0:1] to [PAPDEST=WAPPUSH%3D2100000A%253A100%2FTYPE%3DUSER%40rim.net&PORT=100&REQUESTURI=/] : -1 bytes...>
<2011-01-12 14:00:03.480 EET>:[275]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = submitting push message with id:pushID:asdas>
<2011-01-12 14:00:03.482 EET>:[276]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Executing push submit command for pushID:pushID:asdas>
<2011-01-12 14:00:03.483 EET>:[278]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Pushing message to: 2100000a>
<2011-01-12 14:00:03.484 EET>:[279]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Number of active push connections:1>
<2011-01-12 14:00:03.489 EET>:[280]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = added server-initiated connection = -872546301, push id = pushID:asdas>
<2011-01-12 14:00:03.491 EET>:[281]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Available threads in DefaultJobPool = 9 running JobRunner: DefaultJobRunner-7>
<2011-01-12 14:00:03.494 EET>:[282]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = ReceivedFromServer, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION =>
<2011-01-12 14:00:03.494 EET>:[282]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = ReceivedFromServer, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Transmission Line Section]:>
<2011-01-12 14:00:03.494 EET>:[282]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = ReceivedFromServer, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = POST / HTTP/1.1>
<2011-01-12 14:00:03.494 EET>:[282]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = ReceivedFromServer, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Headers Section]: 8 headers>
<2011-01-12 14:00:03.494 EET>:[282]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = ReceivedFromServer, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Parameters Section]: 3 parameters>
<2011-01-12 14:00:03.499 EET>:[283]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = SentToDevice, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION =>
<2011-01-12 14:00:03.499 EET>:[283]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = SentToDevice, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Transmission Line Section]:>
<2011-01-12 14:00:03.499 EET>:[283]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = SentToDevice, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = POST / HTTP/1.1>
<2011-01-12 14:00:03.499 EET>:[283]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = SentToDevice, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Headers Section]: 9 headers>
<2011-01-12 14:00:03.499 EET>:[283]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, HANDLER = HTTP, EVENT = SentToDevice, DEVICEPIN = 2100000a, CONNECTIONID = -872546301, HTTPTRANSMISSION = [Parameters Section]: 3 parameters>
<2011-01-12 14:00:03.501 EET>:[284]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Finished JobRunner: DefaultJobRunner-7, available threads in DefaultJobPool = 10, time spent = 8ms>
<2011-01-12 14:00:03.521 EET>:[287]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, EVENT = CreatedSendingQueue, DEVICEPIN = 2100000a>
<2011-01-12 14:00:03.526 EET>:[290]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, EVENT = Sending, TAG = 1288699908, DEVICEPIN = 2100000a, VERSION = 16, CONNECTIONID = -872546301, SEQUENCE = 0, TYPE = NOTIFY-REQUEST, CONNECTIONHANDLER = http, PROTOCOL = TCP, PARAMETERS = [MGONTAR/10.10.0.35:100], SIZE = 339>
<2011-01-12 14:00:03.531 EET>:[291]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Number of active push connections:0>
<2011-01-12 14:00:03.591 EET>:[292]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, EVENT = Notification, TAG = 1288699908, STATE = DELIVERED>
<2011-01-12 14:00:03.600 EET>:[296]:<MDS-CS_MDS>:<DEBUG>:<LAYER = SCM, EVENT = Device connections: AVG latency (msecs)79>
<2011-01-12 14:00:03.600 EET>:[297]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, Removed push connection:-872546301>
<2011-01-12 14:00:07.015 EET>:[298]:<MDS-CS_MDS>:<DEBUG>:<LAYER = IPPP, EVENT = RemovedSendingQueue, DEVICEPIN = 2100000a>
And here is real MDS log:
<2011-01-12 11:35:02.763 GMT>:[3932]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, PapServlet: request from 192.168.1.241 583 bytes...>
<2011-01-12 11:35:02.897 GMT>:[3933]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Mapping PAP request to push request for pushID:pushID:sdfsdfwerwer>
<2011-01-12 11:35:02.909 GMT>:[3934]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, PushServlet: POST request from [UNKNOWN @ 192.168.1.241] to [PAPDEST=WAPPUSH%3D22D7F6BD%253A7874%2FTYPE%3DUSER%40rim.net&PORT=7874&REQUESTURI=/]>
<2011-01-12 11:35:02.909 GMT>:[3934]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<push id: pushID:sdfsdfwerwer>
<2011-01-12 11:35:02.910 GMT>:[3935]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, submitting push message with id:pushID:sdfsdfwerwer>
<2011-01-12 11:35:02.910 GMT>:[3936]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Executing push submit command for pushID:pushID:sdfsdfwerwer>
<2011-01-12 11:35:02.911 GMT>:[3937]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Pushing message to: 22d7f6bd>
<2011-01-12 11:35:02.912 GMT>:[3938]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Number of active push connections:1>
<2011-01-12 11:35:02.931 GMT>:[3939]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, added server-initiated connection = -1848311806, push id = pushID:sdfsdfwerwer>
<2011-01-12 11:35:03.240 GMT>:[3940]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = IPPP, EVENT = CreatedSendingQueue, DEVICEPIN = 22d7f6bd, USERID = u3>
<2011-01-12 11:35:03.241 GMT>:[3941]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = IPPP, EVENT = Sending, TAG = 536543251, DEVICEPIN = 22d7f6bd, USERID = u3, VERSION = 16, CONNECTIONID = -1848311806, SEQUENCE = 0, TYPE = NOTIFY-REQUEST, CONNECTIONHANDLER = http, PROTOCOL = TCP, PARAMETERS = [LDN-Server1/192.168.1.240:7874], SIZE = 383>
<2011-01-12 11:35:03.241 GMT>:[3942]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Number of active push connections:0>
<2011-01-12 11:35:03.253 GMT>:[3943]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SRP, SRPID = S27700165[LDN-SERVER1:3200], EVENT = Sending, VERSION = 1, COMMAND = SEND, TAG = 536543251, SIZE = 570>
<2011-01-12 11:35:03.838 GMT>:[3944]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SRP, SRPID = S27700165[LDN-SERVER1:3200], EVENT = Receiving, VERSION = 1, COMMAND = STATUS, TAG = 536543251, SIZE = 10, STATE = DELIVERED>
<2011-01-12 11:35:04.104 GMT>:[3945]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = IPPP, EVENT = Notification, TAG = 536543251, STATE = DELIVERED>
<2011-01-12 11:35:04.121 GMT>:[3946]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Device connections: AVG latency (msecs)893>
<2011-01-12 11:35:04.135 GMT>:[3947]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<INFO >:<LAYER = IPPP, DEVICEPIN = 22d7f6bd, DOMAINNAME = LDN-Server1/192.168.1.240, CONNECTION_TYPE = PUSH_CONN, ConnectionId = -1848311806, DURATION(ms) = 1151, MFH_KBytes = 0, MTH_KBytes = 0.374, MFH_PACKET_COUNT = 0, MTH_PACKET_COUNT = 1>
<2011-01-12 11:35:04.144 GMT>:[3948]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = IPPP, Removed push connection:-1848311806>
<2011-01-12 11:35:09.264 GMT>:[3949]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = IPPP, EVENT = RemovedSendingQueue, DEVICEPIN = 22d7f6bd, USERID = u3>
<2011-01-12 11:35:58.187 GMT>:[3950]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SRP, SRPID = S27700165[LDN-SERVER1:3200], EVENT = Sending, VERSION = 1, COMMAND = INFO, SIZE = 46>
<2011-01-12 11:35:58.187 GMT>:[3951]:<MDS-CS_LDN-SERVER1_MDS-CS_1>:<DEBUG>:<LAYER = SCM, Sent health to S27700165[LDN-SERVER1:3200] Health=[0x 0000 0007 0000 0000],Mask=[0x 0000 0007 0000 0000],Load=[60]>
As you can see, logs not really differs, message is marked as delivered. But my app on device not really gets this message (as it works in mds simulator)
Please advice me, what may be wrong?
Is there some certificate to install or security settings I should configure to make this push message came to device application?
Thank you!
same question on bbforums
