[jitsi-users] Jitsi stops accepting or making calls after a while

Vieri1 · 2015-05-30 21:00:06 UTC

Hi,

BTW are the Jitsi users and dev mailing lists ignoring e-mail messages from providers such as Yahoo and Gmail? I tried sending several e-mails to both lists for the past weeks but they never showed up in the archives. I never had any delivery error reports. Trying my luck with another free provider.

I'm experiencing serious trouble with one of the latest Jisti builds: 2.9.5445.

The softphone works fine for a while until at some point it fails to correctly answer calls or make calls. So the only quick fix is to shut Jitsi down and launch it again.

Here's the final part of the log right after shutting Jitsi down:

2015-04-26 09:29:58.662 INFORMACIÓN: [1638] impl.protocol.sip.OperationSetBasicTelephonySipImpl.createOutgoingCall().184 Creating outgoing call to sip:[HIDDEN]@10.215.147.115
2015-04-26 09:29:58.805 INFORMACIÓN: [1652] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991 Dynamic PT map: 96=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;
2015-04-26 09:29:58.805 INFORMACIÓN: [1652] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008 PT overrides []
2015-04-26 09:29:58.895 INFORMACIÓN: [1652] service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 09:29:58.905 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info() Resetting queue, last seq added: 9223372036854775806, current seq: 40903
2015-04-26 09:29:58.922 INFORMACIÓN: [1674] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 09:29:58.943 INFORMACIÓN: [1652] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio codec/freq: PCMU/8000 Hz
2015-04-26 09:29:58.943 INFORMACIÓN: [1652] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote IP/port: 10.215.147.112/12368
2015-04-26 09:29:58.943 INFORMACIÓN: [1652] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 09:30:26.192 ADVERTENCIA: [1658] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=0, got pt=101
2015-04-26 09:30:26.192 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:26.192 GRAVE: [1658] net.sf.fmj.media.Log.error() No format has been registered for RTP payload type 101
2015-04-26 09:30:26.192 INFORMACIÓN: [1655] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1706] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1655] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1743] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 09:30:26.392 ADVERTENCIA: [1658] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=101, got pt=0
2015-04-26 09:30:26.392 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:26.452 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info() Growing packet queue to 8
2015-04-26 09:30:26.532 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 112
Receive stream stats: decoded with FEC: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for outgoing audio stream SSRC: 623479453
rtpstat:bytes sent: 238560
rtpstat:RTP sent: 1491
rtpstat:remote reported min interarrival jitter: 31.75ms
rtpstat:remote reported max interarrival jitter: 43.5ms
rtpstat:local collisions: 0
rtpstat:remote collisions: 0
rtpstat:RTCP sent: 6
rtpstat:transmit failed: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for incoming rtpmap:0 PCMU/8000 stream SSRC: 1292822869
rtpstat:packets received: 1314
rtpstat:bytes received: 223908
rtpstat:packets lost: 0
rtpstat:min interarrival jitter: 0
rtpstat:max interarrival jitter: 82
rtpstat:RTCPs received: 5
rtpstat:bad RTCP packets: 0
rtpstat:bad RTP packets: 0
rtpstat:local collisions: 0
rtpstat:malformed BYEs: 0
rtpstat:malformed RRs: 0
rtpstat:malformed SDESs: 0
rtpstat:malformed SRs: 0
rtpstat:packets looped: 0
rtpstat:remote collisions: 0
rtpstat:SRs received: 5
rtpstat:transmit failed: 0
rtpstat:unknown types: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 1299
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 1
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 2
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 112
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late by more than MAX_SIZE: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 16
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was enabled
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.

The Jitsi user was on the phone with someone and at some point there was no audio (Jitsi user who made the outgoing call could not hear anything but the other party later reported that he could hear the Jitsi user's voice, ie. the caller's voice). The user hung up but after that, there's no way Jitsi can make an outgoing call or answer an incoming call (the softphone rings, the user clicks to answer but nothing happens and the phone keeps ringing OR it stops ringing but remains in the "connecting" state). The user is forced to shut Jitsi down and launch it again.

This happened several times and after taking a look at several logs, the error message that always seems to precede the reported issue is the following:

net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=0, got pt=101

followed by:

net.sf.fmj.media.Log.error() No format has been registered for RTP payload type 101

and

net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=101, got pt=0

So it seems that FMJ is failing and abruptly stopping audio during a conversation, and Jitsi doesn't seem to recover from that and must be restarted.

Any ideas?

Vieri

lmarinov · 2015-05-30 23:01:49 UTC

I don't know about the mailing list (archives) but your messages used
to pretty much always be automatically marked as Spam by Gmail for me,
I always had to manually move them out of there.

···

2015-05-31 0:00 GMT+03:00 <vieri@openmailbox.org>:

BTW are the Jitsi users and dev mailing lists ignoring e-mail messages from
providers such as Yahoo and Gmail? I tried sending several e-mails to both
lists for the past weeks but they never showed up in the archives.

