[jsdc]

Hello,

I upgraded to 4.1 yesterday from version 4.0 (SP5).

We seem to be getting SRP disconnects every couple of minutes. The strange thing is it seems to reconnect within 2/100s of a second.

We have routed the Blackberry outbound connection via a different Internet Connection with the same results. (Different firewall as well)

System is working fine as far as users are concerned.

My service provider says it is a network connectivity problem. Has anyone seen this before? I would appreciate your thoughts.


Here are some details

I have removed some bits to keep them private shown by [** **]




Example of emails:

Alert1: <N/A> | BlackBerry Dispatcher BLACKBERRY1 (Application Event Log on EXCHANGE1) | 11/06/2006 22:31:52 (6FFFC3B1) -> [SRP] Dispatcher\SRP Connection dropped, Error=0

Alert2: <N/A> | BlackBerry Dispatcher BLACKBERRY1 (Application Event Log on EXCHANGE1) | 11/06/2006 22:31:54 (6FFFC3B0) -> [SRP] Dispatcher\SRP Connection established

---------------------------------------------------------------------------------------------------------------------------------------------------------------------

Looking at the router debug log (level 5) we see the following.


[40000] (11/06 22:31:52.925):{0xE70} [CONFIGURATION] EVENT=Loading_Configuration
[40000] (11/06 22:31:52.925):{0xE70} [RELAY_SRP:S[**MYSRP**]:007eb2f0] Error_receiving_header, ERROR=10054
[30000] (11/06 22:31:52.925):{0xE70} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bb2178] Disconnect session. IP=127.0.0.1
[40000] (11/06 22:31:52.925):{0xE70} [RELAY_SRP:S[**MYSRP**]:007eb2f0] disconnect.
[40000] (11/06 22:31:52.925):{0xE68} [DIAG] EVENT=New_SRP_Connection, IP=127.0.0.1
[40000] (11/06 22:31:52.925):{0xE68} [SERVICE_RELAY_SESSION:UNKNOWN:00bdb180] Create service session.
[30000] (11/06 22:31:52.925):{0xE68} [SERVICE_MANAGER] Connection established. Session=0x00bdb180
[40000] (11/06 22:31:52.925):{0xE68} [SERVICE_SRP:UNKNOWN:00bddfb0] Create_Session
[30000] (11/06 22:31:52.925):{0xE68} [SERVICE_RELAY_SESSION:UNKNOWN:00bdb180] Accept service session. IP=127.0.0.1, ServiceSession=0x00bddfb0
[30000] (11/06 22:31:52.925):{0x130} [DIAG] EVENT=Register_thread, THREADID=0x130, THREADNAME="SRPReceiverHandler"
[40000] (11/06 22:31:52.925):{0x130} [DEBUG] EVENTMSG="SRPReceiverHandler thread started"
[40000] (11/06 22:31:53.925):{0x2790} [DEBUG] EVENTMSG="SRPReceiverHandler thread stopped"
[30000] (11/06 22:31:53.925):{0x2790} [DIAG] EVENT=Unregister_thread, THREADID=0x2790, THREADNAME="SRPReceiverHandler"
[30000] (11/06 22:31:53.925):{0xE70} [SERVICE_MANAGER] Delete session. UID=S[**MYSRP**], Session=0x00bb2178
[40000] (11/06 22:31:53.925):{0xE70} [DEVICE_MANAGER] UpdateServices Enabled=FALSE Services=S[**MYSRP**]
[40000] (11/06 22:31:53.925):{0xE70} [SERVICE_SRP:S[**MYSRP**]:00bddfb0] Receive_CONNECT_CLAIM_UID, VERSION=1, UID=S[**MYSRP**], REQUESTED_VERSION=2
[30000] (11/06 22:31:53.925):{0xE70} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bdb180] Service claim UID. UID: S[**MYSRP**] Requested SRP Version:2, IP=127.0.0.1
[40000] (11/06 22:31:53.925):{0xE70} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bdb180] Requesting relay connection. RelaySession=0x00000000
[40000] (11/06 22:31:53.925):{0xE70} [RELAY_SRP:UNKNOWN:007efe20] Create_Session.
[40000] (11/06 22:31:53.925):{0xE70} [SERVICE_MANAGER] Delete session. Session=0x00bb2178
[40000] (11/06 22:31:53.925):{0xE70} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bb2178] Destroy service session.
[40000] (11/06 22:31:53.925):{0xE70} [SERVICE_SRP:S[**MYSRP**]:00bcb800] Destroy_Session
[40000] (11/06 22:31:53.925):{0xE70} [RELAY_SRP:S[**MYSRP**]:007eb2f0] Destroy_Session.
[40000] (11/06 22:31:53.925):{0xE70} [RELAY_SRP:S[**MYSRP**]:007eb2f0] disconnect.
[30000] (11/06 22:31:53.925):{0x27B8} [DIAG] EVENT=Register_thread, THREADID=0x27B8, THREADNAME="Unnamed"
[30000] (11/06 22:31:53.925):{0x27B8} [RELAY_SRP:UNKNOWN:007efe20] Connecting to relay at address "srp.eu.blackberry.net"
[30000] (11/06 22:31:53.972):{0x27B8} [RELAY_SRP:UNKNOWN:007efe20] Connect: Found 1 addresses for host "srp.eu.blackberry.net"
[30000] (11/06 22:31:53.972):{0x27B8} [RELAY_SRP:UNKNOWN:007efe20] Connect: Host "srp.eu.blackberry.net" @ [193.109.81.33]
[30000] (11/06 22:31:53.972):{0x27B8} [RELAY_SRP:UNKNOWN:007efe20] Connect: Trying "srp.eu.blackberry.net" @ [193.109.81.33]
[30000] (11/06 22:31:53.988):{0x27B8} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bdb180] Connection to relay established.
[30000] (11/06 22:31:53.988):{0x27B8} [DIAG] EVENT=Unregister_thread, THREADID=0x27B8, THREADNAME="Unnamed"
[40000] (11/06 22:31:54.004):{0xE70} [RELAY_SRP:S[**MYSRP**]:007efe20] Receive_CONNECT_RELAY_CHALLENGE
[40000] (11/06 22:31:54.004):{0xE70} [SERVICE_SRP:S[**MYSRP**]:00bddfb0] Receive_CONNECT_CHALLENGE, VERSION=1, CHALLENGE=[**ChallengeEntryRemoved**]@BlackBerry Enterprise Server [BlackBerryDispatcher Version 4.1.2.20 License: Full(50)] - BLACKBERRY1 [DISP] - Exchange
[40000] (11/06 22:31:54.019):{0xE70} [RELAY_SRP:S[**MYSRP**]:007efe20] Receive_CONNECT_CHALLENGE_RESPONSE
[40000] (11/06 22:31:54.019):{0xE70} [SERVICE_SRP:S[**MYSRP**]:00bddfb0] Receive_CONNECT_RESPONSE, VERSION=1
[40000] (11/06 22:31:54.035):{0xE70} [RELAY_SRP:S[**MYSRP**]:007efe20] Receive_CONNECT_ACCEPT
[30000] (11/06 22:31:54.035):{0xE70} [SERVICE_RELAY_SESSION:S[**MYSRP**]:00bdb180] Service relay connection authenticated. SRPVersion: 2
[30000] (11/06 22:31:54.035):{0xE70} [SERVICE_MANAGER] Session authenticated. UID=S[**MYSRP**], Session=0x00bdb180
[40000] (11/06 22:31:54.035):{0xE70} [DEVICE_MANAGER] UpdateServices Enabled=TRUE Services=S[**MYSRP**]

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Dispatcher Logs (level 5) show


