[sip-comm-dev] Hundreds of Threads because of SIP REGISTER keep-alive


#1

When the keep-alive method of a SIP account is REGISTER,
SipRegistrarConnection will issue its reregister at a specific
interval. (In the default configuration, the interval in question is
relatively short so the problem being described is progressing with a
fast pace.) If everything goes according to plan, this translates to
RegistrationState#REGISTERED being fired multiple times (because
SipRegistrarConnection#reregister() will first fire REGISTERING so
when REGISTERED comes next time there will be a transition in the
RegistrationState from REGISTERING to REGISTERED and the latter will
really be fired out to the listeners).

However, OperationSetPresenceSipImpl$RegistrationListener#registrationStateChanged
doesn't care about REGISTERING and just acts on REGISTERED. And the
problem is that with each REGISTERED it will create a new Timer and
schedule a new repeating PollOfflineContactsTask with it. This
effectively brings up the number of Threads (because each Timer is
associated with a TimerThread) to an whooping number in short periods
of time. (I got from 300 to 350 Threads just in the few mutes I was
writing this e-mail.)

···

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#2

Hey Lubo,

Great catch!

I was suspecting that the SIP bundle was doing something illegal cause I
get my SC instance hanging every time I use it for more than a day. The
multiple threads problem could very well explain this behaviour.

Guess this could be your first commit :wink:

Emil

Lubomir Marinov написа:

···

When the keep-alive method of a SIP account is REGISTER,
SipRegistrarConnection will issue its reregister at a specific
interval. (In the default configuration, the interval in question is
relatively short so the problem being described is progressing with a
fast pace.) If everything goes according to plan, this translates to
RegistrationState#REGISTERED being fired multiple times (because
SipRegistrarConnection#reregister() will first fire REGISTERING so
when REGISTERED comes next time there will be a transition in the
RegistrationState from REGISTERING to REGISTERED and the latter will
really be fired out to the listeners).

However, OperationSetPresenceSipImpl$RegistrationListener#registrationStateChanged
doesn't care about REGISTERING and just acts on REGISTERED. And the
problem is that with each REGISTERED it will create a new Timer and
schedule a new repeating PollOfflineContactsTask with it. This
effectively brings up the number of Threads (because each Timer is
associated with a TimerThread) to an whooping number in short periods
of time. (I got from 300 to 350 Threads just in the few mutes I was
writing this e-mail.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#3

The patch honors RegistrationState#REGISTERED events only when there
isn't a previous event of the same type already in effect. As a
result, my SIP Communicator configuration with a Google Talk account
and a SIP account (with REGISTER keep-alive enabled) seems to be set
on 37 threads.

Regards,
Lubo

Hundreds-of-Threads-because-of-SIP-REGISTER-keep_alive.patch (7.43 KB)

···

On Wed, Jul 23, 2008 at 6:19 PM, Emil Ivov <emcho@sip-communicator.org> wrote:

Hey Lubo,

Great catch!

I was suspecting that the SIP bundle was doing something illegal cause I
get my SC instance hanging every time I use it for more than a day. The
multiple threads problem could very well explain this behaviour.

Guess this could be your first commit :wink:

Emil

Lubomir Marinov написа:

When the keep-alive method of a SIP account is REGISTER,
SipRegistrarConnection will issue its reregister at a specific
interval. (In the default configuration, the interval in question is
relatively short so the problem being described is progressing with a
fast pace.) If everything goes according to plan, this translates to
RegistrationState#REGISTERED being fired multiple times (because
SipRegistrarConnection#reregister() will first fire REGISTERING so
when REGISTERED comes next time there will be a transition in the
RegistrationState from REGISTERING to REGISTERED and the latter will
really be fired out to the listeners).

