Skip to content

Instantly share code, notes, and snippets.

@alfredh

alfredh/baresip-ice.log

Created August 4, 2019 07:53
Show Gist options
  • Save alfredh/233baf182b0440ab2808c92d3b23453f to your computer and use it in GitHub Desktop.
Save alfredh/233baf182b0440ab2808c92d3b23453f to your computer and use it in GitHub Desktop.
Download ZIP
Raw
baresip-ice.log
./baresip -f /Users/alfredh/.baresip-gst -v
baresip v0.6.3 Copyright (C) 2010 - 2019 Alfred E. Heggestad et al.
Local network address: IPv4=en0|10.0.1.8
ui: stdio
opus: fmtp="stereo=0;sprop-stereo=0;maxaveragebitrate=64000;useinbandfec=1"
aucodec: opus/48000/1
aucodec: PCMU/8000/1
aucodec: PCMA/8000/1
auplay: coreaudio
ausrc: coreaudio
ausrc: aufile
vidsrc: avcapture
avcapture: found video device 'FaceTime HD Camera'
vidsrc: avformat
ausrc: rst
vidsrc: rst
medianat: stun
medianat: turn
medianat: ice
mediaenc: dtls_srtp
DTLS-SRTP ready with profiles SRTP_AES128_CM_SHA1_80:SRTP_AES128_CM_SHA1_32
uuid: loaded UUID bb2fe713-df57-403b-eec0-64c433aedd09 from file /Users/alfredh/.baresip-gst/uuid
alfredh2@sip.antisip.com: Using medianat 'ice'
Populated 1 account
module: loading app auloop.so
module: loading app contact.so
Populated 3 contacts
module: loading app debug_cmd.so
module: loading app menu.so
module: loading app vidloop.so
Populated 3 audio codecs
Populated 0 audio filters
Populated 0 video codecs
Populated 0 video filters
baresip is ready.
alfredh2@sip.antisip.com: {0/TCP/v4} 200 OK (kamailio (5.2.2 (x86_64/linux))) [1 binding]
All 1 useragent registered successfully! (143 ms)
ua: sipsess connect via TCP 91.121.30.149:5060 --> 10.0.1.8:59103
call: alloc with params laddr=10.0.1.8, af=AF_INET, use_rtp=1
ice: new session with STUN-server at sip.antisip.com (username=alfredh2)
call: use_video=0
call: no common audio codecs - rejected
audio: destroyed (started=0)
ua: sipsess connect via TCP 91.121.30.149:5060 --> 10.0.1.8:59103
call: alloc with params laddr=10.0.1.8, af=AF_INET, use_rtp=1
ice: new session with STUN-server at sip.antisip.com (username=alfredh2)
call: use_video=0
ice: resolved STUN-server to address 91.121.30.149:3478
audio: added interface: en0:10.0.1.8 (local prio 10)
ice: gathering srflx for comp 1 ..
ice: gathering srflx for comp 2 ..
ice: srflx gathering for comp 2 complete.
ice: srflx gathering for comp 1 complete.
ice: all components gathered.
audio: comp1 setting local: 84.208.62.181:44541
audio: comp2 setting local: 84.208.62.181:39972
ice: audio: Default local candidates: 84.208.62.181:44541 / 84.208.62.181:39972
call: media-nat 'ice' established/gathered
answering call from sip:alfredh@sip.antisip.com with 200
call: update media
stream: update 'audio'
{ audio.1} Set default remote candidate: relay:91.121.30.149:46920
{ audio.2} Set default remote candidate: relay:91.121.30.149:46921
chklist: audio: pruned candidate pairs: 4
{ audio. } starting connectivity checks with 4 candidate pairs
{ audio.1} host <---> host FSM: Frozen ===> Waiting
{ audio.1} host <---> relay FSM: Frozen ===> Waiting
{ audio.1} host <---> host FSM: Waiting ===> InProgress
{ audio.1} Tx en0:host:10.0.1.8:31748 ---> host:100.103.159.22:7298 (InProgress)
call: stream start (active=1)
alfredh2@sip.antisip.com: Call established: sip:alfredh@sip.antisip.com
stream: incoming rtp for 'audio' established, receiving from 91.121.30.149:46920
{ audio.1} added PeerReflexive remote candidate with priority 1862270847 (176.11.159.23:7298)
stunsrv: {audio.1} candidate pair not found: source=176.11.159.23:7298
audio: Set audio decoder: opus 48000Hz 1ch
audio: start
audio: player started with sample format S16LE
main: long async blocking: 150>100 ms (h=0x10217b3c0 arg=0x7ffc8b0213b0)
{ audio.2} added PeerReflexive remote candidate with priority 1862270846 (176.11.159.23:7299)
stunsrv: {audio.2} candidate pair not found: source=176.11.159.23:7299
{ audio.1} host <---> relay FSM: Waiting ===> InProgress
{ audio.1} Tx en0:host:10.0.1.8:31748 ---> relay:91.121.30.149:46920 (InProgress) [Trigged]
{ audio.1} Rx Binding Request from 91.121.30.149:46920 via Socket (candpair=InProgress)
stunsrv: {audio.1} candidate pair not found: source=176.11.159.23:7298
{ audio.1} Rx en0:host:10.0.1.8:31748 <--- relay:91.121.30.149:46920 '0 OK'
{ audio.1} adding local PRFLX Candidate: 91.121.30.149:57570
{ audio.1} New local candidate for mapped 91.121.30.149:57570
{ audio.1} host <---> relay FSM: InProgress ===> Succeeded
{ audio.2} host <---> host FSM: Frozen ===> InProgress
{ audio.2} Tx en0:host:10.0.1.8:31749 ---> host:100.103.159.22:7299 (InProgress)
stunsrv: {audio.2} candidate pair not found: source=176.11.159.23:7299
{ audio.1} Rx Binding Request from 91.121.30.149:46920 via Socket (candpair=Succeeded)
{ audio.1} Rx Binding Request from 91.121.30.149:46920 via Socket (candpair=Succeeded)
call: got re-INVITE (SDP Offer)
call: update media
stream: update 'audio'
{ audio.1} Set default remote candidate: relay:91.121.30.149:46920
{ audio.2} Set default remote candidate: relay:91.121.30.149:46921
ICE: ICE Start: ----- ICE Media <audio> -----
local_mode=Full, remote_mode=Full, local_role=Controlled
local_ufrag="7iE5M8n" local_pwd="wFnN7OCigbdBAeGednFVV4WMRFLVTSi"
Components: (2)
id=1 ldef=84.208.62.181:44541 rdef=91.121.30.149:46920 concluded=0
id=2 ldef=84.208.62.181:39972 rdef=91.121.30.149:46921 concluded=0
Local Candidates: (5)
{1} fnd=0a000108 prio=7e000aff en0:host:10.0.1.8:31748
{2} fnd=0a000108 prio=7e000afe en0:host:10.0.1.8:31749
{2} fnd=54d03eb4 prio=640000fe en0:srflx:84.208.62.181:39972 (rel-addr=10.0.1.8:31749)
{1} fnd=54d03eb4 prio=640000ff en0:srflx:84.208.62.181:44541 (rel-addr=10.0.1.8:31748)
{1} fnd=5b791e97 prio=6e0000ff en0:prflx:91.121.30.149:57570 (rel-addr=10.0.1.8:31748)
Remote Candidates: (6)
{1} fnd=1 prio=7effff7f host:100.103.159.22:7298
{2} fnd=9112130149 prio=00fffffe relay:91.121.30.149:46921
{1} fnd=9112130149 prio=00ffffff relay:91.121.30.149:46920
{2} fnd=1 prio=7effff7e host:100.103.159.22:7299
{1} fnd=12bb9b63 prio=6effff7f prflx:176.11.159.23:7298
{2} fnd=3aad0562 prio=6effff7e prflx:176.11.159.23:7299
Check list: [state=Running] (3)
{comp=1} InProgress { } en0:host:10.0.1.8:31748 <---> host:100.103.159.22:7298
{comp=2} InProgress { } en0:host:10.0.1.8:31749 <---> host:100.103.159.22:7299
{comp=2} Frozen { } en0:host:10.0.1.8:31749 <---> relay:91.121.30.149:46921
Valid list: (2)
* {comp=1} Succeeded { VN} en0:prflx:91.121.30.149:57570 <---> relay:91.121.30.149:46920
{comp=1} Succeeded { V } en0:host:10.0.1.8:31748 <---> relay:91.121.30.149:46920
STUN debug:
STUN client transactions: (2)
method=Binding tid=55784205e13e4523bf0f948a rto=100ms tmr=742 n=4 interval=1600
method=Binding tid=3ed496a693868f2259080712 rto=100ms tmr=1167 n=4 interval=1600
audio: comp1 setting local: 91.121.30.149:57570
{ audio.1} Rx en0:host:10.0.1.8:31748 <--- host:100.103.159.22:7298 '0 ' (Operation timed out)
{ audio.1} host <---> host FSM: InProgress ===> Failed
{ audio.2} host <---> relay FSM: Frozen ===> InProgress
{ audio.2} Tx en0:host:10.0.1.8:31749 ---> relay:91.121.30.149:46921 (InProgress)
{ audio.2} Rx en0:host:10.0.1.8:31749 <--- relay:91.121.30.149:46921 '0 OK'
{ audio.2} adding local PRFLX Candidate: 91.121.30.149:57571
{ audio.2} New local candidate for mapped 91.121.30.149:57571
{ audio.2} host <---> relay FSM: InProgress ===> Succeeded
{ audio.2} Rx Binding Request from 91.121.30.149:46921 via Socket (candpair=Succeeded)
{ audio.2} Rx Binding Request from 91.121.30.149:46921 via Socket (candpair=Succeeded)
{ audio.2} Rx en0:host:10.0.1.8:31749 <--- host:100.103.159.22:7299 '0 ' (Operation timed out)
{ audio.2} host <---> host FSM: InProgress ===> Failed
{ audio.1} Tx en0:prflx:91.121.30.149:57570 ---> relay:91.121.30.149:46920 (Succeeded) [USE] [Trigged]
{ audio.2} Tx en0:prflx:91.121.30.149:57571 ---> relay:91.121.30.149:46921 (Succeeded) [USE] [Trigged]
ice: audio: connectivity check is complete (update=0)
audio: Dumping media state: ----- ICE Media <audio> -----
local_mode=Full, remote_mode=Full, local_role=Controlled
local_ufrag="7iE5M8n" local_pwd="wFnN7OCigbdBAeGednFVV4WMRFLVTSi"
Components: (2)
id=1 ldef=84.208.62.181:44541 rdef=91.121.30.149:46920 concluded=1
id=2 ldef=84.208.62.181:39972 rdef=91.121.30.149:46921 concluded=1
Local Candidates: (6)
{1} fnd=0a000108 prio=7e000aff en0:host:10.0.1.8:31748
{2} fnd=0a000108 prio=7e000afe en0:host:10.0.1.8:31749
{2} fnd=54d03eb4 prio=640000fe en0:srflx:84.208.62.181:39972 (rel-addr=10.0.1.8:31749)
{1} fnd=54d03eb4 prio=640000ff en0:srflx:84.208.62.181:44541 (rel-addr=10.0.1.8:31748)
{1} fnd=5b791e97 prio=6e0000ff en0:prflx:91.121.30.149:57570 (rel-addr=10.0.1.8:31748)
{2} fnd=5b791e97 prio=6e0000fe en0:prflx:91.121.30.149:57571 (rel-addr=10.0.1.8:31749)
Remote Candidates: (6)
{1} fnd=1 prio=7effff7f host:100.103.159.22:7298
{2} fnd=9112130149 prio=00fffffe relay:91.121.30.149:46921
{1} fnd=9112130149 prio=00ffffff relay:91.121.30.149:46920
{2} fnd=1 prio=7effff7e host:100.103.159.22:7299
{1} fnd=12bb9b63 prio=6effff7f prflx:176.11.159.23:7298
{2} fnd=3aad0562 prio=6effff7e prflx:176.11.159.23:7299
Check list: [state=Completed] (2)
{comp=1} Failed { } en0:host:10.0.1.8:31748 <---> host:100.103.159.22:7298 (Operation timed out)
{comp=2} Failed { } en0:host:10.0.1.8:31749 <---> host:100.103.159.22:7299 (Operation timed out)
Valid list: (4)
* {comp=1} Succeeded { VN} en0:prflx:91.121.30.149:57570 <---> relay:91.121.30.149:46920
{comp=1} Succeeded { V } en0:host:10.0.1.8:31748 <---> relay:91.121.30.149:46920
* {comp=2} Succeeded { VN} en0:prflx:91.121.30.149:57571 <---> relay:91.121.30.149:46921
{comp=2} Succeeded { V } en0:host:10.0.1.8:31749 <---> relay:91.121.30.149:46921
STUN debug:
STUN client transactions: (2)
method=Binding tid=4c86ff5da3745b98f93a27e4 rto=100ms tmr=100 n=1 interval=100
method=Binding tid=9b0b4a6aae5e43b3b43d914d rto=100ms tmr=100 n=1 interval=100
audio: comp2 setting local: 91.121.30.149:57571
stream: mnat connected: raddr 91.121.30.149:46920 91.121.30.149:46921
stream: audio: starting RTCP with remote 91.121.30.149:46921
audio: Set audio encoder: opus 48000Hz 1ch
opus: encoder fmtp (useinbandfec=1)
audio: start
rst: audio ptime=20 sampc=960 aubuf=[96000:1920000]
audio: source started with sample format S16LE
audio tx pipeline: rst ---> opus
audio rx pipeline: coreaudio <--- opus
audio: start
rst: connection established
{ audio.1} Rx en0:prflx:91.121.30.149:57570 <--- relay:91.121.30.149:46920 '0 OK'
{ audio.2} Rx en0:prflx:91.121.30.149:57571 <--- relay:91.121.30.149:46921 '0 OK'
rst: name='SLAY Radio' metaint=8192
rst: new format: 48000 hz, 1 ch, encoding 0x00d0
[0:00:13] audio=61660/42030 (bit/s)
--- Audio stream ---
tx: encode: opus 48000Hz/1ch ptime=20ms S16LE
aubuf: wish_sz=1920 cur_sz=0 filling=0 (cur 0.00ms, max 600.00ms, or 0, ur 0)
source: rst,http://relay.slayradio.org:8000/ S16LE
time = 10.820 sec
rx: decode: opus 48000Hz/1ch S16LE
aubuf: wish_sz=1920 cur_sz=13440 filling=0 (cur 140.00ms, max 160.00ms, or 2, ur 0)
player: coreaudio,default S16LE
n_discard:0
time = 13.419 sec
audio tx pipeline: rst ---> opus
audio rx pipeline: coreaudio <--- opus
audio dir=sendrecv pt_enc=96
local: 91.121.30.149:57570, remote: 91.121.30.149:46920/91.121.30.149:46921
mnat: ice (connected=yes)
menc: (none) (secure=no)
RTP debug:
Encode: seq=629 ssrc=0xa338b7d8
----- RTCP Session: -----
cname=sip:alfredh2@sip.antisip.com SSRC=0xa338b7d8/2738403288 rx=48000Hz
member 0xe60fe5d8: lost=0 Jitter=3.5ms RTT=80.7ms
IP=91.121.30.149:46920 psent=657 rcvd=674
TX: packets=541, octets=81638
--- jitter buffer debug---
running=1 min=2 cur=2 max=6 [frames]
seq_put=673
Stat: put=671 get=671 oos=0 dup=0 late=0 or=0 ur=2 flush=1 put/get_ratio=100% lost=0 (0.00%)
sip:alfredh@sip.antisip.com: session closed: Connection reset by peer
sip:alfredh2@sip.antisip.com: Call with sip:alfredh@sip.antisip.com terminated (duration: 19 secs)
audio: destroyed (started=1)
audio Transmit: Receive:
packets: 825 955
avg. bitrate: 59.7 40.2 (kbit/s)
errors: 0 0
pkt.report: 638 771
lost: 0 0
jitter: 3.3 7.2 (ms)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment