Inaudible speech during first minutes of Pidgin calls #107

xnandersson · 2016-06-22T08:48:37Z

Still an issue. Several reports. Can it be something else but the codec?

"Audio (both sent and received) is distorted and full of static -- basically unusable -- at the beginning of a call or meeting, but after anywhere between 1 and 10 minutes, it suddenly clears up. This happens regardless of whether I'm using the office Ethernet, the office WiFi, or connected via the VPN."

tmuehlhoff · 2016-06-22T09:03:17Z

I am affected still as well (peers are keep on telling me that my voice is distorted), though I haven't yet had taken any measures. Compared to before it doesn't seem to bother my peers as much as before, so it has definitely improved.
Let me know if I can assist. /To

xhaakon · 2016-06-22T12:41:51Z

Please make some logs with GST_DEBUG=4 and post your dpkg --list. What's your settings in Pidgin's Voice/Video preferences?

rbordelo · 2016-06-22T17:58:14Z

Attached are the requested logs and dpkg --list. The logs was taken during calls to both the test call service and to a cell phone.

dpkg_list.txt
pidgin_gst_debug.log.gz
pidgin_gst_debug2.log.gz
pidgin_gst_debug3.log.gz
pidgin_gst_debug4.log.gz

xnandersson · 2016-06-28T05:27:10Z

Perhaps there are some pointers in the packets. RTCP-packets might carry useful information https://en.wikipedia.org/wiki/RTP_Control_Protocol

Either it is the packets, or it is an issue with the codec.

xhaakon · 2016-06-28T11:49:04Z

Is here anyone who has these audio issues and uses something else than Ubuntu 14.04?

@rbordelo is on 14.04 according to his logs, and if I remember correctly the same is true for @tmuehlhoff. Might be an issue with old GStreamer...

xnandersson · 2016-06-28T11:49:35Z

I'm on 16.04 and have issues.

rbeldin · 2016-06-29T13:02:29Z

I am on 16.04 and have experienced complete silence for 1-2 minutes during the beginning of a call that usually ends up with the other party hanging up. Once this happens, I can't connect back to them and they just hear a couple of fast beeps before it hangs up. Most of the people I engage with are running 'real' Skype for Business on Windows PCs.

xnandersson · 2016-07-05T10:04:55Z

@rbeldin Sounds like a different issue to me. I also wouldn't claim that this issue is "inaudible" as the headline suggest, but definitely a "cracking" noise whenever your counterpart speaks. During moments of silence there is no background noise. It seems like a decoder issue, because the other party (who is on MS Lync) can hear everything just perfectly. The cracking noise is only on the Pidgin client. Also if both TX and RX uses similar routes, that perhaps also cancel out the possibility of a bandwidth issue (latency) or packet loss.

xnandersson · 2016-07-14T19:41:04Z

Finding from one of our users:

"If it helps, see below something experienced in last few days:

I joined calls on Lync (Conf calls), sound was bad as usual and as described in this email trail.
Evolution was started also
As soon as I quit Evolution, sound got directly better

The above happened on 2 occasions already, coincidence?"

xhaakon · 2016-07-15T10:08:47Z

@xnandersson That doesn't have to be so far-fetched a coincidence as it may look since Evolution might connect to pulseaudio server in order to e.g. play notification sounds.

I've seen something similar under unrelated circumstances - if I recall correctly, when I would launch a QEMU virtual machine (with a configured sound card) using libvirt, the volume of my media player would suddenly decrease, and after turning the VM off, it would return to the original level. Sound quality wasn't affected though, just the volume.

The user could try to collect some potentially useful piece of data should the situation you described happen again:

after joining the conference if the sound is bad and Evolution running, run pactl list (from pulseaudio-utils package) and save the output
close Evolution, hear if the sound gets better
save the output from pactl list again

xnandersson · 2016-09-13T10:30:25Z

Looks like one can "fix" the problem by opening some other applications. If I start and close Thunderbird for example a few times it seems like it can fix the sound. No idea how this correlates though.... So perhaps it is just a matter of kicking pulse-audio a few times?

joakim-tjernlund · 2016-09-16T14:27:51Z

I got bad received Audio, either I got no audio at all or there is audio with static noise in it.
Using Gentoo with gst 1.8.2 and lastest sipe, libnice and farstream from
https://github.com/tieto/

xhaakon · 2016-09-16T15:26:02Z

@joakim-tjernlund Does the noise go away after a while or is it persistent? The former would be consistent with this bug report.

joakim-tjernlund · 2016-09-16T15:30:06Z

@xhaakon In this one off test I had noisy received audio to begin with and after a minute or two received audio died and we ended the test shortly after that.
He could hear me all the time though.

xnandersson · 2016-09-16T15:32:19Z

@joakim-tjernlund Try next time to let the call go on for longer. Preferably 10-20 minutes. Also try and open/close some other programs at the same time.

joakim-tjernlund · 2016-09-23T12:18:35Z

I just hit another odd thing, I tested an Audio call with a coworker and while he could hear me fine, I just
heard myself!
BTW, it would be great if one could call oneself for testing purposes.

xhaakon · 2016-09-23T13:00:57Z

BTW, it would be great if one could call oneself for testing purposes.

You can use Lync's integrated test call bot for checking your audio configuration. In Pidgin, go to Accounts -> [your sipe account] -> Test call.

joakim-tjernlund · 2016-09-23T13:28:24Z

Ahh, news to me. Test Call works fine for me.

joakim-tjernlund · 2016-10-03T17:20:13Z

Anyone compared ALSA vs. Pulseaudio?

xnandersson · 2016-10-03T17:22:16Z

No. But reportedly Debian is not tainted with this problem...

joakim-tjernlund · 2016-10-03T17:26:36Z

And debian uses ALSA?
I just tried to use ALSA instead and did a Test Call but heard no sound at all :(

joakim-tjernlund · 2016-10-03T17:39:44Z

Tried again a few times and now I got choppy sound using ALSA.
Wonder if this can anything to do with kernel conf CONFIG_SND_HDA_PREALLOC_SIZE=64 ?

joakim-tjernlund · 2016-10-05T23:25:13Z

On another machine I get choppy audio and GST_DEBUG=4 pidgin gives me

alsa conf.c:4817:snd_config_expand: alsalib error: Unknown parameters {AES0 0x02 AES1 0x82 AES2 0x00 AES3 0x02}
alsa pcm.c:2450:snd_pcm_open_noupdate: alsalib error: Unknown PCM default:{AES0 0x02 AES1 0x82 AES2 0x00 AES3 0x02}
alsa gstalsasink.c:330:gst_alsasink_getcaps:<autoaudiosink0-actual-sink-alsa> returning caps audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)2, channel-mask=(bitmask)0x0000000000000003; audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)1; audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)3, channel-mask=(bitmask)0x000000000000000b; audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)4, channel-mask=(bitmask)0x0000000000000033; audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)6, channel-mask=(bitmask)0x000000000000003f; audio/x-raw, format=(string){ U8, S16LE, S24_32LE, S32LE, S24LE }, layout=(string)interleaved, rate=(int)[ 4000, 384000 ], channels=(int)8, channel-mask=(bitmask)0x0000000000000c3f

Any chance this is related?

joakim-tjernlund · 2016-10-07T13:30:52Z

Which H264 impl. fits SIPE best, openh264 or x264 ? Minimum version of there?

joakim-tjernlund · 2016-10-07T15:39:03Z

Are people using srtp 1.5.4/2.0.0 yet?

xhaakon · 2016-10-07T19:40:11Z

Which H264 impl. fits SIPE best, openh264 or x264 ? Minimum version of there?

Sipe uses x264 through GStreamer encoder and decoder plugins from the "ugly" set. We don't prescribe any minimal required version, but best choose something less ancient than what Ubuntu 14.04 has (our oldest supported system). The exact version number is a bit complex 2:0.142.2389+git956c8d8-2 - that upstream commit ID it includes is probably your best guide.

We'd also like to take advantage of hardware accelerated H264 encoding & decoding through VAAPI, but its support in Farstream isn't quite there yet and causes crashes.

Are people using srtp 1.5.4/2.0.0 yet?

They use libsrtp that ships with their distro. I see Ubuntu 16.04 still has 1.4.5, so the versions you mentioned aren't in widespread use yet.

joakim-tjernlund · 2016-10-08T15:28:59Z

On another machine I get choppy audio when doing a test call and GST_DEBUG=3 pidgin gives me

