[jitsi-dev] Jitsi freezes on Windows 7 when incoming call ringing + call pickup


#1

Hi,

I found that Jitsi froze today in the following scenario:

Windows 7 Jitsi client receives a call (popup notification) but Jitsi user simultaneously dials *8 which in my case executes "call pickup" via Asterisk. So the user answers a call which is "probably" not the one that's notified on screen but was another one ringing within the same Asterisk callgroup/pickupgroup. The Jitsi user and the caller can talk just fine but the Jitsi app is frozen (see attached screenshot of a custom, near-native Jitsi application). I can't easily reproduce this app freeze (I tried to make 2 simultaneous calls, etc. but the app didn't freeze anymore). Still, I'm posting it just for the record.

I had to kill the app and restart it (when the call ended Jitsi GUI did not resume).

The only thing I saw in the log (and it was active because it kept growing during the GUI freeze):

11:07:47.525 INFO: [173] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
11:07:47.631 INFO: [135] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio codec/freq: GSM/8000 Hz
11:07:47.632 INFO: [135] org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote IP/port: 10.215.147.112/10268
11:07:47.632 INFO: [135] net.sf.fmj.media.Log.info() Starting RTPSourceStream.
11:07:49.310 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:82, bytes:2739, interarrival jitter:2, lost packets:0, time since previous report:32767999ms ]
11:08:11.293 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:1182, bytes:39039, interarrival jitter:1, lost packets:0, time since previous report:4213ms ]
11:08:32.763 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:2255, bytes:74448, interarrival jitter:4, lost packets:0, time since previous report:621ms ]
11:08:53.727 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:3304, bytes:109065, interarrival jitter:3, lost packets:0, time since previous report:1535ms ]
11:09:14.138 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:4324, bytes:142725, interarrival jitter:3, lost packets:0, time since previous report:1805ms ]
11:09:39.269 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:5581, bytes:184206, interarrival jitter:0, lost packets:0, time since previous report:1963ms ]
11:10:00.553 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:6645, bytes:219318, interarrival jitter:0, lost packets:0, time since previous report:3196ms ]
11:10:20.591 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:7647, bytes:252384, interarrival jitter:0, lost packets:0, time since previous report:3184ms ]
11:10:40.894 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:8662, bytes:285879, interarrival jitter:2, lost packets:0, time since previous report:3437ms ]
11:10:59.363 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:9585, bytes:316338, interarrival jitter:3, lost packets:0, time since previous report:1855ms ]
11:11:24.456 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:10839, bytes:357720, interarrival jitter:2, lost packets:0, time since previous report:21936ms ]
11:11:42.530 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:11744, bytes:387585, interarrival jitter:2, lost packets:0, time since previous report:40010ms ]
11:12:07.193 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:12976, bytes:428241, interarrival jitter:2, lost packets:0, time since previous report:64673ms ]
11:12:27.666 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:14000, bytes:462033, interarrival jitter:2, lost packets:0, time since previous report:85146ms ]
11:12:45.395 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:14887, bytes:491304, interarrival jitter:2, lost packets:0, time since previous report:102875ms ]
11:13:07.429 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:15988, bytes:527637, interarrival jitter:2, lost packets:0, time since previous report:124909ms ]
11:13:29.721 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:17103, bytes:564432, interarrival jitter:2, lost packets:0, time since previous report:147201ms ]
11:13:51.428 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:18188, bytes:600237, interarrival jitter:2, lost packets:0, time since previous report:168908ms ]
11:14:15.774 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:19405, bytes:640398, interarrival jitter:2, lost packets:0, time since previous report:193254ms ]
11:14:32.112 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:20222, bytes:667359, interarrival jitter:2, lost packets:0, time since previous report:209592ms ]
11:14:50.722 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:21153, bytes:698082, interarrival jitter:2, lost packets:0, time since previous report:228202ms ]
11:15:14.526 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:22343, bytes:737352, interarrival jitter:2, lost packets:0, time since previous report:252006ms ]
11:15:38.723 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:23553, bytes:777282, interarrival jitter:2, lost packets:0, time since previous report:276203ms ]
11:16:03.131 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:24773, bytes:817542, interarrival jitter:2, lost packets:0, time since previous report:300611ms ]
11:16:26.196 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:25926, bytes:855591, interarrival jitter:2, lost packets:0, time since previous report:323676ms ]
11:16:42.082 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:26720, bytes:881793, interarrival jitter:2, lost packets:0, time since previous report:339562ms ]
11:17:06.274 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:27928, bytes:921657, interarrival jitter:2, lost packets:0, time since previous report:363754ms ]
11:17:28.732 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:29051, bytes:958716, interarrival jitter:2, lost packets:0, time since previous report:386212ms ]
11:17:50.053 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:30117, bytes:993894, interarrival jitter:2, lost packets:0, time since previous report:407533ms ]
11:18:08.306 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:31029, bytes:1023990, interarrival jitter:2, lost packets:0, time since previous report:425786ms ]
11:18:30.510 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:32140, bytes:1060653, interarrival jitter:2, lost packets:0, time since previous report:447990ms ]
11:18:56.086 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:33418, bytes:1102827, interarrival jitter:2, lost packets:0, time since previous report:473566ms ]
11:19:13.284 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:34278, bytes:1131207, interarrival jitter:2, lost packets:0, time since previous report:490764ms ]
11:19:36.612 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:35413, bytes:1168662, interarrival jitter:2, lost packets:0, time since previous report:514092ms ]
11:19:51.762 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:36171, bytes:1193676, interarrival jitter:2, lost packets:0, time since previous report:529242ms ]
11:20:07.804 INFO: [157] org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info() rtpstat:Sending a report for audio stream SSRC:2000728625 [packet count:36973, bytes:1220142, interarrival jitter:2, lost packets:0, time since previous report:545284ms ]