[40333] (11/06 22:31:48.613):{0x1AA4} [BIPPa] (S[**MYSRP**]_001) Received PING (45)
[40335] (11/06 22:31:48.613):{0x1AA4} [BIPPa] (S[**MYSRP**]_001) Send PING_RESPONSE (45)
[40333] (11/06 22:31:50.160):{0x1AA8} [BIPPe] (S[**MYSRP**]:C3,agent_sync) Received PING (68)
[40335] (11/06 22:31:50.160):{0x1AA8} [BIPPe] (S[**MYSRP**]:C3,agent_sync) Send PING_RESPONSE (68)
[30000] (11/06 22:31:52.925):{0x1958} SRPClient::ReceivePacket: No received bytes (0)
[50097] (11/06 22:31:52.925):{0x1818} [SRP] Dispatcher\SRP Connection dropped, Error=0
[40000] (11/06 22:31:52.925):{0x20D8} SRPClientReceiver thread stopped
[30000] (11/06 22:31:52.925):{0x20D8} [DIAG] EVENT=Unregister_thread, THREADID=0x20D8, THREADNAME="SRPClientReceiver"
[30000] (11/06 22:31:52.925):{0x1818} [SRP] Connection lost
[40000] (11/06 22:31:52.925):{0x1818} [SRP] Connecting to "localhost"
[40000] (11/06 22:31:52.925):{0x1818} SRPClient::Connect: Found 1 addresses for host "localhost"
[40000] (11/06 22:31:52.925):{0x1818} SRPClient::Connect: Host "localhost" @ [127.0.0.1]
[40000] (11/06 22:31:52.925):{0x1818} SRPClient::Connect: Trying "localhost" @ [127.0.0.1]
[40000] (11/06 22:31:52.925):{0x1818} [SRP] EVENT=Send_CONNECT_UID_CLAIM, VERSION=1, UID=S[**MYSRP**], REQUEST_VERSION=2
[40000] (11/06 22:31:54.004):{0x1818} [SRP] EVENT=Receive_CONNECT_CHALLENGE, VERSION=1, CHALLENGE=[**ChallengeEntryRemoved**]
[40000] (11/06 22:31:54.004):{0x1818} [SRP] EVENT=Send_CONNECT_CHALLENGE, VERSION=1, CHALLENGE=[**ChallengeEntryRemoved**]@BlackBerry Enterprise Server [BlackBerryDispatcher Version 4.1.2.20 License: Full(50)] - BLACKBERRY1 [DISP] - Exchange
[40000] (11/06 22:31:54.019):{0x1818} [SRP] EVENT=Receive_CONNECT_RESPONSE, VERSION=1
[40000] (11/06 22:31:54.019):{0x1818} [SRP] EVENT=Send_CONNECT_RESPONSE, VERSION=1
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Receive_CONNECT_RESULT, VERSION=2, RESULT=0
[40000] (11/06 22:31:54.035):{0x1818} SRPClient::Authenticate: Authentication successful, Version=2
[30000] (11/06 22:31:54.035):{0x1818} [SRP] Connection established
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send info, Features=0x00000001
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send info, ComplianceLevel=0x05
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send info, Reason=1
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Send_INFO, VERSION=2, SIZE=215
[50096] (11/06 22:31:54.035):{0x1818} [SRP] Dispatcher\SRP Connection established
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Send_PING, VERSION=1, TAG=80
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Ping 80 sent
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send data, Tag=794251, Submit=0, Size=98
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Send_DATA, VERSION=2, TAG=794251, SIZE=98
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send data, Tag=794252, Submit=0, Size=98
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Send_DATA, VERSION=2, TAG=794252, SIZE=98
[40000] (11/06 22:31:54.035):{0x1818} [SRP] Send data, Tag=794253, Submit=0, Size=96
[40000] (11/06 22:31:54.035):{0x1818} [SRP] EVENT=Send_DATA, VERSION=2, TAG=794253, SIZE=96

[NJBlackBerry]

Any chance it is a duplicate SRP?

[jsdc]

Thanks for the reply.

Won't RIM disable my SRP if they see it from 2 different IP addresses at the same time?

[NJBlackBerry]

Yes.

[jsdc]

I have tracked down the source of the problem.

It turned out to be the Analysis Engine in a Cisco IPS 4240 running version 5.1.2. The IPS is inline and external to our firewall. We have the same hardware on our 2nd Internet connection so when we switched over the problem remained.

Disable the engine and the disconnects go away.

Cisco TAC, here I come.