However, OperationSetPresenceSipImpl$RegistrationListener#registrationStateChanged
doesn't care about REGISTERING and just acts on REGISTERED. And the
problem is that with each REGISTERED it will create a new Timer and
schedule a new repeating PollOfflineContactsTask with it. This
effectively brings up the number of Threads (because each Timer is
associated with a TimerThread) to an whooping number in short periods
of time. (I got from 300 to 350 Threads just in the few mutes I was
writing this e-mail.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#4

Hi,
I try to run SC with Media Server – in scenario Music On Hold
I start to receive music from server and than after 10-20s it stops with following error – information:

No format has been registered for RTP Payload type 126
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@9b1670
new one is com.sun.media.rtp.PassiveSSRCInfo@1de4dd8

Any one Has an idea what to try to solve it.
Why that is happening.
And what can I do (does chenging to wav on Server would solve problem?)
I appreciate any help.

Best regards
Przemek

received request=
INVITE sip:4001@10.162.2.140:19924;transport=udp SIP/2.0

From: "4002" <sip:4002@10.162.11.182:5090>;tag=714b5b41

Call-ID: 84EFC606-9E83-49C4-8127-183C539A4700-152@10.162.11.182
CSeq: 3 INVITE
Content-Type: application/sdp
Via: SIP/2.0/UDP 10.162.11.182:5090;branch=z9hG4bK807FDAD2-E5F4-4A15-8116-3F662969E720-1357
Contact: <sip:10.162.11.182:5090>
Max-Forwards: 70
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: 100rel,timer
Content-Length: 301

v=0
o=Genesys 59 59 IN IP4 10.162.11.182
s=StreamManager 7.5.006.03
c=IN IP4 10.162.11.182
t=0 0
m=audio 8112 RTP/AVP 0 8 3 4 18 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:4 g723/8000
a=rtpmap:18 g729/8000

11:32:45.457 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processRequest().1314 Found one processor for method INVITE, processor is=OperationSetBasicTelephonySipImpl-[dn=4001 addr="4001" <sip:4001@10.162.11.812>]
11:32:45.457 FINE: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processRequest().575 received INVITE
11:32:45.457 FINE: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processRequest().581 request is an INVITE. Dialog state=Confirmed Dialog
11:32:45.457 FINER: impl.protocol.sip.ActiveCallsRepository.findCallParticipant().161 Looking for participant with dialog: gov.nist.javax.sip.stack.SIPDialog@19da967 among 1 calls
11:32:45.457 FINER: impl.protocol.sip.CallSipImpl.findCallParticipant().238 Looking for participant with dialog: gov.nist.javax.sip.stack.SIPDialog@19da967among 1 calls
11:32:45.457 FINER: impl.protocol.sip.CallSipImpl.findCallParticipant().250 Returing cp=4002 <"4002" <sip:4002@10.162.11.182:5090>>;status=Connected
11:32:45.457 FINER: impl.protocol.sip.ActiveCallsRepository.findCallParticipant().172 Returning participant 4002 <"4002" <sip:4002@10.162.11.182:5090>>;status=Connected
11:32:45.457 FINER: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processInvite().1464 Will verify whether INVITE is properly addressed.
11:32:45.457 FINE: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processInvite().1526 Invite seems ok, we'll say OK.
11:32:45.457 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.attachToTag().2246 We seem to already have a tag in this dialog. Returning
11:32:45.457 FINE: impl.media.CallSessionImpl.createSessionDescription().1300 Will create media descs with: audio public address=/10.162.2.140:5000 and video public address=/10.162.2.140:5002
11:32:45.457 FINER: impl.media.CallSessionImpl.createSessionDescription().1314 Generated SDP - v=0
o=4001 0 0 IN IP4 10.162.2.140
s=-
c=IN IP4 10.162.2.140
t=0 0
m=audio 5000 RTP/AVP 0 8 3

11:32:45.457 FINER: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processInvite().1564 will send OK response:
11:32:45.473 FINE: impl.protocol.sip.OperationSetBasicTelephonySipImpl.processInvite().1567 sent a OK response: SIP/2.0 200 OK

From: "4002" <sip:4002@10.162.11.182:5090>;tag=714b5b41

Call-ID: 84EFC606-9E83-49C4-8127-183C539A4700-152@10.162.11.182
CSeq: 3 INVITE
Via: SIP/2.0/UDP 10.162.11.182:5090;branch=z9hG4bK807FDAD2-E5F4-4A15-8116-3F662969E720-1357
User-Agent: null 1.0 0.build.by.SVN Windows XP
Content-Type: application/sdp
Content-Length: 112

v=0
o=4001 0 0 IN IP4 10.162.2.140
s=-
c=IN IP4 10.162.2.140
t=0 0
m=audio 5000 RTP/AVP 0 8 3
a=sendrecv

11:32:45.473 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.StartEvent[source=com.sun.media.content.unknown.Handler@1bfa3d3,previous=Started,current=Started,target=Started,mediaTime=javax.media.Time@10980e7,timeBaseTime=javax.media.Time@467991]
11:32:45.473 FINE: impl.media.CallSessionImpl.controllerUpdate().2305 Received a StartEvent
11:32:45.488 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processRequest().1211 received request=
ACK sip:4001@10.162.2.140:19924;transport=udp SIP/2.0

From: "4002" <sip:4002@10.162.11.182:5090>;tag=714b5b41

Call-ID: 84EFC606-9E83-49C4-8127-183C539A4700-152@10.162.11.182
CSeq: 3 ACK
Via: SIP/2.0/UDP 10.162.11.182:5090;branch=z9hG4bK807FDAD2-E5F4-4A15-8116-3F662969E720-1360
Content-Length: 0

11:32:45.488 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processRequest().1314 Found one processor for method ACK, processor is=OperationSetBasicTelephonySipImpl-[dn=4001 addr="4001" <sip:4001@10.162.11.812>]
11:32:45.488 FINER: impl.protocol.sip.ActiveCallsRepository.findCallParticipant().161 Looking for participant with dialog: gov.nist.javax.sip.stack.SIPDialog@19da967 among 1 calls
11:32:45.488 FINER: impl.protocol.sip.CallSipImpl.findCallParticipant().238 Looking for participant with dialog: gov.nist.javax.sip.stack.SIPDialog@19da967among 1 calls
11:32:45.488 FINER: impl.protocol.sip.CallSipImpl.findCallParticipant().250 Returing cp=4002 <"4002" <sip:4002@10.162.11.182:5090>>;status=Connected
11:32:45.488 FINER: impl.protocol.sip.ActiveCallsRepository.findCallParticipant().172 Returning participant 4002 <"4002" <sip:4002@10.162.11.182:5090>>;status=Connected
11:32:45.488 FINE: impl.media.CallSessionImpl.update().2120 received a new incoming stream. javax.media.rtp.event.NewReceiveStreamEvent[source = RTPManager
  SSRCCache com.sun.media.rtp.SSRCCache@1192059
  Dataport 5000
  Controlport 5001
  Address 0.0.0.0
  RTPForwarder com.sun.media.rtp.util.PacketForwarder@9ac0f5
  RTPDemux com.sun.media.rtp.RTPDemultiplexer@1f21c50]
11:32:45.488 FINE: impl.media.CallSessionImpl.update().2130 Received new RTP stream: ULAW/rtp, 8000.0 Hz, 8-bit, Mono
11:32:45.488 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.TransitionEvent[source=com.sun.media.content.unknown.Handler@16d835f,previous=Unrealized,current=Realizing,target=Realized]
11:32:45.504 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.RealizeCompleteEvent[source=com.sun.media.content.unknown.Handler@16d835f,previous=Realizing,current=Realized,target=Realized]
11:32:45.504 FINE: impl.media.CallSessionImpl.controllerUpdate().2246 A player was realized and will be started.
11:32:45.504 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.TransitionEvent[source=com.sun.media.content.unknown.Handler@16d835f,previous=Realized,current=Prefetching,target=Started]
11:32:45.520 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.PrefetchCompleteEvent[source=com.sun.media.content.unknown.Handler@16d835f,previous=Prefetching,current=Prefetched,target=Started]
11:32:45.520 FINE: impl.media.CallSessionImpl.controllerUpdate().2204 Received a ControllerEvent: javax.media.StartEvent[source=com.sun.media.content.unknown.Handler@16d835f,previous=Prefetched,current=Started,target=Started,mediaTime=javax.media.Time@15f4a7f,timeBaseTime=javax.media.Time@113e9fd]
11:32:45.520 FINE: impl.media.CallSessionImpl.controllerUpdate().2305 Received a StartEvent
11:32:47.969 FINE: impl.media.CallSessionImpl.update().2076 A new participant had just joined: 10.162.11.182
11:32:47.969 FINE: impl.media.CallSessionImpl.update().2187 The previously unidentified stream ULAW/rtp, 8000.0 Hz, 8-bit, Mono had now been identified as sent by: 10.162.11.182
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@670479
new one is com.sun.media.rtp.PassiveSSRCInfo@156b386
11:32:53.837 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processTransactionTerminated().1165 Transaction terminated for req=INVITE sip:4001@10.162.2.140:19924;transport=udp SIP/2.0

From: "4002" <sip:4002@10.162.11.182:5090>;tag=714b5b41

Call-ID: 84EFC606-9E83-49C4-8127-183C539A4700-152@10.162.11.182
CSeq: 2 INVITE
Content-Type: application/sdp
Via: SIP/2.0/UDP 10.162.11.182:5090;branch=z9hG4bK807FDAD2-E5F4-4A15-8116-3F662969E720-1354
Contact: <sip:10.162.11.182:5090>
Max-Forwards: 70
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: 100rel,timer
Content-Length: 338

v=0
o=GSIP-TREATMENT 1218047572 1 IN IP4 10.162.11.182
s=Genesys SIP Server
c=IN IP4 0.0.0.0
t=0 0
m=audio 31652 RTP/AVP 0 8 101
a=alt:1 3 : U62yl0o9 +LDFjDpQ 10.162.2.140 31652
a=alt:2 2 : hP4XpIYd EWF577dK 192.168.47.1 31652
a=alt:3 1 : iHIfE5Am VX5sys5W 192.168.134.1 31652
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

11:32:53.837 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processTransactionTerminated().1178 Found one processor for method INVITE, processor is=OperationSetBasicTelephonySipImpl-[dn=4001 addr="4001" <sip:4001@10.162.11.812>]
11:32:53.993 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processTransactionTerminated().1165 Transaction terminated for req=INVITE sip:4001@10.162.2.140:19924;transport=udp SIP/2.0

From: "4002" <sip:4002@10.162.11.182:5090>;tag=714b5b41

Call-ID: 84EFC606-9E83-49C4-8127-183C539A4700-152@10.162.11.182
CSeq: 3 INVITE
Content-Type: application/sdp
Via: SIP/2.0/UDP 10.162.11.182:5090;branch=z9hG4bK807FDAD2-E5F4-4A15-8116-3F662969E720-1357
Contact: <sip:10.162.11.182:5090>
Max-Forwards: 70
Session-Expires: 1800;refresher=uac
Min-SE: 90
Supported: 100rel,timer
Content-Length: 301

v=0
o=Genesys 59 59 IN IP4 10.162.11.182
s=StreamManager 7.5.006.03
c=IN IP4 10.162.11.182
t=0 0
m=audio 8112 RTP/AVP 0 8 3 4 18 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:4 g723/8000
a=rtpmap:18 g729/8000

11:32:53.993 FINE: impl.protocol.sip.ProtocolProviderServiceSipImpl.processTransactionTerminated().1178 Found one processor for method INVITE, processor is=OperationSetBasicTelephonySipImpl-[dn=4001 addr="4001" <sip:4001@10.162.11.812>]
No format has been registered for RTP Payload type 126
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@9b1670
new one is com.sun.media.rtp.PassiveSSRCInfo@1de4dd8
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1c8b24d
new one is com.sun.media.rtp.PassiveSSRCInfo@1320a41
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@3f4ebd
new one is com.sun.media.rtp.PassiveSSRCInfo@4a5c78
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1fcf790
new one is com.sun.media.rtp.PassiveSSRCInfo@e14d81
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1a7789c
new one is com.sun.media.rtp.PassiveSSRCInfo@1df5f21
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1de891b
new one is com.sun.media.rtp.PassiveSSRCInfo@fb6c5f
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@87e704
new one is com.sun.media.rtp.PassiveSSRCInfo@4fe91e
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@51ef4e
new one is com.sun.media.rtp.PassiveSSRCInfo@135f44e
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@13a34af
new one is com.sun.media.rtp.PassiveSSRCInfo@58dd2d
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@20c906
new one is com.sun.media.rtp.PassiveSSRCInfo@6db33c
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1263db
new one is com.sun.media.rtp.PassiveSSRCInfo@159e6e8
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1469658
new one is com.sun.media.rtp.PassiveSSRCInfo@1389b3f
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@158689a
new one is com.sun.media.rtp.PassiveSSRCInfo@13b5a3a
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1a0b53e
new one is com.sun.media.rtp.PassiveSSRCInfo@1dafb4e
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@15c97e4
new one is com.sun.media.rtp.PassiveSSRCInfo@1f8247d
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@23bdd1
new one is com.sun.media.rtp.PassiveSSRCInfo@830122
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@bf7916
new one is com.sun.media.rtp.PassiveSSRCInfo@a6af6e
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1478a2d
new one is com.sun.media.rtp.PassiveSSRCInfo@1c09624
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@c1186f
new one is com.sun.media.rtp.PassiveSSRCInfo@12b3349
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@134263a
new one is com.sun.media.rtp.PassiveSSRCInfo@b9b8d0
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1148603
new one is com.sun.media.rtp.PassiveSSRCInfo@6a63d3
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@bfed5a
new one is com.sun.media.rtp.PassiveSSRCInfo@77eb97
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@10c3a08
new one is com.sun.media.rtp.PassiveSSRCInfo@1b6235b
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@cb42cf
new one is com.sun.media.rtp.PassiveSSRCInfo@8f2ca6
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1bc4ec8
new one is com.sun.media.rtp.PassiveSSRCInfo@1d840d9
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@898540
new one is com.sun.media.rtp.PassiveSSRCInfo@8b677f
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@37d490
new one is com.sun.media.rtp.PassiveSSRCInfo@1647278
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1972e3a
new one is com.sun.media.rtp.PassiveSSRCInfo@5bf624
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@17cd15d
new one is com.sun.media.rtp.PassiveSSRCInfo@1955970
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@22ce00
new one is com.sun.media.rtp.PassiveSSRCInfo@102a0a5
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@180b22e
new one is com.sun.media.rtp.PassiveSSRCInfo@31fb31
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@162522b
new one is com.sun.media.rtp.PassiveSSRCInfo@89dd
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@15b1773
new one is com.sun.media.rtp.PassiveSSRCInfo@160bf50
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@b05236
new one is com.sun.media.rtp.PassiveSSRCInfo@1e55794
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1d8d237
new one is com.sun.media.rtp.PassiveSSRCInfo@1d13272
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@146e381
new one is com.sun.media.rtp.PassiveSSRCInfo@1024994
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@12cd19d
new one is com.sun.media.rtp.PassiveSSRCInfo@1759d12
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@9b2a51
new one is com.sun.media.rtp.PassiveSSRCInfo@f7345b
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@687ea9
new one is com.sun.media.rtp.PassiveSSRCInfo@538974
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@6545d2
new one is com.sun.media.rtp.PassiveSSRCInfo@cade31
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@2bccb2
new one is com.sun.media.rtp.PassiveSSRCInfo@18bbf55
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1be8711
new one is com.sun.media.rtp.PassiveSSRCInfo@1958cc2
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@14c28db
new one is com.sun.media.rtp.PassiveSSRCInfo@10e687b
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1c8fb4b
new one is com.sun.media.rtp.PassiveSSRCInfo@1ea0105
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@1e91a4d
new one is com.sun.media.rtp.PassiveSSRCInfo@bdc9b3
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@523df
new one is com.sun.media.rtp.PassiveSSRCInfo@1762027
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@38fff7
new one is com.sun.media.rtp.PassiveSSRCInfo@2cbc86
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@10d3f0d

···

To: "4001" <sip:4001@10.162.11.182:5090>;tag=c5fe039b
To: "4001" <sip:4001@10.162.11.182:5090>;tag=c5fe039b
Contact: "4001" <sip:4001@10.162.2.140:19924;transport=udp>
To: "4001" <sip:4001@10.162.11.182:5090>;tag=c5fe039b
To: "4001" <sip:4001@10.162.11.182:5090>;tag=c5fe039b
To: "4001" <sip:4001@10.162.11.182:5090>;tag=c5fe039b

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#5

Hey all,

We just had an offline discussion with Lubo on this one. Basically we
have a number of thread safety issues in op set presence. This comes
from the fact that with SIP we need to do all the status polling
ourselves and we do this through a bunch of TimerTasks which access (rw)
class fields randomly and could cause problems.

We have agreed to try and patch the cases that are most likely to happen
which amounts to synchronizing access to the timer field. We will come
back to SIP presence later (when time permits) and try to come up with a
solution that generally resolves the thread safety issue in there.

Cheers
Emil

Lubomir Marinov написа:

···

The patch honors RegistrationState#REGISTERED events only when there
isn't a previous event of the same type already in effect. As a
result, my SIP Communicator configuration with a Google Talk account
and a SIP account (with REGISTER keep-alive enabled) seems to be set
on 37 threads.

Regards,
Lubo

On Wed, Jul 23, 2008 at 6:19 PM, Emil Ivov <emcho@sip-communicator.org> wrote:

Hey Lubo,

Great catch!

I was suspecting that the SIP bundle was doing something illegal cause I
get my SC instance hanging every time I use it for more than a day. The
multiple threads problem could very well explain this behaviour.

Guess this could be your first commit :wink:

Emil

Lubomir Marinov написа:

When the keep-alive method of a SIP account is REGISTER,
SipRegistrarConnection will issue its reregister at a specific
interval. (In the default configuration, the interval in question is
relatively short so the problem being described is progressing with a
fast pace.) If everything goes according to plan, this translates to
RegistrationState#REGISTERED being fired multiple times (because
SipRegistrarConnection#reregister() will first fire REGISTERING so
when REGISTERED comes next time there will be a transition in the
RegistrationState from REGISTERING to REGISTERED and the latter will
really be fired out to the listeners).