I also did a heap dump while the app was still running.
Would it be useful if I sent it?
It's quite big so I may need to send it elsewhere and not to the mailing list.

Note: this issue seldom occurs (actually first time I see it in Jitsi) so it's not a top priority.

Version: 2.1.4521.10591 x86 Win7

Thanks,

Vieri


#2

Just FYI regarding this issue I said earlier that:
'So the user answers a call which is "probably" not the one that's notified on screen'
Actually it IS the same caller.

ยทยทยท

--- On Wed, 3/20/13, Vieri <rentorbuy@yahoo.com> wrote:

Hi,

I found that Jitsi froze today in the following scenario:

Windows 7 Jitsi client receives a call (popup notification)
but Jitsi user simultaneously dials *8 which in my case
executes "call pickup" via Asterisk. So the user answers a
call which is "probably" not the one that's notified on
screen but was another one ringing within the same Asterisk
callgroup/pickupgroup. The Jitsi user and the caller can
talk just fine but the Jitsi app is frozen (see attached
screenshot of a custom, near-native Jitsi application). I
can't easily reproduce this app freeze (I tried to make 2
simultaneous calls, etc. but the app didn't freeze anymore).
Still, I'm posting it just for the record.

I had to kill the app and restart it (when the call ended
Jitsi GUI did not resume).

The only thing I saw in the log (and it was active because
it kept growing during the GUI freeze):