0:00:25.990256495   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio OPUS clock:48000 channels:2 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.993439095   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio SPEEX clock:0 channels:1 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.995910786   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 14: audio MPA-ROBUST clock:90000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 14
0:00:25.996000636   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 14: audio X-MP3-DRAFT-00 clock:90000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 14
0:00:25.996087353   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 14: audio MPA clock:90000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 14
0:00:25.996198072   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio MPEG4-GENERIC clock:0 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.996304298   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio MP4A-LATM clock:0 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.996410063   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio ILBC clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.996511580   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 3: audio GSM clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 3
0:00:25.996614194   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 18: audio G729 clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 18
0:00:25.996724167   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio G726-16 clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.996824658   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 4: audio G723 clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 4
0:00:25.996929156   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for 9: audio G722 clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 9
0:00:25.997034073   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio DV clock:90000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.997137798   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio CELT clock:0 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.997247018   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio BV16 clock:8000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.997335582   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio BV32 clock:16000 channels:0 params:(nil): Could not link element inside the send codec bin for pt 96
0:00:25.997447482   541       0xb4de70 WARN    fsrtpconference_disco fs-rtp-discover-codecs.c:1847:codec_blueprints_add_caps: Could not create send codec bin from blueprint for -1: audio AMR clock:8000 channels:1 params:0xd91000: Could not link element inside the send codec bin for pt 96
0:00:26.011592389   541       0xd81e80 FIXME                default gstutils.c:3766:gst_pad_create_stream_id_internal:<pidgindefaultaudiosrc-actual-src-als:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:26.014365086   541       0xd81800 FIXME                default gstutils.c:3766:gst_pad_create_stream_id_internal:<nicesrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:26.014538466   541       0xd60190 FIXME                default gstutils.c:3766:gst_pad_create_stream_id_internal:<nicesrc1:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:26.845820302   541       0xdf3000 FIXME                default gstutils.c:3766:gst_pad_create_stream_id_internal:<dtmfsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:26.885192426   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:26.885203711   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.035488878   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.035501904   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.042801082   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.042809590   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.140500743   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.140511739   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.140523866   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.140528500   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.140732835   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.140741396   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.246121626   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.246133472   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.246144716   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.246150185   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.252821379   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.252830789   541       0xd81800 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.349692428   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.349704217   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.450357693   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.450370150   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:27.450386644   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:00:27.450392225   541       0xd60190 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:00:28.668527950   541       0xd6bd90 WARN                    alsa conf.c:4674:parse_args: alsalib error: Unknown parameter AES0
0:00:28.668549478   541       0xd6bd90 WARN                    alsa conf.c:4834:snd_config_expand: alsalib error: Parse arguments error: No such file or directory
0:00:28.668556339   541       0xd6bd90 WARN                    alsa pcm.c:2450:snd_pcm_open_noupdate: alsalib error: Unknown PCM default:{AES0 0x02 AES1 0x82 AES2 0x00 AES3 0x02}
0:00:28.670857076   541 0x7f19fc001d90 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<autoaudiosink0-actual-sink-alsa> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:00:29.105186044   541       0xd81e80 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<fakesink1> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:00:29.105206767   541       0xd81e80 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<nicesink0> stream-start event without group-id. Consider implementing group-id handling in the upstream elements

Is this normal?

joakim-tjernlund · 2016-10-09T19:08:35Z

Using Pulseaudio I get lots of distortions and this is logged:

0:01:29.844006215  6545       0xec7000 FIXME                default gstutils.c:3766:gst_pad_create_stream_id_internal:<dtmfsrc1:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:01:29.880480370  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:29.880495216  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.031578036  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.031590115  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.136099400  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.136110203  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.240363985  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.240380940  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.445889525  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.445901340  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.445914226  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.445919778  6545       0xcfeca0 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:30.451417850  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:644:validate_buffer:<srtpdec_1> No SSRC found in buffer
0:01:30.451427231  6545       0xa76d40 WARN                 srtpdec gstsrtpdec.c:1212:gst_srtp_dec_chain:<srtpdec_1> Invalid buffer, dropping
0:01:31.925619276  6545 0x7f2f38000de0 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<pulsesink0> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:01:32.544682365  6545 0x7f2f40004940 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<fakesink4> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:01:32.544705968  6545 0x7f2f40004940 FIXME               basesink gstbasesink.c:3126:gst_base_sink_default_event:<nicesink2> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:01:33.562772804  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:34.701854643  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:35.222741723  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:36.602065978  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:37.422366630  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:37.661758349  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:38.122282867  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:38.761967358  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:38.882477889  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:39.042694845  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:39.201751559  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:39.942103724  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow
0:01:40.262564357  6545 0x7f2f00007120 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<pulsesink0> Got underflow

I have the feeling that these audio issues are latency based. This test machine has
175 ms ping time to the Lync server.
Could it be that GST or SIPE fails to compensate for latency?

joakim-tjernlund · 2016-10-10T13:44:00Z

Here is a somewhat better data point, using http://repo.or.cz/siplcs.git/shortlog/refs/heads/mob I
get lots of distortion on first Test call and lots of this(GST_DEBUG=3)

0:00:44.420026545  8681 0x7f36cc002cf0 WARN           audiobasesink gstaudiobasesink.c:1807:gst_audio_base_sink_get_alignment:<pulsesink0> Unexpected discontinuity in audio timestamps of +0:00:00.030000000, resyncing

while using pidgin-sipe 1.21.1 I get almost no distortion(if any)
Tested several times

joakim-tjernlund · 2016-10-11T18:24:30Z

I there a way to play the Test Call with gst-play(or similar)? That would present a great way to
narrow down the problem.

tmuehlhoff · 2016-11-18T14:22:19Z

Hi,
I'm still suffering from bad outgoing voice. But only in conferences, not in direct calls. I'm attaching a sample file recorded by my colleagues Lync client (female voice, not distorted).
?Tomas

TMCM-ThursdayNovember17201632642PM.mp4.zip

xhaakon · 2016-11-20T17:18:19Z

@tmuehlhoff The sample sounds to me as if some very low-quality encoding was used. Could you please provide a Pidgin log from a conference call? I'd be interested in the codec being selected.

Does your sound improve after a while as @xnandersson describes in the original post, or keeps being distorted for the whole duration of the call?

Also what's the Ubuntu version you're currently using?

But only in conferences, not in direct calls.

Lync conference servers usually support somewhat limited range of codecs compared to the desktop clients themselves, so this observation would support the theory that Sipe selects some low-bandwidth encoder although better options should be available on your system. There still remains the question why only some users experience this sound quality problem...

tmuehlhoff · 2016-11-21T08:32:08Z

Hi, thanks for answering. What kind of logs are you referring to ? the Pidgin "System log" remains empty even though I checked all 3 log boxes in preferences/logging.
I captured some seconds in Wireshark, but it's all TLS encrypted, so that won't help I assume.
Ubuntu Version is 14.04.05, Kernel 3.13.0-100-generic, Pidgin 1:3.0.0 collab-1+201611050947 ubuntu14.04.1, sipe 1.21.1+sipe-0+201611140632 ubuntu14.04.1, remmina 1.2.0 rcgit+sipe-0+201608170747~ubuntu14.04.1
/Tomas

xhaakon · 2016-11-21T09:21:01Z

What kind of logs are you referring to ?

@tmuehlhoff I mean the terminal output when running Pidgin from shell with debug parameter:

pidgin --debug

tmuehlhoff · 2016-11-21T12:52:58Z

I did a capture, I'm a bit hesitating to attach the whole log here since it contains company data. I'll snip out what I think is relevant. I can send you the full file via E-Mail.
PCMU seems to me not the most efficient codec.
/Tomas

grep -i codec pidgin-debug.txt -A 10 -B 10
(13:39:55) sipe: process_input_message: msg->response(200),msg->method(INVITE)
(13:39:55) sipe: process_input_message: we have a transaction callback
(13:39:55) sipe: sipe_dialog_parse_routes: route sip:SESSFEPOOL202.ericsson.com:5061;transport=tls;ms-fe=sessmwfe2204.ericsson.se;opaque=state:T:Tc.JNSu814HJlq-CXalIJ_2FccTAAAAAAAA:F:Fc.JNSu814HJlq-CXvlIJ_2FccTAAAAAAAA:Eu:Ci.R5a038200;lr;ms-route-sig=fl0dytzDOYoa44E4w6YJFUQ8OUNplheX7GgWBTbJRWbotAF5ziVFo5xwAA
(13:39:55) sipe: NTLM MAC(): Extented Session Security
(13:39:55) sipe: NTLM MAC(): Key Exchange
(13:39:55) sipe: NTLM calculated MAC: 01000000452B9B7858EC494E64000000
(13:39:55) sipe: process_input_message: removing CSeq 3
(13:39:55) sipe: SIP transactions count:0 after removal
(13:39:55) backend-fs2: farstream-component-state-changed: component: 1 state: CONNECTING
(13:39:55) backend-fs2: farstream-component-state-changed: component: 2 state: CONNECTING
(13:39:55) backend-fs2: farstream-send-codec-changed: codec: 0: audio PCMU clock:8000 channels:1
(13:39:55) sipe: sip_sec_verify_signature: message is:<3F4EEEE5><57><sessmwfe2204.ericsson.se><9D93gCEC6a94BCi7447mD0AAtF1E6bBB0FxECCAx><4>sip:tomas.muehlhoff@ericsson.com;gruu;opaque=app:conf:focus:id:2FKR6YGW<6A250080>sip:tomas.muehlhoff@ericsson.com<6173451478><><><> signature to verify is:01000000232d0aabd67d1d6a64000000
(13:39:55) sipe: NTLM MAC(): Extented Session Security
(13:39:55) sipe: NTLM MAC(): Key Exchange
(13:39:55) sipe: NTLM calculated MAC: 01000000232D0AABD67D1D6A64000000
(13:39:55) sipe: sip_transport_input: signature of incoming message validated
(13:39:55) sipe: process_input_message: msg->response(0),msg->method(BENOTIFY)
(13:39:55) sipe: send->process_incoming_benotify
(13:39:55) sipe: process_incoming_notify: subscription_state: active;expires=3600
(13:39:55) sipe: sipe_dialog_find who='sip:tomas.muehlhoff@ericsson.com;gruu;opaque=app:conf:chat:id:2FKR6YGW'
(13:39:55) media: candidate pair established
(13:39:55) sipe: sipe_status_and_note: switch to 'in-a-conference' for the account
(13:39:55) g_log: purple_xmlnode_insert_data: assertion 'data != NULL' failed
(13:39:55) util: Writing file blist.xml to directory /home/eddtomu/.purple
(13:39:55) util: Writing file /home/eddtomu/.purple/blist.xml
(13:39:56) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:39:56) accels: saving accels to /home/eddtomu/.purple/accels
(13:39:56) util: Writing file prefs.xml to directory /home/eddtomu/.purple
(13:39:56) util: Writing file /home/eddtomu/.purple/prefs.xml
(13:39:57) gtkmedia: state: 1 sid: audio name: sip:tomas.muehlhoff@ericsson.com;gruu;opaque=app:conf:audio-video:id:2FKR6YGW
(13:39:57) sipe: sipe_media_state_changed_cb: 1 audio sip:tomas.muehlhoff@ericsson.com;gruu;opaque=app:conf:audio-video:id:2FKR6YGW
(13:39:57) backend-fs2: farstream-recv-codecs-changed: PCMU
(13:40:00) util: Writing file status.xml to directory /home/eddtomu/.purple
(13:40:00) util: Writing file /home/eddtomu/.purple/status.xml
(13:40:00) util: Writing file accounts.xml to directory /home/eddtomu/.purple
(13:40:00) util: Writing file /home/eddtomu/.purple/accounts.xml
(13:40:00) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:40:00) g_log: gst_rtcp_packet_add_rb: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:40:00) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:40:00) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:40:00) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed
(13:40:00) g_log: gst_rtcp_packet_get_rb_count: assertion 'packet->type == GST_RTCP_TYPE_RR || packet->type == GST_RTCP_TYPE_SR' failed

joakim-tjernlund · 2016-11-21T13:21:42Z

I would appreciate a list of codecs supported by SIPE, it is a jungle out there and for an amateur like me it is hard to keep up.
I just saw http://blog.schertz.name/2014/03/media-codecs-in-lync-2013/ where SILK is mentioned but
if I understand correctly it is now renamed to Opus, should I have Opus(via gstreamer) installed too?

tmuehlhoff · 2016-11-21T16:34:38Z

I would assume G.729 would do fine...

joakim-tjernlund · 2017-01-11T18:30:59Z

Just FYI, my audio became much better when I upgraded to ALSA 1.1.3

tmuehlhoff · 2017-01-12T13:58:59Z

seems the PPA doesn't support trusty anymore in which I am still...

tmuehlhoff · 2017-02-22T09:44:59Z

Is there anything I can do about my bad uplink audio in multiparty calls ? One2one is usually ok!

joakim-tjernlund · 2017-08-25T15:46:38Z

Got a similar issue now, doing a test call or one2one my microphon stops working for
10th's of seconds and then it start working again.
Usin GST_DEBUG=3 pidgin -d I can see when microphone stops:

(17:30:02) sipe: send->process_incoming_benotify
(17:30:02) sipe: process_incoming_notify: subscription_state: active;expires=24718
(17:30:02) sipe: sipe_process_presence: Content-Type: application/msrtc-event-categories+xml
(17:30:02) sipe: process_incoming_notify_rlmi: startTime=2017-08-24T00:00:00Z granularity=15 cal_free_busy_base64=
AAAAAAAAACqqAACqUAAAAAAAAAAAAAAAAAAAAAAAACqqAACqqqoAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
0:01:19.783409509  9590 0x7fadd4002e30 WARN           audiobasesink gstaudiobasesink.c:1512:gst_audio_base_sink_skew_slaving:<alsasink0> correct clock skew -0:00:00.020036104 < -+0:00:00.020000000
0:01:20.781816887  9590 0x7fadd4002e30 WARN           audiobasesink gstaudiobasesink.c:1807:gst_audio_base_sink_get_alignment:<alsasink0> Unexpected discontinuity in audio timestamps of -0:00:00.040000000, resyncing

0:01:21.976524414  9590 0x7fadd4002e30 WARN           audiobasesink gstaudiobasesink.c:1484:gst_audio_base_sink_skew_slaving:<alsasink0> correct clock skew +0:00:00.020017986 > +0:00:00.020000000
(17:30:06) util: Writing file status.xml to directory /home/jocke/.purple
(17:30:06) util: Writing file /home/jocke/.purple/status.xml
(17:30:06) util: Writing file prefs.xml to directory /home/jocke/.purple
(17:30:06) util: Writing file /home/jocke/.purple/prefs.xml
(17:30:06) util: Writing file accounts.xml to directory /home/jocke/.purple
(17:30:06) util: Writing file /home/jocke/.purple/accounts.xml
0:01:22.749810151  9590 0x7fadb00028f0 FIXME                default gstutils.c:3826:gst_pad_create_stream_id_internal:<dtmfsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
(17:30:06) backend-fs2: farstream-send-codec-changed: codec: 97: audio SIREN clock:16000 channels:1 bitrate=16000
0:01:22.750796555  9590      0x33dda80 FIXME                default gstutils.c:3826:gst_pad_create_stream_id_internal:<rtpdtmfsrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:01:22.751515608  9590      0x33dda80 FIXME               basesink gstbasesink.c:3077:gst_base_sink_default_event:<fakesink1> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:01:22.751549322  9590      0x33dda80 FIXME               basesink gstbasesink.c:3077:gst_base_sink_default_event:<nicesink0> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:01:22.752589680  9590      0x33cfe30 WARN         audio-resampler audio-resampler.c:273:convert_taps_gint16_c: can't find exact taps
0:01:22.752955241  9590      0x33cfe30 WARN         audio-resampler audio-resampler.c:273:convert_taps_gint16_c: can't find exact taps
0:01:22.753786892  9590 0x7fadb00028f0 WARN         audio-resampler audio-resampler.c:273:convert_taps_gint16_c: can't find exact taps
0:01:22.788078887  9590      0x33cfe30 WARN         audio-resampler audio-resampler.c:273:convert_taps_gint16_c: can't find exact taps
0:01:22.980198515  9590 0x7fadd4002e30 WARN           audiobasesink gstaudiobasesink.c:1807:gst_audio_base_sink_get_alignment:<alsasink0> Unexpected discontinuity in audio timestamps of +0:00:00.040000000, resyncing
(17:30:08) backend-fs2: farstream-component-state-changed: component: 1 state: READY

Then a lon PAUSE and when microphone returns again this:

(17:30:53) sipe: sipe_core_schedule_execute: executing <+http-timeout>
(17:30:53) sipe: sipe_core_schedule_execute timeouts count 9 after removal
(17:30:53) sipe: sipe_http_transport_drop: dropping connection 'autodiscover.infinera.com:443': timeout
(17:30:53) sipe: sipe_http_transport_free: destroying connection 'autodiscover.infinera.com:443'
(17:30:53) sipe: sipe_schedule_allocate timeouts count 10 after addition
(17:30:53) sipe: scheduling action <+http-timeout> timeout 2 seconds
(17:30:53) sipe: sipe_schedule_remove: action name=<+http-timeout>
(17:30:53) sipe: sipe_schedule_allocate timeouts count 10 after addition
(17:30:53) sipe: scheduling action <+http-timeout> timeout 2 seconds
(17:30:53) sipe: transport_deferred_destroy: 0x331a730
(17:30:55) sipe: sipe_core_schedule_execute: executing <+http-timeout>
(17:30:55) sipe: sipe_core_schedule_execute timeouts count 9 after removal
(17:30:55) sipe: sipe_http_transport_drop: dropping connection 'owa.infinera.com:443': timeout
(17:30:55) sipe: sipe_http_transport_free: destroying connection 'owa.infinera.com:443'
(17:30:55) sipe: transport_deferred_destroy: 0x33191c0
(17:31:07) sipe: sip_sec_verify_signature: message is:<TLS-DSK><65209277><44><SIP Communications Service><sv-sfbfe-prd1.infinera.com><8900g69B8a49A0i35F6mAF1Ft797Eb54FCx36F0x><14><BENOTIFY><sip:Joakim.Tjernlund@infinera.com><AA6C0080><sip:Joakim.Tjernlund@infinera.com><1922124904><><><> signature to verify is:0da17af99c71817fbe2744bedb42bdf330358536
(17:31:07) sipe: sip_transport_input: signature of incoming message validated
(17:31:07) sipe: process_input_message: msg->response(0),msg->method(BENOTIFY)
(17:31:07) sipe: send->process_incoming_benotify
(17:31:07) sipe: process_incoming_notify: subscription_state: active;expires=24653
(17:31:07) sipe: sipe_process_presence: Content-Type: application/msrtc-event-categories+xml
(17:31:07) sipe: process_incoming_notify_rlmi: busyidle
(17:31:07) blist: Updating buddy status for sip:martin.wahlsten@infinera.com (Office Communicator)

joakim-tjernlund · 2017-08-25T16:08:00Z

with GST_DEBUG=4 I see when microphone is silent lost of:

0:02:19.208063748 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 16
0:02:19.218124733 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 17
0:02:19.228361825 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 18
0:02:19.238568681 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 19
0:02:19.247724360 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 0
0:02:19.257898382 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 1
0:02:19.268007819 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 2
0:02:19.278210043 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 3
0:02:19.288457947 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 4
0:02:19.298537960 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.696551616 @ 5
0:02:19.308790236 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 6
0:02:19.319001174 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 7
0:02:19.329202550 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 8
0:02:19.339414289 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 9
0:02:19.349572822 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 10
0:02:19.358714833 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 11
0:02:19.368878436 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 12
0:02:19.378992202 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 13
0:02:19.389280092 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 14
0:02:19.399440791 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 15
0:02:19.408946623 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 16
0:02:19.419081363 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 17
0:02:19.429278141 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 18
0:02:19.439553692 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.695551616 @ 19
0:02:19.449730573 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.694551616 @ 0
0:02:19.459939642 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.694551616 @ 1
0:02:19.470124673 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.694551616 @ 2
0:02:19.480331012 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.694551616 @ 3
0:02:19.490581502 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.694551616 @ 4
0:02:19.500735300 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.693551616 @ 5
0:02:19.510946002 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.693551616 @ 6
0:02:19.521182920 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.693551616 @ 7
0:02:19.531254798 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.693551616 @ 8
0:02:19.541450605 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.693551616 @ 9
0:02:19.551663885 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.692551616 @ 10
0:02:19.561928239 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.692551616 @ 11
0:02:19.572086806 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.692551616 @ 12
0:02:19.582270092 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.692551616 @ 13
0:02:19.592483895 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.692551616 @ 14
0:02:19.602760433 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 15
0:02:19.612868173 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 16
0:02:19.622980890 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 17
0:02:19.633213451 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 18
0:02:19.643428776 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 19
0:02:19.653545829 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 0
0:02:19.662801377 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 1
0:02:19.672983981 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 2
0:02:19.683275950 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 3
0:02:19.693402658 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 4
0:02:19.703613134 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.691551616 @ 5
0:02:19.713846650 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.690551616 @ 6
0:02:19.724008708 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.690551616 @ 7
0:02:19.734208063 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.690551616 @ 8
0:02:19.744402690 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.690551616 @ 9

Then, when  microphone returns again I see:

0:02:19.744505336 10466      0x22fee80 INFO              ringbuffer gstaudioringbuffer.c:1793:gst_audio_ring_buffer_read:<audiosrcringbuffer1> Retrieved timestamp 5124095:34:33.690551616 @ 9
0:02:19.744720933 10466      0x1527b50 INFO               GST_EVENT gstevent.c:1511:gst_event_new_reconfigure: creating reconfigure event
0:02:19.754630157 10466 0x7fdadc002230 INFO              ringbuffer gstaudioringbuffer.c:2033:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer1> Storing timestamp 5124095:34:33.690551616 @ 10
0:02:19.754704748 10466      0x22fee80 INFO              ringbuffer gstaudioringbuffer.c:1793:gst_audio_ring_buffer_read:<audiosrcringbuffer1> Retrieved timestamp 5124095:34:33.690551616 @ 10
0:02:19.754825691 10466      0x22fee80 INFO           basetransform gstbasetransform.c:1370:gst_base_transform_setcaps:<volume_audio> reuse caps
0:02:19.754870821 10466      0x22fee80 INFO                GST_PADS gstpad.c:4112:gst_pad_peer_query:<valve_discovery_1:src> pad has no peer
0:02:19.754910228 10466      0x22fee80 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)16000, channels=(int)1;
0:02:19.754968060 10466      0x22fee80 INFO           basetransform gstbasetransform.c:1370:gst_base_transform_setcaps:<sendlevel_audio> reuse caps
0:02:19.755215701 10466      0x22fee80 INFO                GST_PADS gstpad.c:4112:gst_pad_peer_query:<valve_discovery_1:src> pad has no peer
0:02:19.755604870 10466      0x22fee80 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 2147483647 ];
0:02:19.755695199 10466      0x22fee80 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, rate=(int)16000, channels=(int)1, layout=(string)interleaved;
0:02:19.756814386 10466      0x22fee80 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, rate=(int)16000, channels=(int)1, layout=(string)interleaved;
0:02:19.756839433 10466      0x22fee80 INFO               structure gststructure.c:3051:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=

joakim-tjernlund · 2017-08-29T17:39:49Z

BTW, pidgin-sipe specificall disables SIREN during conference claiming it doesn't work:

/*
	 * Do not announce Theora. Its optional parameters are too long,
	 * Communicator rejects such SDP message and does not support the codec
	 * anyway.
	 *
	 * For some yet unknown reason, A/V conferencing server does not accept
	 * voice stream sent by SIPE when SIREN codec is in use. Nevertheless,
	 * we are able to decode incoming SIREN from server and with MSOC
	 * client, bidirectional call using the codec works. Until resolved,
	 * do not try to negotiate SIREN usage when conferencing. PCMA or PCMU
	 * seems to work properly in this scenario.
	 */
	while (i) {
		PurpleMediaCodec *codec = i->data;
		gchar *encoding_name = purple_media_codec_get_encoding_name(codec);

		if (sipe_strequal(encoding_name,"THEORA") ||
		    (is_conference && sipe_strequal(encoding_name,"SIREN"))) {
			GList *tmp;
			g_object_unref(codec);
			tmp = i->next;
			codecs = g_list_delete_link(codecs, i);
			i = tmp;
		} else if (sipe_strequal(encoding_name, "H264")) {

I took that out and tested conference and that worked fine(using SIREN codec)

jjohnson42 · 2018-06-21T13:53:57Z

I will confirm that removing the SIREN treatment helped, I also had to greatly reduce volume on the mic in my case.

joakim-tjernlund · 2018-06-26T10:41:25Z

@xnandersson, any comment on the exclusion of SIREN? Seems to work these days.

Also, this commit, https://bitbucket.org/pidgin/main/commits/08a29966cee99dedfc266e79e8fba31ecc08aa37 ,might help the original audio issue.

xnandersson · 2018-06-26T11:02:21Z

@joakim-tjernlund @xhaakon Thanks for the heads-up Joakim. Could be time to revisit this issue then.

joakim-tjernlund · 2018-06-26T12:10:29Z

Sorry for if offtopic but I got this audio prolem where the microphone stops working and the last thing I see using GST_DEBUG=3 is:

0:00:22.044095339  6747 0x562a224f5d60 WARN                   pulse pulsesink.c:702:gst_pulsering_stream_underflow_cb:<autoaudiosink0-actual-sink-pulse> Got underflow
0:00:25.886390874  6747 0x562a231858f0 WARN                audiosrc gstaudiosrc.c:221:audioringbuffer_thread_func:<autoaudiosrc0-actual-src-puls> error reading data -1 (reason: Resource temporarily unavailable), skipping segment

And that comes from:

do {
        read = readfunc (src, readptr, left, &timestamp);
        GST_LOG_OBJECT (src, "transfered %d bytes of %d to segment %d", read,
            left, readseg);
        if (read < 0 || read > left) {
          GST_WARNING_OBJECT (src,
              "error reading data %d (reason: %s), skipping segment", read,
              g_strerror (errno));
          break;
        }
        left -= read;
        readptr += read;
} while (left > 0);

      /* Update timestamp on buffer if required */
      gst_audio_ring_buffer_set_timestamp (buf, readseg, timestamp);

      /* we read one segment */
gst_audio_ring_buffer_advance (buf, 1);

Got no idea if this func should try handle EAGAIN or if readfunc should do that. I cannot even
tell where this readfunc is impl.(in pidgin, pidgin-sipe or somewhere else).
Any ideas?

The value of the optional "lastActive" attribute in a presence notification is now parsed and passed down as seconds since epoch timestamp to the backend. User visible changes in the Pidgin UI: * idle users are now "greyed out" like offline users * idle timers now work when "Show" -> "Idle Times" is enabled

xnandersson added the bug label Jun 22, 2016

xnandersson mentioned this issue Sep 16, 2016

Pidgin SEGV in gtk_style_context_get_valist() #117

Closed

joakim-tjernlund mentioned this issue Oct 6, 2016

rdpsnd/pulse: Fix crashes in pulseaudio FreeRDP/FreeRDP#2694

Merged

xnandersson closed this as completed Jun 26, 2018

xnandersson reopened this Jun 26, 2018

Inaudible speech during first minutes of Pidgin calls #107

Inaudible speech during first minutes of Pidgin calls #107

Comments

xnandersson commented Jun 22, 2016

tmuehlhoff commented Jun 22, 2016

xhaakon commented Jun 22, 2016

rbordelo commented Jun 22, 2016

xnandersson commented Jun 28, 2016

xhaakon commented Jun 28, 2016

xnandersson commented Jun 28, 2016

rbeldin commented Jun 29, 2016

xnandersson commented Jul 5, 2016

xnandersson commented Jul 14, 2016

xhaakon commented Jul 15, 2016

xnandersson commented Sep 13, 2016

joakim-tjernlund commented Sep 16, 2016

xhaakon commented Sep 16, 2016

joakim-tjernlund commented Sep 16, 2016

xnandersson commented Sep 16, 2016

joakim-tjernlund commented Sep 23, 2016

xhaakon commented Sep 23, 2016

joakim-tjernlund commented Sep 23, 2016

joakim-tjernlund commented Oct 3, 2016

xnandersson commented Oct 3, 2016

joakim-tjernlund commented Oct 3, 2016

joakim-tjernlund commented Oct 3, 2016

joakim-tjernlund commented Oct 5, 2016

joakim-tjernlund commented Oct 7, 2016

joakim-tjernlund commented Oct 7, 2016

xhaakon commented Oct 7, 2016 • edited Loading

joakim-tjernlund commented Oct 8, 2016

joakim-tjernlund commented Oct 9, 2016

joakim-tjernlund commented Oct 10, 2016

joakim-tjernlund commented Oct 11, 2016

tmuehlhoff commented Nov 18, 2016

xhaakon commented Nov 20, 2016

tmuehlhoff commented Nov 21, 2016 • edited Loading

xhaakon commented Nov 21, 2016

tmuehlhoff commented Nov 21, 2016 • edited Loading

joakim-tjernlund commented Nov 21, 2016

tmuehlhoff commented Nov 21, 2016

joakim-tjernlund commented Jan 11, 2017

tmuehlhoff commented Jan 12, 2017

tmuehlhoff commented Feb 22, 2017

joakim-tjernlund commented Aug 25, 2017

joakim-tjernlund commented Aug 25, 2017

joakim-tjernlund commented Aug 29, 2017

jjohnson42 commented Jun 21, 2018

joakim-tjernlund commented Jun 26, 2018

xnandersson commented Jun 26, 2018

joakim-tjernlund commented Jun 26, 2018

xhaakon commented Oct 7, 2016 •

edited

Loading

tmuehlhoff commented Nov 21, 2016 •

edited

Loading

tmuehlhoff commented Nov 21, 2016 •

edited

Loading