However, OperationSetPresenceSipImpl$RegistrationListener#registrationStateChanged
doesn't care about REGISTERING and just acts on REGISTERED. And the
problem is that with each REGISTERED it will create a new Timer and
schedule a new repeating PollOfflineContactsTask with it. This
effectively brings up the number of Threads (because each Timer is
associated with a TimerThread) to an whooping number in short periods
of time. (I got from 300 to 350 Threads just in the few mutes I was
writing this e-mail.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

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

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#6

p-dudek schrieb:

Hi, I try to run SC with Media Server – in scenario Music On Hold
I start to receive music from server and than after 10-20s it stops with following error – information:

No format has been registered for RTP Payload type 126
changing to Passive
existing one com.sun.media.rtp.RecvSSRCInfo@9b1670
new one is com.sun.media.rtp.PassiveSSRCInfo@1de4dd8

Any one Has an idea what to try to solve it.
Why that is happening.
And what can I do (does chenging to wav on Server would solve problem?)
I appreciate any help.

Best regards
Przemek

Hi Przemek,

I'm far from being an expert on the matter or on the project, but I might still be able to help you with some information. The "RTP Payload type" is a field sent with each RTP packet, which determines the format of the contained media stream. What formats each of the recipients understand is determined by the SDP that they send to each other via SIP, before setting up the RTP media streams:

m=audio 8112 RTP/AVP 0 8 3 4 18 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:4 g723/8000
a=rtpmap:18 g729/8000

These lines determine the formats the other side can send you. The last numbers of the m=audio line are a list of such format numbers, or RTP payload types, 0 8 2 3 4 18. These numbers are used in the RTP media streams themselves, and because the other side has made known what each number means, it is clear what format is being used in the RTP media stream.

The error message you get sounds very much like the other side has sent an RTP packet with a payload type which cannot be determined, since it has not sent any information about that specific payload type.

If this is the case, there is probably a bug in the software you use to send the stream, but it is also a bug of SIP Communicator to stop, instead of just ignoring spurious packets like this one, since it would be very easy to abort existing RTP sessions from the outside in that case with a single forged packet if you can sniff the traffic, or 64K - some (number of UDP ports) packets if you can not.

To find a solution, I would use a network sniffer such as wireshark, try to find the offending packet, and try to determine the contents of it by looking at it, and then find a switch in the server software to turn that behaviour off.

When dealing with SIP telephony, network sniffers are your friends. Get one, now :slight_smile:

Hope that helps!
Wolfram

···

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net


#7

r4072 commit the patch with the addition of synchronization of the
access to the timer field (as we agreed with Emil and he described in
his e-mail).

···

On Thu, Jul 24, 2008 at 7:15 PM, Emil Ivov <emcho@sip-communicator.org> wrote:

Hey all,

We just had an offline discussion with Lubo on this one. Basically we
have a number of thread safety issues in op set presence. This comes
from the fact that with SIP we need to do all the status polling
ourselves and we do this through a bunch of TimerTasks which access (rw)
class fields randomly and could cause problems.

We have agreed to try and patch the cases that are most likely to happen
which amounts to synchronizing access to the timer field. We will come
back to SIP presence later (when time permits) and try to come up with a
solution that generally resolves the thread safety issue in there.

Cheers
Emil

Lubomir Marinov написа:

The patch honors RegistrationState#REGISTERED events only when there
isn't a previous event of the same type already in effect. As a
result, my SIP Communicator configuration with a Google Talk account
and a SIP account (with REGISTER keep-alive enabled) seems to be set
on 37 threads.

Regards,
Lubo

On Wed, Jul 23, 2008 at 6:19 PM, Emil Ivov <emcho@sip-communicator.org> wrote:

Hey Lubo,

Great catch!

I was suspecting that the SIP bundle was doing something illegal cause I
get my SC instance hanging every time I use it for more than a day. The
multiple threads problem could very well explain this behaviour.

Guess this could be your first commit :wink:

Emil

Lubomir Marinov написа:

When the keep-alive method of a SIP account is REGISTER,
SipRegistrarConnection will issue its reregister at a specific
interval. (In the default configuration, the interval in question is
relatively short so the problem being described is progressing with a
fast pace.) If everything goes according to plan, this translates to
RegistrationState#REGISTERED being fired multiple times (because
SipRegistrarConnection#reregister() will first fire REGISTERING so
when REGISTERED comes next time there will be a transition in the
RegistrationState from REGISTERING to REGISTERED and the latter will
really be fired out to the listeners).

However, OperationSetPresenceSipImpl$RegistrationListener#registrationStateChanged
doesn't care about REGISTERING and just acts on REGISTERED. And the
problem is that with each REGISTERED it will create a new Timer and
schedule a new repeating PollOfflineContactsTask with it. This
effectively brings up the number of Threads (because each Timer is
associated with a TimerThread) to an whooping number in short periods
of time. (I got from 300 to 350 Threads just in the few mutes I was
writing this e-mail.)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

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

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net