Boris_Grozev · 2015-05-31 04:22:45 UTC

Hi Vieri,

These logs indicate that a packet with pt=0 reached FMJ, which normally shouldn't happen. Does this only happen with recent versions of jitsi (the more specific you can be the easier it would be to trace)? Is the other side also running jitsi? Any particular way to reproduce?

Regards,
Boris

···

On May 31, 2015 12:00:06 AM EEST, vieri@openmailbox.org wrote:

Hi,

BTW are the Jitsi users and dev mailing lists ignoring e-mail messages
from providers such as Yahoo and Gmail? I tried sending several e-mails

to both lists for the past weeks but they never showed up in the
archives. I never had any delivery error reports. Trying my luck with
another free provider.

I'm experiencing serious trouble with one of the latest Jisti builds:
2.9.5445.

The softphone works fine for a while until at some point it fails to
correctly answer calls or make calls. So the only quick fix is to shut
Jitsi down and launch it again.

Here's the final part of the log right after shutting Jitsi down:

2015-04-26 09:29:58.662 INFORMACIÓN: [1638]
impl.protocol.sip.OperationSetBasicTelephonySipImpl.createOutgoingCall().184

Creating outgoing call to sip:[HIDDEN]@10.215.147.115
2015-04-26 09:29:58.805 INFORMACIÓN: [1652]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991
Dynamic PT map: 96=rtpmap:-1 H264/90000
fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1
H264/90000 fmtp:profile-level-id=4DE01f;
2015-04-26 09:29:58.805 INFORMACIÓN: [1652]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008

PT overrides []
2015-04-26 09:29:58.895 INFORMACIÓN: [1652]
service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 09:29:58.905 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info()

Resetting queue, last seq added: 9223372036854775806, current seq:
40903
2015-04-26 09:29:58.922 INFORMACIÓN: [1674] net.sf.fmj.media.Log.info()

Starting RTPSourceStream.
2015-04-26 09:29:58.943 INFORMACIÓN: [1652]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio codec/freq:
PCMU/8000 Hz
2015-04-26 09:29:58.943 INFORMACIÓN: [1652]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote IP/port:
10.215.147.112/12368
2015-04-26 09:29:58.943 INFORMACIÓN: [1652] net.sf.fmj.media.Log.info()

Starting RTPSourceStream.
2015-04-26 09:30:26.192 ADVERTENCIA: [1658]
net.sf.fmj.media.Log.warning() Stopping stream because of payload type
mismatch: expecting pt=0, got pt=101
2015-04-26 09:30:26.192 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:26.192 GRAVE: [1658] net.sf.fmj.media.Log.error() No
format has been registered for RTP payload type 101
2015-04-26 09:30:26.192 INFORMACIÓN: [1655] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1706] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1655] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:26.192 INFORMACIÓN: [1743] net.sf.fmj.media.Log.info()

Starting RTPSourceStream.
2015-04-26 09:30:26.392 ADVERTENCIA: [1658]
net.sf.fmj.media.Log.warning() Stopping stream because of payload type
mismatch: expecting pt=101, got pt=0
2015-04-26 09:30:26.392 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:26.452 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info()

Growing packet queue to 8
2015-04-26 09:30:26.532 INFORMACIÓN: [1658] net.sf.fmj.media.Log.info()

Growing packet queue to 16
2015-04-26 09:30:28.833 INFORMACIÓN: [1744]
org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 112
Receive stream stats: decoded with FEC: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.
2015-04-26 09:30:28.833 INFORMACIÓN: [1744]
org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for
outgoing audio stream SSRC: 623479453
rtpstat:bytes sent: 238560
rtpstat:RTP sent: 1491
rtpstat:remote reported min interarrival jitter: 31.75ms
rtpstat:remote reported max interarrival jitter: 43.5ms
rtpstat:local collisions: 0
rtpstat:remote collisions: 0
rtpstat:RTCP sent: 6
rtpstat:transmit failed: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744]
org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for
incoming rtpmap:0 PCMU/8000 stream SSRC: 1292822869
rtpstat:packets received: 1314
rtpstat:bytes received: 223908
rtpstat:packets lost: 0
rtpstat:min interarrival jitter: 0
rtpstat:max interarrival jitter: 82
rtpstat:RTCPs received: 5
rtpstat:bad RTCP packets: 0
rtpstat:bad RTP packets: 0
rtpstat:local collisions: 0
rtpstat:malformed BYEs: 0
rtpstat:malformed RRs: 0
rtpstat:malformed SDESs: 0
rtpstat:malformed SRs: 0
rtpstat:packets looped: 0
rtpstat:remote collisions: 0
rtpstat:SRs received: 5
rtpstat:transmit failed: 0
rtpstat:unknown types: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 1299
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 1
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 2
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 112
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were
late by more than MAX_SIZE: 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 0
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 16
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was
enabled
2015-04-26 09:30:28.833 INFORMACIÓN: [1744] net.sf.fmj.media.Log.info()