11:07:47.525 INFO: [173] net.sf.fmj.media.Log.info()
Starting RTPSourceStream.
11:07:47.631 INFO: [135]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio
codec/freq: GSM/8000 Hz
11:07:47.632 INFO: [135]
org.jitsi.impl.neomedia.MediaStreamImpl.info() audio remote
IP/port: 10.215.147.112/10268
11:07:47.632 INFO: [135] net.sf.fmj.media.Log.info()
Starting RTPSourceStream.
11:07:49.310 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:82, bytes:2739, interarrival jitter:2, lost
packets:0, time since previous report:32767999ms ]
11:08:11.293 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:1182, bytes:39039, interarrival jitter:1, lost
packets:0, time since previous report:4213ms ]
11:08:32.763 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:2255, bytes:74448, interarrival jitter:4, lost
packets:0, time since previous report:621ms ]
11:08:53.727 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:3304, bytes:109065, interarrival jitter:3,
lost packets:0, time since previous report:1535ms ]
11:09:14.138 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:4324, bytes:142725, interarrival jitter:3,
lost packets:0, time since previous report:1805ms ]
11:09:39.269 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:5581, bytes:184206, interarrival jitter:0,
lost packets:0, time since previous report:1963ms ]
11:10:00.553 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:6645, bytes:219318, interarrival jitter:0,
lost packets:0, time since previous report:3196ms ]
11:10:20.591 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:7647, bytes:252384, interarrival jitter:0,
lost packets:0, time since previous report:3184ms ]
11:10:40.894 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:8662, bytes:285879, interarrival jitter:2,
lost packets:0, time since previous report:3437ms ]
11:10:59.363 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:9585, bytes:316338, interarrival jitter:3,
lost packets:0, time since previous report:1855ms ]
11:11:24.456 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:10839, bytes:357720, interarrival jitter:2,
lost packets:0, time since previous report:21936ms ]
11:11:42.530 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:11744, bytes:387585, interarrival jitter:2,
lost packets:0, time since previous report:40010ms ]
11:12:07.193 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:12976, bytes:428241, interarrival jitter:2,
lost packets:0, time since previous report:64673ms ]
11:12:27.666 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:14000, bytes:462033, interarrival jitter:2,
lost packets:0, time since previous report:85146ms ]
11:12:45.395 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:14887, bytes:491304, interarrival jitter:2,
lost packets:0, time since previous report:102875ms ]
11:13:07.429 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:15988, bytes:527637, interarrival jitter:2,
lost packets:0, time since previous report:124909ms ]
11:13:29.721 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:17103, bytes:564432, interarrival jitter:2,
lost packets:0, time since previous report:147201ms ]
11:13:51.428 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:18188, bytes:600237, interarrival jitter:2,
lost packets:0, time since previous report:168908ms ]
11:14:15.774 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:19405, bytes:640398, interarrival jitter:2,
lost packets:0, time since previous report:193254ms ]
11:14:32.112 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:20222, bytes:667359, interarrival jitter:2,
lost packets:0, time since previous report:209592ms ]
11:14:50.722 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:21153, bytes:698082, interarrival jitter:2,
lost packets:0, time since previous report:228202ms ]
11:15:14.526 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:22343, bytes:737352, interarrival jitter:2,
lost packets:0, time since previous report:252006ms ]
11:15:38.723 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:23553, bytes:777282, interarrival jitter:2,
lost packets:0, time since previous report:276203ms ]
11:16:03.131 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:24773, bytes:817542, interarrival jitter:2,
lost packets:0, time since previous report:300611ms ]
11:16:26.196 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:25926, bytes:855591, interarrival jitter:2,
lost packets:0, time since previous report:323676ms ]
11:16:42.082 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:26720, bytes:881793, interarrival jitter:2,
lost packets:0, time since previous report:339562ms ]
11:17:06.274 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:27928, bytes:921657, interarrival jitter:2,
lost packets:0, time since previous report:363754ms ]
11:17:28.732 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:29051, bytes:958716, interarrival jitter:2,
lost packets:0, time since previous report:386212ms ]
11:17:50.053 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:30117, bytes:993894, interarrival jitter:2,
lost packets:0, time since previous report:407533ms ]
11:18:08.306 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:31029, bytes:1023990, interarrival jitter:2,
lost packets:0, time since previous report:425786ms ]
11:18:30.510 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:32140, bytes:1060653, interarrival jitter:2,
lost packets:0, time since previous report:447990ms ]
11:18:56.086 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:33418, bytes:1102827, interarrival jitter:2,
lost packets:0, time since previous report:473566ms ]
11:19:13.284 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:34278, bytes:1131207, interarrival jitter:2,
lost packets:0, time since previous report:490764ms ]
11:19:36.612 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:35413, bytes:1168662, interarrival jitter:2,
lost packets:0, time since previous report:514092ms ]
11:19:51.762 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:36171, bytes:1193676, interarrival jitter:2,
lost packets:0, time since previous report:529242ms ]
11:20:07.804 INFO: [157]
org.jitsi.impl.neomedia.transform.rtcp.StatisticsEngine.info()
rtpstat:Sending a report for audio stream SSRC:2000728625
[packet count:36973, bytes:1220142, interarrival jitter:2,
lost packets:0, time since previous report:545284ms ]

I also did a heap dump while the app was still running.
Would it be useful if I sent it?
It's quite big so I may need to send it elsewhere and not to
the mailing list.

Note: this issue seldom occurs (actually first time I see it
in Jitsi) so it's not a top priority.

Version: 2.1.4521.10591 x86 Win7

Thanks,

Vieri