Stopping RTPSourceStream.

The Jitsi user was on the phone with someone and at some point there
was
no audio (Jitsi user who made the outgoing call could not hear anything

but the other party later reported that he could hear the Jitsi user's
voice, ie. the caller's voice). The user hung up but after that,
there's
no way Jitsi can make an outgoing call or answer an incoming call (the
softphone rings, the user clicks to answer but nothing happens and the
phone keeps ringing OR it stops ringing but remains in the "connecting"

state). The user is forced to shut Jitsi down and launch it again.

This happened several times and after taking a look at several logs,
the
error message that always seems to precede the reported issue is the
following:

net.sf.fmj.media.Log.warning() Stopping stream because of payload type
mismatch: expecting pt=0, got pt=101

followed by:

net.sf.fmj.media.Log.error() No format has been registered for RTP
payload type 101

and

net.sf.fmj.media.Log.warning() Stopping stream because of payload type
mismatch: expecting pt=101, got pt=0

So it seems that FMJ is failing and abruptly stopping audio during a
conversation, and Jitsi doesn't seem to recover from that and must be
restarted.

Any ideas?

Vieri

_______________________________________________
users mailing list
users@jitsi.org
Unsubscribe instructions and other list options:
http://lists.jitsi.org/mailman/listinfo/users

--
Sent from a mobile. Please excuse my brevity.

Vieri1 · 2015-05-30 23:21:06 UTC

For example, I sent an e-mail to the dev mailing list in May. I also sent more messages to "users" in the same month. I then checked the archives: 0 messages from me in "dev" and only 2 of mine from Yahoo early in the month. At some point in May, e-mails from Yahoo stopped appearing on the list.

A few days ago I also tried to subscribe to the users mailing list from a different GMAIL account. I never got the confirmation e-mail.

Now with openmailbox.org, it all seems to work fine.

Really odd.

Anyway, what I was trying to report during the last few weeks is the show-stopper FMJ bug. Any ideas on what I can try? Do you need a pcap dump? Any suggestions at all?

Thanks,

Vieri

···

On 2015-05-31 01:01, Lyubomir Marinov wrote:

2015-05-31 0:00 GMT+03:00 <vieri@openmailbox.org>:

BTW are the Jitsi users and dev mailing lists ignoring e-mail messages from
providers such as Yahoo and Gmail? I tried sending several e-mails to both
lists for the past weeks but they never showed up in the archives.

I don't know about the mailing list (archives) but your messages used
to pretty much always be automatically marked as Spam by Gmail for me,
I always had to manually move them out of there.

Vieri1 · 2015-05-31 15:07:32 UTC

Hi Boris,

There are 2 glitches here:

1) FMJ doesn't expect pt=0 but it doesn't handle the situation "cleanly" (from a user's and an application's point of view) because the audio on the Jitsi caller's end stops working but the audio on the callee's end keeps flowing. I don't know anything about this packet type but if it's "unexpected" then it should either ignore it or abort the whole audio streaming process so that the main app can handle it somehow. Besides, notice that in the log an unexpected pt=0 is then followed by an unexpected pt=101 or viceversa.

2) Jitsi seems to misbehave when FMJ hits this "bug". It's bad enough for a Jitsi user to lose audio during a conversation and have to abruptly end the call but it's even worse when the user has to restart the application in order to make and receive new calls.

If you want, I can try to revert to stable 2.8.5426 and see if the FMJ issue is reproducible there.

Jitsi versions tested and confirmed having the FMJ issue:

2.9.5445
2.9.5444
2.9.5441

I cannot confirm the issue for versions <= 2.8.5426.

Actually, we were running 2.1 before upgrading to 2.9 and never had this specific issue but there were other problems that made us move to 2.9.
So I guess I can confirm that 2.1 did not have this problem.

I've never witnessed this issue when the callee is Jitsi. It always happens when calling FROM Jitsi 2.9 to a landline or cell phone via Asterisk 1.4 PRI E1 and BRI ISDN lines.

It's not easy to reproduce and doesn't always happen. However, according to user experience, when it happens with a specific callee, it's usually reproducible because subsequent calls to the same number usually fail the same way. But this is only subjective information. If you need it I can send you a pcap produced by Jitsi itself of a call that actually failed.

Thanks,

Vieri

···

On 2015-05-31 06:22, Boris Grozev wrote:

Hi Vieri,

These logs indicate that a packet with pt=0 reached FMJ, which
normally shouldn't happen. Does this only happen with recent versions
of jitsi (the more specific you can be the easier it would be to
trace)? Is the other side also running jitsi? Any particular way to
reproduce?

Vieri1 · 2015-06-01 07:32:30 UTC

2.1 and 2.2 also had this issue (I downgraded and tested).

I can send you a pcap trace if it's of any use.

Please let me know.

Thanks,

Vieri

···

On 2015-05-31 17:07, vieri@openmailbox.org wrote:

Jitsi versions tested and confirmed having the FMJ issue:

2.9.5445
2.9.5444
2.9.5441

Boris_Grozev · 2015-06-01 08:13:33 UTC

Hi Vieri,

These logs indicate that a packet with pt=0 reached FMJ, which
normally shouldn't happen. Does this only happen with recent versions
of jitsi (the more specific you can be the easier it would be to
trace)? Is the other side also running jitsi? Any particular way to
reproduce?

Hi Boris,

There are 2 glitches here:

1) FMJ doesn't expect pt=0 but it doesn't handle the situation "cleanly"
(from a user's and an application's point of view) because the audio on
the Jitsi caller's end stops working but the audio on the callee's end
keeps flowing. I don't know anything about this packet type but if it's
"unexpected" then it should either ignore it or abort the whole audio
streaming process so that the main app can handle it somehow. Besides,
notice that in the log an unexpected pt=0 is then followed by an
unexpected pt=101 or viceversa.

2) Jitsi seems to misbehave when FMJ hits this "bug". It's bad enough
for a Jitsi user to lose audio during a conversation and have to
abruptly end the call but it's even worse when the user has to restart
the application in order to make and receive new calls.

As Emil reminded me, 0 is actually a valid payload type (for the PCMU codec). So this might be just a red herring.

···

On 31/05/15 18:07, vieri@openmailbox.org wrote:

On 2015-05-31 06:22, Boris Grozev wrote:

On 01/06/15 10:32, vieri@openmailbox.org wrote:
> I can send you a pcap trace if it's of any use.
>
> Please let me know.

We could see whether the remote side really sends PCMU packets or not. But, again, this may turn out to be unrelated.

Regards,
Boris

Vieri1 · 2015-06-01 11:25:52 UTC

Well, please take a look at the trace file I've attached.
Let's see if there's any luck.

Also, please let me know if I can try anything else.

Thanks,

Vieri

report.zip (56.1 KB)

···

On 2015-06-01 10:13, Boris Grozev wrote:

As Emil reminded me, 0 is actually a valid payload type (for the PCMU
codec). So this might be just a red herring.

On 01/06/15 10:32, vieri@openmailbox.org wrote:

I can send you a pcap trace if it's of any use.

Please let me know.

We could see whether the remote side really sends PCMU packets or not.
But, again, this may turn out to be unrelated.

Vieri1 · 2015-06-02 09:43:46 UTC

No luck I suppose?

I asked the users who were using Jitsi to run another SIP softphone and they've been making and receiving calls for several hours now without any issues.
So I'm compiling the latest Jitsi snapshot and will try again soon.

Just a note: I'm using a 32-bit Jitsi app (with a 32-bit JRE) within a 64-bit Windows 7.
That shouldn't be an issue, right?

Vieri

···

On 2015-06-01 13:25, vieri@openmailbox.org wrote:

Also, please let me know if I can try anything else.

Boris_Grozev · 2015-06-02 10:03:28 UTC

Also, please let me know if I can try anything else.

No luck I suppose?

Not really. The codec being used is PCMU, so PT=0 is absolutely normal.

I asked the users who were using Jitsi to run another SIP softphone and
they've been making and receiving calls for several hours now without
any issues.
So I'm compiling the latest Jitsi snapshot and will try again soon.

Just a note: I'm using a 32-bit Jitsi app (with a 32-bit JRE) within a
64-bit Windows 7.
That shouldn't be an issue, right?

I don't think it should be a problem.

Boris

···

On 02/06/15 12:43, vieri@openmailbox.org wrote:

On 2015-06-01 13:25, vieri@openmailbox.org wrote:

Vieri1 · 2015-06-02 10:44:58 UTC

OK, but the first message in the log is:

expecting pt=0, got pt=101

What's pt=101?
Does it have something to do with DTMF?
If so, would you suggest me to change DTMF settings somehow? My Asterisk 1.4 server has rfc2833 set for the SIP client from which this Jitsi log was taken (see below).

2015-04-26 11:49:54.657 INFORMACIÓN: [312] impl.protocol.sip.OperationSetBasicTelephonySipImpl.createOutgoingCall().184 Creating outgoing call to sip:123456789@10.215.147.115
2015-04-26 11:49:56.653 INFORMACIÓN: [328] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991 Dynamic PT map: 96=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;
2015-04-26 11:49:56.653 INFORMACIÓN: [328] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008 PT overrides []
2015-04-26 11:49:56.753 INFORMACIÓN: [328] service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 11:49:56.769 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Resetting queue, last seq added: 9223372036854775806, current seq: 33563
2015-04-26 11:49:56.831 INFORMACIÓN: [353] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 11:49:56.853 INFORMACIÓN: [328] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio codec/freq: PCMU/8000 Hz
2015-04-26 11:49:56.853 INFORMACIÓN: [328] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote IP/port: 10.215.147.112/15836
2015-04-26 11:49:56.853 INFORMACIÓN: [328] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 11:50:04.273 INFORMACIÓN: [389] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991 Dynamic PT map: 96=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1 H264/90000 fmtp:profile-level-id=4DE01f;
2015-04-26 11:50:04.273 INFORMACIÓN: [389] service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008 PT overrides []
2015-04-26 11:50:04.273 INFORMACIÓN: [389] service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 11:50:10.703 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=0, got pt=101
2015-04-26 11:50:10.703 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:10.703 GRAVE: [334] net.sf.fmj.media.Log.error() No format has been registered for RTP payload type 101
2015-04-26 11:50:10.703 INFORMACIÓN: [331] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [386] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [331] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [394] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
2015-04-26 11:50:10.753 GRAVE: [377] org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.error() BufferTransferHandler.transferData
java.lang.reflect.UndeclaredThrowableException
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.transferData(AudioMixerPushBufferStream.java:1170)
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream$1.transferData(AudioMixerPushBufferStream.java:124)
  at org.jitsi.impl.neomedia.protocol.StreamSubstituteBufferTransferHandler.transferData(StreamSubstituteBufferTransferHandler.java:82)
  at org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.runInProcessThread(WASAPIStream.java:2574)
  at org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.access$400(WASAPIStream.java:34)
  at org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream$4.run(WASAPIStream.java:2680)
Caused by: java.io.IOException
  at org.jitsi.impl.neomedia.protocol.CachingPushBufferStream.read(CachingPushBufferStream.java:385)
  at org.jitsi.impl.neomedia.conference.AudioMixer.read(AudioMixer.java:1003)
  at org.jitsi.impl.neomedia.device.AudioMixerMediaDevice$2.read(AudioMixerMediaDevice.java:323)
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.readInPushBufferStream(AudioMixerPushBufferStream.java:586)
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.readInPushBufferStreams(AudioMixerPushBufferStream.java:779)
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.read(AudioMixerPushBufferStream.java:457)
  at org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.transferData(AudioMixerPushBufferStream.java:1166)
  ... 5 more
Caused by: java.io.IOException: The source stream is closed
  at net.sf.fmj.media.multiplexer.RawBufferMux$RawBufferSourceStream.read(RawBufferMux.java:256)
  at org.jitsi.impl.neomedia.protocol.CachingPushBufferStream.transferData(CachingPushBufferStream.java:656)
  at org.jitsi.impl.neomedia.protocol.CachingPushBufferStream$1.transferData(CachingPushBufferStream.java:571)
  at net.sf.fmj.media.multiplexer.RawBufferMux$RawBufferSourceStream.run(RawBufferMux.java:380)
  at java.lang.Thread.run(Thread.java:745)
  at net.sf.fmj.media.util.MediaThread.run(MediaThread.java:202)
2015-04-26 11:50:10.903 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=101, got pt=0
2015-04-26 11:50:10.903 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:10.983 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 8
2015-04-26 11:50:11.063 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:13.463 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:13.563 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:15.963 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:16.103 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:18.503 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:18.633 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:21.033 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:21.173 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:23.573 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:23.723 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:26.123 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:26.263 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:28.663 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:28.793 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:31.193 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:31.333 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:33.733 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:33.883 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:36.283 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Shrinking packet queue to 15
2015-04-26 11:50:36.423 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Growing packet queue to 16
2015-04-26 11:50:37.883 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=0, got pt=101
2015-04-26 11:50:37.883 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:38.093 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning() Stopping stream because of payload type mismatch: expecting pt=101, got pt=0
2015-04-26 11:50:38.093 INFORMACIÓN: [334] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:38.463 INFORMACIÓN: [401] org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 1356
Receive stream stats: decoded with FEC: 0
2015-04-26 11:50:38.463 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.
2015-04-26 11:50:38.473 INFORMACIÓN: [401] org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for outgoing audio stream SSRC: 1351047631
rtpstat:bytes sent: 332320
rtpstat:RTP sent: 2077
rtpstat:remote reported min interarrival jitter: 35.5ms
rtpstat:remote reported max interarrival jitter: 36.0ms
rtpstat:local collisions: 0
rtpstat:remote collisions: 0
rtpstat:RTCP sent: 9
rtpstat:transmit failed: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for incoming rtpmap:0 PCMU/8000 stream SSRC: 1765182779
rtpstat:packets received: 2083
rtpstat:bytes received: 354448
rtpstat:packets lost: 0
rtpstat:min interarrival jitter: 38
rtpstat:max interarrival jitter: 90
rtpstat:RTCPs received: 8
rtpstat:bad RTCP packets: 0
rtpstat:bad RTP packets: 0
rtpstat:local collisions: 0
rtpstat:malformed BYEs: 0
rtpstat:malformed RRs: 0
rtpstat:malformed SDESs: 0
rtpstat:malformed SRs: 0
rtpstat:packets looped: 0
rtpstat:remote collisions: 0
rtpstat:SRs received: 8
rtpstat:transmit failed: 0
rtpstat:unknown types: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 2056
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 1
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 12
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 1346
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking: 10
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late by more than MAX_SIZE: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 16
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was enabled
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info() Stopping RTPSourceStream.

···

On 2015-06-02 12:03, Boris Grozev wrote:

On 02/06/15 12:43, vieri@openmailbox.org wrote:

On 2015-06-01 13:25, vieri@openmailbox.org wrote:

Also, please let me know if I can try anything else.

No luck I suppose?

Not really. The codec being used is PCMU, so PT=0 is absolutely normal.

Emil_Ivov1 · 2015-06-02 11:07:31 UTC

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Emil

···

On Tue, Jun 2, 2015 at 1:44 PM, <vieri@openmailbox.org> wrote:

On 2015-06-02 12:03, Boris Grozev wrote:

On 02/06/15 12:43, vieri@openmailbox.org wrote:

On 2015-06-01 13:25, vieri@openmailbox.org wrote:

Also, please let me know if I can try anything else.

No luck I suppose?

Not really. The codec being used is PCMU, so PT=0 is absolutely normal.

OK, but the first message in the log is:

expecting pt=0, got pt=101

What's pt=101?
Does it have something to do with DTMF?
If so, would you suggest me to change DTMF settings somehow? My Asterisk 1.4
server has rfc2833 set for the SIP client from which this Jitsi log was
taken (see below).

2015-04-26 11:49:54.657 INFORMACIÓN: [312]
impl.protocol.sip.OperationSetBasicTelephonySipImpl.createOutgoingCall().184
Creating outgoing call to sip:123456789@10.215.147.115
2015-04-26 11:49:56.653 INFORMACIÓN: [328]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991
Dynamic PT map: 96=rtpmap:-1 H264/90000
fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1 H264/90000
fmtp:profile-level-id=4DE01f;
2015-04-26 11:49:56.653 INFORMACIÓN: [328]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008 PT
overrides []
2015-04-26 11:49:56.753 INFORMACIÓN: [328]
service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 11:49:56.769 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Resetting queue, last seq added: 9223372036854775806, current seq: 33563
2015-04-26 11:49:56.831 INFORMACIÓN: [353] net.sf.fmj.media.Log.info()
Starting RTPSourceStream.
2015-04-26 11:49:56.853 INFORMACIÓN: [328]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio codec/freq: PCMU/8000
Hz
2015-04-26 11:49:56.853 INFORMACIÓN: [328]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote IP/port:
10.215.147.112/15836
2015-04-26 11:49:56.853 INFORMACIÓN: [328] net.sf.fmj.media.Log.info()
Starting RTPSourceStream.
2015-04-26 11:50:04.273 INFORMACIÓN: [389]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().991
Dynamic PT map: 96=rtpmap:-1 H264/90000
fmtp:profile-level-id=4DE01f;packetization-mode=1; 99=rtpmap:-1 H264/90000
fmtp:profile-level-id=4DE01f;
2015-04-26 11:50:04.273 INFORMACIÓN: [389]
service.protocol.media.MediaHandler.registerDynamicPTsWithStream().1008 PT
overrides []
2015-04-26 11:50:04.273 INFORMACIÓN: [389]
service.protocol.media.CallPeerMediaHandler.start().1921 Starting
2015-04-26 11:50:10.703 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning()
Stopping stream because of payload type mismatch: expecting pt=0, got pt=101
2015-04-26 11:50:10.703 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:10.703 GRAVE: [334] net.sf.fmj.media.Log.error() No format
has been registered for RTP payload type 101
2015-04-26 11:50:10.703 INFORMACIÓN: [331] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [386] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [331] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:10.703 INFORMACIÓN: [394] net.sf.fmj.media.Log.info()
Starting RTPSourceStream.
2015-04-26 11:50:10.753 GRAVE: [377]
org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.error()
BufferTransferHandler.transferData
java.lang.reflect.UndeclaredThrowableException
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.transferData(AudioMixerPushBufferStream.java:1170)
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream$1.transferData(AudioMixerPushBufferStream.java:124)
        at
org.jitsi.impl.neomedia.protocol.StreamSubstituteBufferTransferHandler.transferData(StreamSubstituteBufferTransferHandler.java:82)
        at
org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.runInProcessThread(WASAPIStream.java:2574)
        at
org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream.access$400(WASAPIStream.java:34)
        at
org.jitsi.impl.neomedia.jmfext.media.protocol.wasapi.WASAPIStream$4.run(WASAPIStream.java:2680)
Caused by: java.io.IOException
        at
org.jitsi.impl.neomedia.protocol.CachingPushBufferStream.read(CachingPushBufferStream.java:385)
        at
org.jitsi.impl.neomedia.conference.AudioMixer.read(AudioMixer.java:1003)
        at
org.jitsi.impl.neomedia.device.AudioMixerMediaDevice$2.read(AudioMixerMediaDevice.java:323)
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.readInPushBufferStream(AudioMixerPushBufferStream.java:586)
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.readInPushBufferStreams(AudioMixerPushBufferStream.java:779)
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.read(AudioMixerPushBufferStream.java:457)
        at
org.jitsi.impl.neomedia.conference.AudioMixerPushBufferStream.transferData(AudioMixerPushBufferStream.java:1166)
        ... 5 more
Caused by: java.io.IOException: The source stream is closed
        at
net.sf.fmj.media.multiplexer.RawBufferMux$RawBufferSourceStream.read(RawBufferMux.java:256)
        at
org.jitsi.impl.neomedia.protocol.CachingPushBufferStream.transferData(CachingPushBufferStream.java:656)
        at
org.jitsi.impl.neomedia.protocol.CachingPushBufferStream$1.transferData(CachingPushBufferStream.java:571)
        at
net.sf.fmj.media.multiplexer.RawBufferMux$RawBufferSourceStream.run(RawBufferMux.java:380)
        at java.lang.Thread.run(Thread.java:745)
        at net.sf.fmj.media.util.MediaThread.run(MediaThread.java:202)
2015-04-26 11:50:10.903 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning()
Stopping stream because of payload type mismatch: expecting pt=101, got pt=0
2015-04-26 11:50:10.903 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:10.983 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 8
2015-04-26 11:50:11.063 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:13.463 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:13.563 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:15.963 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:16.103 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:18.503 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:18.633 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:21.033 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:21.173 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:23.573 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:23.723 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:26.123 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:26.263 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:28.663 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:28.793 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:31.193 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:31.333 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:33.733 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:33.883 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:36.283 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Shrinking packet queue to 15
2015-04-26 11:50:36.423 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Growing packet queue to 16
2015-04-26 11:50:37.883 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning()
Stopping stream because of payload type mismatch: expecting pt=0, got pt=101
2015-04-26 11:50:37.883 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:38.093 ADVERTENCIA: [334] net.sf.fmj.media.Log.warning()
Stopping stream because of payload type mismatch: expecting pt=101, got pt=0
2015-04-26 11:50:38.093 INFORMACIÓN: [334] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:38.463 INFORMACIÓN: [401]
org.jitsi.impl.neomedia.MediaStreamImpl.info()
Receive stream stats: discarded RTP packets: 1356
Receive stream stats: decoded with FEC: 0
2015-04-26 11:50:38.463 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.
2015-04-26 11:50:38.473 INFORMACIÓN: [401]
org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for
outgoing audio stream SSRC: 1351047631
rtpstat:bytes sent: 332320
rtpstat:RTP sent: 2077
rtpstat:remote reported min interarrival jitter: 35.5ms
rtpstat:remote reported max interarrival jitter: 36.0ms
rtpstat:local collisions: 0
rtpstat:remote collisions: 0
rtpstat:RTCP sent: 9
rtpstat:transmit failed: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401]
org.jitsi.impl.neomedia.MediaStreamImpl.info() rtpstat:call stats for
incoming rtpmap:0 PCMU/8000 stream SSRC: 1765182779
rtpstat:packets received: 2083
rtpstat:bytes received: 354448
rtpstat:packets lost: 0
rtpstat:min interarrival jitter: 38
rtpstat:max interarrival jitter: 90
rtpstat:RTCPs received: 8
rtpstat:bad RTCP packets: 0
rtpstat:bad RTP packets: 0
rtpstat:local collisions: 0
rtpstat:malformed BYEs: 0
rtpstat:malformed RRs: 0
rtpstat:malformed SDESs: 0
rtpstat:malformed SRs: 0
rtpstat:packets looped: 0
rtpstat:remote collisions: 0
rtpstat:SRs received: 8
rtpstat:transmit failed: 0
rtpstat:unknown types: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Total packets added: 2056
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times reset() called: 1
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Times grow() called: 12
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because full: 1346
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped while shrinking: 10
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late:
0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped because they were late
by more than MAX_SIZE: 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Packets dropped in reset(): 0
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Max size reached: 16
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
net.sf.fmj.media.rtp.RTPSourceStream Adaptive jitter buffer mode was enabled
2015-04-26 11:50:38.473 INFORMACIÓN: [401] net.sf.fmj.media.Log.info()
Stopping RTPSourceStream.

_______________________________________________
users mailing list
users@jitsi.org
Unsubscribe instructions and other list options:
http://lists.jitsi.org/mailman/listinfo/users

--
https://jitsi.org

Vieri1 · 2015-06-02 11:49:53 UTC

I'm attaching the trace file. The first packet in the file is SIP/SDP for that same call.

Vieri

fail1_sdp.zip (4.31 KB)

···

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Vieri1 · 2015-06-02 12:04:19 UTC

And here's another more recent call with the same issue.
I'm attaching 2 zip files: Jitsi log and Jitsi pcap where you can see the SDP offer/answer.

Vieri

fail2.zip (1.38 KB)

fail2_sdp.zip (5.74 KB)

···

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

Vieri1 · 2015-06-03 08:38:19 UTC

Hi,

Did you have a chance to look at the trace files I sent?

The softphones I asked my users to use while we try to fix Jitsi have a list of preferred audio codecs where gsm comes before ulaw. So the only big difference I see between both softphones is that Jitsi always uses ulaw (because I provision the Jitsi client and enable just this one codec since I've experienced trouble with gsm) and the other softphone always uses gsm.
I really don't see why that should matter but maybe I'll try using gsm with Jitsi again or alaw.

Vieri

···

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Vieri1 · 2015-06-03 11:39:48 UTC

Tried using Jitsi with only gsm codec but I'm still getting the same pt=101 issues.
So the choice of audio codec doesn't seem to matter.

Vieri

···

On 2015-06-03 10:38, vieri@openmailbox.org wrote:

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Hi,

Did you have a chance to look at the trace files I sent?

The softphones I asked my users to use while we try to fix Jitsi have
a list of preferred audio codecs where gsm comes before ulaw. So the
only big difference I see between both softphones is that Jitsi always
uses ulaw (because I provision the Jitsi client and enable just this
one codec since I've experienced trouble with gsm) and the other
softphone always uses gsm.
I really don't see why that should matter but maybe I'll try using gsm
with Jitsi again or alaw.

Vieri1 · 2015-06-05 10:28:45 UTC

I've been testing Jitsi with SIP INFO as DTMF instead of RFC2833. I've never had any audio issues with it (as described in my previous posts) for almost 48 hours.
I might be mistaken but it seems that Jitsi is having trouble when used with an Asterisk 1.4 SIP account with dtmfmode=rfc2833 whereas no issues are reported with dtmfmode=info.

Any thoughts?

Thanks,

Vieri

···

On 2015-06-03 13:39, vieri@openmailbox.org wrote:

On 2015-06-03 10:38, vieri@openmailbox.org wrote:

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Hi,

Did you have a chance to look at the trace files I sent?

The softphones I asked my users to use while we try to fix Jitsi have
a list of preferred audio codecs where gsm comes before ulaw. So the
only big difference I see between both softphones is that Jitsi always
uses ulaw (because I provision the Jitsi client and enable just this
one codec since I've experienced trouble with gsm) and the other
softphone always uses gsm.
I really don't see why that should matter but maybe I'll try using gsm
with Jitsi again or alaw.

Tried using Jitsi with only gsm codec but I'm still getting the same
pt=101 issues.
So the choice of audio codec doesn't seem to matter.

Vieri1 · 2015-06-24 10:01:36 UTC

After more than 2 weeks testing I can confirm that the bug (JMF?) does not manifest itself when using:

DTMFmode : info

instead of

DTMFmode : rfc2833

So maybe JMF and/or Jitsi are mishandling something related to DTMF mode rfc2833.

I don't mind switching all SIP users to SIP INFO because fortunately for now all the clients support this mode but it would be useful to know if anyone else is experiencing issues with more recent Asterisk systems (> 1.4) and rfc2833.

Thanks,

Vieri

···

On 2015-06-05 12:28, vieri@openmailbox.org wrote:

On 2015-06-03 13:39, vieri@openmailbox.org wrote:

On 2015-06-03 10:38, vieri@openmailbox.org wrote:

On 2015-06-02 13:07, Emil Ivov wrote:

Could you please share the SDP offer answer that negotiated this call?

It is very strange to me that Jitsi is getting 101. Yes this is often
telephone-event (DTMF per RFC 4733 (previously 2833)) but I don't see
why Asterisk would want to sent this to Jitsi.

Hi,

Did you have a chance to look at the trace files I sent?

The softphones I asked my users to use while we try to fix Jitsi have
a list of preferred audio codecs where gsm comes before ulaw. So the
only big difference I see between both softphones is that Jitsi always
uses ulaw (because I provision the Jitsi client and enable just this
one codec since I've experienced trouble with gsm) and the other
softphone always uses gsm.
I really don't see why that should matter but maybe I'll try using gsm
with Jitsi again or alaw.

Tried using Jitsi with only gsm codec but I'm still getting the same
pt=101 issues.
So the choice of audio codec doesn't seem to matter.

I've been testing Jitsi with SIP INFO as DTMF instead of RFC2833. I've
never had any audio issues with it (as described in my previous posts)
for almost 48 hours.
I might be mistaken but it seems that Jitsi is having trouble when
used with an Asterisk 1.4 SIP account with dtmfmode=rfc2833 whereas no
issues are reported with dtmfmode=info.