BelledonneCommunications / linphone-desktop

Linphone is a free VoIP and video softphone based on the SIP protocol. Mirror of git://git.linphone.org/linphone-desktop.git
https://linphone.org/
GNU General Public License v3.0
417 stars 211 forks source link

[Bug]: INVITE with IPv4 triggers bad IPv4-mapped addresses #788

Open systemcrash opened 1 year ago

systemcrash commented 1 year ago

Context

-

General information

macOS about: 13.5.2 (22G91)

Linphone about: Desktop 5.1.2 - Qt5.15.2 Core 5.2.97

Expected behaviour

Reply with global IPv6 in SDP, instead of:

Media local ip to reach 192.0.2.1 is :::ffff:192.168.1.9

( Trying to be 'smart' when we receive everything via IPv6 anyway just breaks things. )

To Reproduce

  1. Register to SIP proxy via IPv6
  2. Call in to self (call comes in from IPv4 hop on other side of proxy IPv4 addr )
  3. BANG

Additional context

[17:17:05:876][Info]Core:linphone: channel [0x7f80bfbe8000]: received [1802] new bytes from [TLS://sip.example.test:5061]:
INVITE sip:paul@[--myGlobalIPv6--]:54674;transport=tls SIP/2.0
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bKe5f28dd4437f654a2c6eec8dfdfe1469.1
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK6059b35a7ab26d3894f9089ef3e8e7cc.0.JC2XJlT7RulVPp7fsNsjUg__
Session-Expires: 14400
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK583847473c03c5121d6f4b732d0c8156.NJY1RXDDEj0ghSDD2L8I3w__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 10 INVITE
Contact: <sip:EqKcUfZFdUiMlT_RT@[--ProxyGlobalIPv6_2--]:5061;transport=tls>
Supported: timer, replaces, path, histinfo
Allow: ACK, CANCEL, INVITE, BYE, NOTIFY, INFO, OPTIONS, PRACK, REFER, UPDATE
User-Agent: Sems-Sip_1.0
Max-Forwards: 18
Content-Type: application/sdp
Content-Length: 831
Record-Route: <sip:rs.gcV55uP.6rwKSgCs8Y25f4a804@[--ProxyGlobalIPv6_2--]:5061;transport=tls;lr>

v=0
o=trunk1.13 93 382631988 IN IP6 --ProxyGlobalIPv6_2--
s=-
c=IN IP6 --ProxyGlobalIPv6_2--
t=0 0
a=ice-lite
m=audio 58044 RTP/SAVP 8 13 96 0
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:6pGIoWDTaps6TUVuT0RhB38gCpPTV/L/JMc0Iz+h
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:x6qQ2R/k7KiqJEkcy6pII/0BNNAVHOo76YMzvvif
a=fingerprint:sha-256 52:EC:14:EA:D9:34:DA:10:9D:65:F1:DC:CE:01:19:AD:79:3C:49:63:52:92:69:09:C7:7E:11:D6:A9:3F:23:3B
a=setup:actpass
a=rtpmap:8 PCMA/8000
a=rtpmap:13 CN/8000
a=rtpmap:96 telephone-event/8000
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtcp-mux
a=candidate:2a038600860000000000000000000073 1 UDP 2130706431 --ProxyGlobalIPv6_2-- 58044 typ host
a=candidate:2a038600860000000000000000000073 2 UDP 2130706430 --ProxyGlobalIPv6_2-- 58045 typ host
a=ice-ufrag:opw5MBRX+NPjsb22
a=ice-pwd:xHVOgTfPZXruBwCLCdj1GS7l

[17:17:05:882][Info]Core:linphone: channel [0x7f80bfbe8000] [971] bytes parsed
[17:17:05:882][Info]Core:linphone: channel [0x7f80bfbe8000] read [831] bytes of body from [sip.example.test:5061]
[17:17:05:883][Info]Core:linphone: transaction [0x600010d89800]: starting transaction background task with id=[42].
[17:17:05:883][Info]Core:linphone: Changing [server] [INVITE] transaction [0x600010d89800], from state [INIT] to [PROCEEDING]
[17:17:05:883][Info]Core:linphone: channel [0x7f80bfbe8000]: message sent to [TLS://sip.example.test:5061], size: [513] bytes
SIP/2.0 100 Trying
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bKe5f28dd4437f654a2c6eec8dfdfe1469.1
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK6059b35a7ab26d3894f9089ef3e8e7cc.0.JC2XJlT7RulVPp7fsNsjUg__
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK583847473c03c5121d6f4b732d0c8156.NJY1RXDDEj0ghSDD2L8I3w__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: sip:+--redacted_callee--@--ProxyGlobalIPv4--
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 10 INVITE
Content-Length: 0

[17:17:05:884][Info]Core:linphone: New server dialog [0x600008414000] , local tag [2wZIVxd], remote tag [44f6aab8]
[17:17:05:884][Info]Core:linphone: op [0x7f80bf6ba010] : setOrUpdateDialog() current=[0x0] new=[0x600008414000]
[17:17:05:884][Info]Core:linphone: New incoming call from [sip:+--redacted_caller--@192.0.2.1] to [sip:+--redacted_callee--@--ProxyGlobalIPv4--]
[17:17:05:885][Info]Core:linphone: Found payload PCMA/8000 fmtp=
[17:17:05:885][Info]Core:linphone: Found payload CN/8000 fmtp=
[17:17:05:885][Info]Core:linphone: Found payload telephone-event/8000 fmtp=
[17:17:05:885][Info]Core:linphone: Found payload PCMU/8000 fmtp=
[17:17:05:885][Info]Core:linphone: Found: 2 valid crypto lines
[17:17:05:885][Info]Core:linphone: Start measurement of [Get call log.].
[17:17:05:888][Info]Core:linphone: Duration of [Get call log.]: 2ms.
[17:17:05:888][Info]Core:linphone: New MediaSession [0x60000dc6fe58] initialized (liblinphone version: 5.2.97)
[17:17:05:890][Info]Core:linphone: MainDb::addEvent() of type ConferenceCallStarted (value 3)
[17:17:05:892][Info]Core:linphone: Insert new conference call in database: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
[17:17:05:897][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_log_updated]
[17:17:05:897][Info]Core:linphone: Rtp bundle is disabled.
[17:17:05:897][Info]Core:linphone: Media local ip to reach 192.0.2.1 is :::ffff:192.168.19.9
[17:17:05:897][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80
[17:17:05:897][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_32
[17:17:05:897][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_80
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_32
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80 UNENCRYPTED_SRTCP
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80 UNENCRYPTED_SRTP
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80 UNENCRYPTED_SRTCP UNENCRYPTED_SRTP
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80 UNAUTHENTICATED_SRTP
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_32 UNAUTHENTICATED_SRTP
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_128_GCM
[17:17:05:898][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_256_GCM
[17:17:05:899][Warning]Core:linphone: BctbxException occurred:
[17:17:05:899][Info]Core:linphone: [LIME]  /Users/buildbot/builds/V3JisSb9/1/BC/public/linphone-desktop/linphone-sdk/lime/src/lime_localStorage.cpp:269 Cannot find Lime User sip:paul@[--myGlobalIPv6--] in DB while setting up identity key for ZRTP auxiliary secret
[17:17:05:899][Info]Core:linphone: stream#0 [audio] in state [Stopped]: multicast role is [inactive]
[17:17:05:899][Info]Core:linphone: RtpSession bound to [::0] ports [7078] [7079]
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_32
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_80
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_32
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_128_GCM
[17:17:05:899][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_256_GCM
[17:17:05:899][Info]Core:linphone: Configured zrtp key agreement: 'MS_ZRTP_KEY_AGREEMENT_K255_KYB512'
[17:17:05:899][Info]Core:linphone: Creating ZRTP engine on rtp session [0x7f80ba894000] ssrc 0x6cdbb7b9
[17:17:05:902][Info]Core:linphone: rtp_session_enable_network_simulation:DISABLING NETWORK SIMULATION
[17:17:05:902][Info]Core:linphone: Setting DSCP to 46 for MSAudio stream.
[17:17:05:902][Info]Core:linphone: Created stream of type audio at index 0: stream#0 [audio] in state [Stopped]
[17:17:05:902][Info]Core:linphone: [MS2AudioStream] setting type of soundcard 0x600001bbfb60 to voice
[17:17:05:902][Info]Core:linphone: [MS2AudioStream] setting type of soundcard 0x600001b50eb0 to voice
[17:17:05:902][Info]Core:linphone: Doing SDP offer/answer process of type incoming
[17:17:05:902][Info]Core:linphone: No match for CN/8000/1
[17:17:05:903][Info]Core:linphone: [Initiate Incoming Stream] Found matching configurations: local configuration index 0 remote offered configuration index 0
[17:17:05:903][Info]Core:linphone: Found crypto algorithm matching tag 1: algorithm 1 master key 6pGIoWDTaps6TUVuT0RhB38gCpPTV/L/JMc0Iz+h
[17:17:05:903][Error]Core:linphone: Unable to retrieve contact address from proxy confguration for call session 0x60000dc6fe58 (local address sip:+--redacted_callee--@--ProxyGlobalIPv4-- remote address sip:+--redacted_caller--@192.0.2.1).
[17:17:05:903][Info]Core:linphone: [ToneManager] stopDtmfStream
[17:17:05:904][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_created]
[17:17:05:904][Info]Core:linphone: Starting background task [67] with name: [Liblinphone call notification] and expiration of [30]
[17:17:05:904][Info]Core:linphone: [ToneManager] destroyRingStream
[17:17:05:904][Info]Core:linphone: [ToneManager] startRingtone
[17:17:05:904][Info]Core:linphone: Starting local ringtone...
[17:17:05:905][Info]Core:linphone: speex_lib_ctl init with neon ? 0
[17:17:05:906][Info]Core:linphone: Configuring resampler input with rate=[44100], nchannels=[2]
[17:17:05:906][Info]Core:linphone: MSFilePlayer[0x600004e4fac0]: /Users/paul/Documents/Ringtone/hello_2015.wav opened: rate=44100,channel=2, length=18292 ms
[17:17:05:906][Info]Core:linphone: configuring resampler output to rate=[44100], nchannels=[2]
[17:17:05:906][Info]Core:linphone: ms_filter_link: MSFilePlayer:0x600004e4fac0,0-->MSDtmfGen:0x600004e4c640,0
[17:17:05:906][Info]Core:linphone: ms_filter_link: MSDtmfGen:0x600004e4c640,0-->MSResample:0x600004e4fc00,0
[17:17:05:906][Info]Core:linphone: Priority used: 47
[17:17:05:906][Info]Core:linphone: ms_filter_link: MSResample:0x600004e4fc00,0-->MSAuWrite:0x600004e4fb60,0
[17:17:05:906][Info]Core:linphone: Ring MSTicker priority set to SCHED_RR and value (47)
[17:17:05:906][Info]Core:linphone: Initializing speex resampler in mode [voip] from 2 channels
[17:17:05:908][Info]Core:linphone: Format for [lpcm] rate [44100] channels [2]
[17:17:05:909][Info]Core:linphone: Format for [lpcm] rate [44100] channels [2]
[17:17:05:909][Info]Core:linphone: Number of frames per buffer = 512
[17:17:05:968][Info]Core:linphone: CallSession [0x60000dc6fe58] moving from state LinphoneCallIdle to LinphoneCallIncomingReceived
[17:17:05:968][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [first_call_started]
[17:17:05:969][Info]Core:linphone: QT: "Update (`sip:+--redacted_caller--@192.0.2.1`, `sip:+--redacted_callee--@--ProxyGlobalIPv4--`) from chat call."
[17:17:05:974][Info]Core:linphone: QT: "Add call:" "sip:+--redacted_callee--@--ProxyGlobalIPv4--" "sip:+--redacted_caller--@192.0.2.1"
[17:17:06:242][Info]Core:linphone: Setting call id [sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7] to ChatRoom [0x7f80b7f58530]
[17:17:06:250][Info]Core:linphone: Setting call id [sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7] to ChatRoom [0x7f80b7f58530]
[17:17:06:251][Info]Core:linphone: Start measurement of [Get call history 2.].
[17:17:06:252][Info]Core:linphone: Duration of [Get call history 2.]: 0ms.
[17:17:06:405][Info]Core:linphone: QT: "Create notifications:" NotificationReceivedCall_QMLTYPE_614(0x60000cf07020, name="__internalWrapper", parent=0x600003f43c40, geometry=0,0 0x0)
[17:17:06:405][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_state_changed]
[17:17:06:405][Info]Core:linphone: Ending background task [67] with name: [Liblinphone call notification]
[17:17:06:405][Info]Core:linphone: Contact has not been fixed, stack will do
[17:17:06:405][Warning]Core:linphone: no host found in this uri
[17:17:06:405][Info]Core:linphone: [org.antlr.runtime.MismatchedTokenException]  reason []
[17:17:06:405][Error]Core:linphone: fast_header_address parser error for ["Paul" <sip:paul@:-1>]
[17:17:06:405][Warning]Core:linphone: Cannot create Address, bad uri ["Paul" <sip:paul@:-1>]
[17:17:06:405][Warning]Core:linphone: Unable to set contact address for session 0x7f80ba7fc200 to  as it is not valid
[17:17:06:405][Info]Core:linphone: channel [0x7f80bfbe8000]: message sent to [TLS://sip.example.test:5061], size: [767] bytes
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bKe5f28dd4437f654a2c6eec8dfdfe1469.1
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK6059b35a7ab26d3894f9089ef3e8e7cc.0.JC2XJlT7RulVPp7fsNsjUg__
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK583847473c03c5121d6f4b732d0c8156.NJY1RXDDEj0ghSDD2L8I3w__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->;tag=2wZIVxd
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 10 INVITE
User-Agent: Linphone-Desktop/5.1.2 (MacBook-Pro.local) osx/13.5 Qt/5.15.2 LinphoneSDK/5.2.97
Supported: replaces, outbound, gruu, record-aware
Record-route: <sip:rs.gcV55uP.6rwKSgCs8Y25f4a804@[--ProxyGlobalIPv6_2--]:5061;transport=tls;lr>
Content-Length: 0

[17:17:06:405][Info]Core:linphone: Dialog [0x600008414000]: now updated by transaction [0x600010d89800].
[17:17:06:405][Info]Core:linphone: channel [0x7f80bfbe8000]: ending recv background task with id=[41].
[17:17:06:514][Info]Core:linphone: [Magic Search] Found 0 results in friends
[17:17:06:516][Info]Core:linphone: Start measurement of [Get call history 2.].
[17:17:06:516][Info]Core:linphone: Duration of [Get call history 2.]: 0ms.
[17:17:06:855][Info]Core:linphone: Incoming call ringing for 1 seconds
[17:17:07:835][Info]Core:linphone: Incoming call ringing for 2 seconds
[17:17:08:835][Info]Core:linphone: Incoming call ringing for 3 seconds
[17:17:09:835][Info]Core:linphone: Incoming call ringing for 4 seconds
[17:17:10:722][Info]Core:linphone: Keeping same crypto keys when making new local stream description
[17:17:10:722][Warning]Core:linphone: BctbxException occurred:
[17:17:10:722][Info]Core:linphone: [LIME]  /Users/buildbot/builds/V3JisSb9/1/BC/public/linphone-desktop/linphone-sdk/lime/src/lime_localStorage.cpp:269 Cannot find Lime User sip:paul@[--myGlobalIPv6--] in DB while setting up identity key for ZRTP auxiliary secret
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_32
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_80
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_32
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_128_GCM
[17:17:10:723][Info]Core:linphone: Configured srtp crypto suite: AEAD_AES_256_GCM
[17:17:10:723][Warning]Core:linphone: BctbxException occurred:
[17:17:10:723][Info]Core:linphone: [LIME]  /Users/buildbot/builds/V3JisSb9/1/BC/public/linphone-desktop/linphone-sdk/lime/src/lime_localStorage.cpp:269 Cannot find Lime User sip:paul@[--myGlobalIPv6--] in DB while setting up identity key for ZRTP auxiliary secret
[17:17:10:724][Info]Core:linphone: Configuring prefered card sampling rate to [16000]
[17:17:10:724][Info]Core:linphone: [LIME] Missing identity keys for mutual authentication, do not set auxiliary secret from identity keys
[17:17:10:724][Info]Core:linphone: Contact has not been fixed, stack will do
[17:17:10:724][Warning]Core:linphone: no host found in this uri
[17:17:10:724][Info]Core:linphone: [org.antlr.runtime.MismatchedTokenException]  reason []
[17:17:10:724][Error]Core:linphone: fast_header_address parser error for ["Paul" <sip:paul@:-1>]
[17:17:10:724][Warning]Core:linphone: Cannot create Address, bad uri ["Paul" <sip:paul@:-1>]
[17:17:10:724][Warning]Core:linphone: Unable to set contact address for session 0x7f80ba7fc200 to  as it is not valid
[17:17:10:724][Info]Core:linphone: Accepting server transaction [0x600010d89800] on op [0x7f80bf6ba010]
[17:17:10:724][Info]Core:linphone: Doing SDP offer/answer process of type incoming
[17:17:10:724][Info]Core:linphone: No match for CN/8000/1
[17:17:10:724][Info]Core:linphone: [Initiate Incoming Stream] Found matching configurations: local configuration index 0 remote offered configuration index 0
[17:17:10:724][Info]Core:linphone: Found crypto algorithm matching tag 1: algorithm 1 master key 6pGIoWDTaps6TUVuT0RhB38gCpPTV/L/JMc0Iz+h
[17:17:10:725][Info]Core:linphone: channel [0x7f80bfbe8000]: message sent to [TLS://sip.example.test:5061], size: [1239] bytes
SIP/2.0 200 Ok
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bKe5f28dd4437f654a2c6eec8dfdfe1469.1
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK6059b35a7ab26d3894f9089ef3e8e7cc.0.JC2XJlT7RulVPp7fsNsjUg__
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK583847473c03c5121d6f4b732d0c8156.NJY1RXDDEj0ghSDD2L8I3w__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->;tag=2wZIVxd
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 10 INVITE
User-Agent: Linphone-Desktop/5.1.2 (MacBook-Pro.local) osx/13.5 Qt/5.15.2 LinphoneSDK/5.2.97
Supported: replaces, outbound, gruu, record-aware
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, PRACK, UPDATE
Contact: <sip:[--myGlobalIPv6--]:54674;transport=tls>;+org.linphone.specs="lime"
Content-Type: application/sdp
Content-Length: 243
Record-route: <sip:rs.gcV55uP.6rwKSgCs8Y25f4a804@[--ProxyGlobalIPv6_2--]:5061;transport=tls;lr>

v=0
o=paul 2984 2991 IN IP6 ::ffff:192.168.19.9
s=Talk
c=IN IP6 ::ffff:192.168.19.9
t=0 0
m=audio 7078 RTP/SAVP 8 96 0
a=rtpmap:96 telephone-event/8000
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:9noflYEx+yG7LyHZVBkBva7DYvxJmSocezk7wcx7

[17:17:10:725][Info]Core:linphone: Changing [server] [INVITE] transaction [0x600010d89800], from state [PROCEEDING] to [ACCEPTED]
[17:17:10:725][Info]Core:linphone: Dialog [0x600008414000]: now updated by transaction [0x600010d89800].
[17:17:10:725][Info]Core:linphone: [ToneManager] session 0x60000dc6fe58 is no longer ringing.
[17:17:10:725][Info]Core:linphone: [ToneManager] stopRingtone
[17:17:10:751][Info]Core:linphone: ms_filter_unlink: MSFilePlayer:0x600004e4fac0,0-->MSDtmfGen:0x600004e4c640,0
[17:17:10:751][Info]Core:linphone: ms_filter_unlink: MSDtmfGen:0x600004e4c640,0-->MSResample:0x600004e4fc00,0
[17:17:10:751][Info]Core:linphone: ms_filter_unlink: MSResample:0x600004e4fc00,0-->MSAuWrite:0x600004e4fb60,0
[17:17:10:772][Info]Core:linphone: Ring MSTicker thread exiting
[17:17:10:773][Info]Core:linphone: msasync.c: worker thread is exiting.
[17:17:10:773][Info]Core:linphone: CallSession [0x60000dc6fe58] moving from state LinphoneCallIncomingReceived to LinphoneCallConnected
[17:17:10:773][Info]Core:linphone: MainDb::addEvent() of type ConferenceCallConnected (value 21)
[17:17:10:774][Info]Core:linphone: Update conference call in database: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
[17:17:10:775][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_log_updated]
[17:17:10:775][Info]Core:linphone: Unable to find audio video conference with conference ID ConferenceId(peer=IdentityAddress(sip:+--redacted_callee--@--ProxyGlobalIPv4--), local=IdentityAddress(sip:+--redacted_callee--@--ProxyGlobalIPv4--)) in RAM.
[17:17:10:776][Info]Core:linphone: QT: "Update (`sip:+--redacted_caller--@192.0.2.1`, `sip:+--redacted_callee--@--ProxyGlobalIPv4--`) from chat call."
[17:17:10:776][Info]Core:linphone: QT: "Delete notification:" NotificationReceivedCall_QMLTYPE_614(0x60000cf07020, name = "__internalWrapper")
[17:17:10:776][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_state_changed]
[17:17:10:776][Info]Core:linphone: Negotiated media encryption is LinphoneMediaEncryptionSRTP
[17:17:10:776][Info]Core:linphone: [ToneManager] destroyRingStream
[17:17:10:776][Info]Core:linphone: StreamsGroup 0x600000720000 rendering stream#0 [audio] in state [Stopped]
[17:17:10:776][Info]Core:linphone: stream#0 [audio] in state [Stopped] is not part of any bundle
[17:17:10:776][Info]Core:linphone: Audio bandwidth for StreamsGroup [0x600000720000] is 80
[17:17:10:776][Info]Core:linphone: Call state LinphoneCallStreamsRunning, using voice stream
[17:17:10:776][Info]Core:linphone: Equalizer location: hp
[17:17:10:777][Info]Core:linphone: cannot set noise gate mode to [0] because no volume send
[17:17:10:777][Info]Core:linphone: Found crypto algorithm matching tag 1: algorithm 1 master key 9noflYEx+yG7LyHZVBkBva7DYvxJmSocezk7wcx7
[17:17:10:777][Info]Core:linphone: media_stream_set_srtp_send_key(): key f6..7b stream sessions is [0x7f80bf7ae538]
[17:17:10:777][Info]Core:linphone: media_stream_set_srtcp_send_key(): key f6..7b stream sessions is [0x7f80bf7ae538]
[17:17:10:777][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_send_master_key_changed]
[17:17:10:777][Info]Core:linphone: media_stream_set_srtp_recv_key(): key ea..a1 stream sessions is [0x7f80bf7ae538]
[17:17:10:777][Info]Core:linphone: media_stream_set_srtcp_recv_key(): key ea..a1 stream sessions is [0x7f80bf7ae538]
[17:17:10:777][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_receive_master_key_changed]
[17:17:10:777][Info]Core:linphone: stream#0 [audio] in state [Stopped] is not part of any bundle
[17:17:10:777][Warning]Core:linphone: Fail to set IPv4 packet info on RTP socket: Invalid argument.
[17:17:10:777][Warning]Core:linphone: Fail to set IPv4 packet info on RTCP socket: Invalid argument.
[17:17:10:777][Info]Core:linphone: ICE state is IceStateNotActivated for stream#0 [audio] in state [Stopped]
[17:17:10:777][Info]Core:linphone: RtpSession [0x7f80ba894000] sending to rtp [--ProxyGlobalIPv6_2--]:58044 rtcp [--ProxyGlobalIPv6_2--]:58044
[17:17:10:778][Info]Core:linphone: Stun packet of length 20 sent on rtp for session [0x7f80ba894000]
[17:17:10:778][Info]Core:linphone: Stun packet of length 20 sent on rtcp for session [0x7f80ba894000]
[17:17:10:778][Info]Core:linphone: audio_stream_start_from_io: create encoder, decoder and resamplers.
[17:17:10:778][Info]Core:linphone: speex_lib_ctl init with neon ? 0
[17:17:10:778][Info]Core:linphone: speex_lib_ctl init with neon ? 0
[17:17:10:778][Info]Core:linphone: Setting echo canceller delay with value configured by application.
[17:17:10:778][Info]Core:linphone: MKVRecorder: initialisation
[17:17:10:778][Info]Core:linphone: speex_lib_ctl init with neon ? 0
[17:17:10:778][Info]Core:linphone: Configuring av recorder with audio format type=audio;encoding=opus;rate=48000;channels=1;fmtp=''
[17:17:10:778][Info]Core:linphone: MKVRecorder: set pin #1 format. type=audio;encoding=opus;rate=48000;channels=1;fmtp=''
[17:17:10:778][Info]Core:linphone: target bitrate not set for stream [0x7f80bf7ae530] using payload's bitrate is 80000
[17:17:10:778][Info]Core:linphone: Setting audio encoder network bitrate to [80000] on stream [0x7f80bf7ae530]
[17:17:10:778][Info]Core:linphone: RtpSession: target upload bandwidth set to 80000
[17:17:10:778][Info]Core:linphone: MSAlawEnc configured with ptime=20
[17:17:10:778][Info]Core:linphone: No information available for [//],
[17:17:10:778][Info]Core:linphone: Sound device information for [//] is: builtin=[no], delay=[0] ms
[17:17:10:778][Info]Core:linphone: MSVolume[0x600004915ea0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:778][Info]Core:linphone: MSVolume[0x6000049178e0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:778][Info]Core:linphone: configuring MSAuRead:0x600004917d40-->MSAlawEnc:0x600004917e80 from rate [44100] to rate [8000] and from channel [1] to channel [1]
[17:17:10:778][Info]Core:linphone: configuring MSAlawDec:0x600004917ac0-->MSAuWrite:0x600004917f20 from rate [8000] to rate [44100] and from channel [1] to channel [1]
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAuRead:0x600004917d40,0-->MSResample:0x600004917ca0,0
[17:17:10:779][Info]Core:linphone: Priority used: 47
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSResample:0x600004917ca0,0-->MSEqualizer:0x600004914d20,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSEqualizer:0x600004914d20,0-->MSWebRTCAEC:0x600004e5c0a0,1
[17:17:10:779][Info]Core:linphone: MSAudio MSTicker priority set to SCHED_RR and value (47)
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSWebRTCAEC:0x600004e5c0a0,1-->MSVolume:0x600004915ea0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSVolume:0x600004915ea0,0-->MSAudioMixer:0x600004915c20,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAudioMixer:0x600004915c20,0-->MSAlawEnc:0x600004917e80,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAlawEnc:0x600004917e80,0-->MSRtpSend:0x600004e5c280,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSRtpRecv:0x6000049163a0,0-->MSAlawDec:0x600004917ac0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAlawDec:0x600004917ac0,0-->MSGenericPLC:0x600004914a00,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSGenericPLC:0x600004914a00,0-->MSAudioFlowControl:0x600004914820,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAudioFlowControl:0x600004914820,0-->MSDtmfGen:0x600004917c00,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSDtmfGen:0x600004917c00,0-->MSVolume:0x6000049178e0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSVolume:0x6000049178e0,0-->MSTee:0x600004915d60,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSTee:0x600004915d60,0-->MSEqualizer:0x600004914be0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSEqualizer:0x600004914be0,0-->MSAudioMixer:0x6000049155e0,0
[17:17:10:779][Info]Core:linphone: speex_lib_ctl init with neon ? 0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSFilePlayer:0x600004914e60,0-->MSResample:0x6000049157c0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSResample:0x6000049157c0,0-->MSAudioMixer:0x6000049155e0,1
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAudioMixer:0x6000049155e0,0-->MSWebRTCAEC:0x600004e5c0a0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSWebRTCAEC:0x600004e5c0a0,0-->MSResample:0x600004915860,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSResample:0x600004915860,0-->MSAuWrite:0x600004917f20,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSAudioMixer:0x600004915e00,1-->MSResample:0x600004915ae0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSResample:0x600004915ae0,0-->MSOpusEnc:0x6000049140a0,0
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSOpusEnc:0x6000049140a0,0-->MSMKVRecorder:0x600004915a40,1
[17:17:10:779][Info]Core:linphone: ms_filter_link: MSItcSource:0x600004915b80,0-->MSMKVRecorder:0x600004915a40,0
[17:17:10:780][Info]Core:linphone: ms_filter_link: MSAudioMixer:0x600004915c20,1-->MSAudioMixer:0x600004915e00,0
[17:17:10:780][Info]Core:linphone: ms_filter_link: MSTee:0x600004915d60,1-->MSAudioMixer:0x600004915e00,1
[17:17:10:780][Info]Core:linphone: ms_filter_link: MSAudioMixer:0x600004915e00,0-->MSFileRec:0x600004915cc0,0
[17:17:10:780][Info]Core:linphone: ms_ticker_set_time_func: ticker's time method updated.
[17:17:10:783][Info]Core:linphone: Format for [lpcm] rate [44100] channels [1]
[17:17:10:783][Info]Core:linphone: Format for [lpcm] rate [44100] channels [1]
[17:17:10:783][Info]Core:linphone: Number of frames per buffer = 512
[17:17:10:912][Info]Core:linphone: Initializing speex resampler in mode [voip] from 1 channels
[17:17:10:912][Info]Core:linphone: Initializing WebRTC echo canceler with framesize=80, delay_ms=93, delay_samples=744
[17:17:10:912][Info]Core:linphone: Initializing speex resampler in mode [voip] from 1 channels
[17:17:10:912][Info]Core:linphone: MSOpusEnc: codec bitrate set to [30000] with ptime [20]
[17:17:10:912][Info]Core:linphone: Setting opus codec bitrate to [30000] from network bitrate [46000] with ptime [20]
[17:17:10:912][Info]Core:linphone: Initializing speex resampler in mode [voip] from 1 channels
[17:17:10:912][Info]Core:linphone: Initializing speex resampler in mode [voip] from 1 channels
[17:17:10:914][Info]Core:linphone: Format for [lpcm] rate [44100] channels [2]
[17:17:10:915][Info]Core:linphone: Format for [lpcm] rate [44100] channels [1]
[17:17:10:915][Info]Core:linphone: Number of frames per buffer = 512
[17:17:10:973][Info]Core:linphone: Filter MSRtpRecv is already being scheduled; nothing to do.
[17:17:10:973][Info]Core:linphone: MSVolume[0x600004915ea0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:973][Info]Core:linphone: MSVolume[0x6000049178e0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:973][Info]Core:linphone: AudioStream[0x7f80bf7ae530]: mic is [enabled].
[17:17:10:973][Info]Core:linphone: MSVolume[0x600004915ea0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:973][Info]Core:linphone: MSAudioFlowControl: configured with strategy=[1] and silent_threshold=[0.020000].
[17:17:10:973][Info]Core:linphone: MSVolume[0x6000049178e0]: set gain to [0.000000 db], [1.000000] linear
[17:17:10:973][Info]Core:linphone: [LIME] Missing identity keys for mutual authentication, do not set auxiliary secret from identity keys
[17:17:10:973][Info]Core:linphone: CallSession[0x60000dc6fe58] : payload type 8 PCMA/8000 fmtp= added to frozen list
[17:17:10:973][Info]Core:linphone: CallSession[0x60000dc6fe58] : payload type 96 telephone-event/8000 fmtp= added to frozen list
[17:17:10:974][Info]Core:linphone: CallSession[0x60000dc6fe58] : payload type 0 PCMU/8000 fmtp= added to frozen list
[17:17:10:974][Info]Core:linphone: CallSession [0x60000dc6fe58] moving from state LinphoneCallConnected to LinphoneCallStreamsRunning
[17:17:10:974][Info]Core:linphone: Unable to find audio video conference with conference ID ConferenceId(peer=IdentityAddress(sip:+--redacted_callee--@--ProxyGlobalIPv4--), local=IdentityAddress(sip:+--redacted_callee--@--ProxyGlobalIPv4--)) in RAM.
[17:17:10:974][Info]Core:linphone: QT: "Update (`sip:+--redacted_caller--@192.0.2.1`, `sip:+--redacted_callee--@--ProxyGlobalIPv4--`) from chat call."
[17:17:10:977][Info]Core:linphone: Setting call id [sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7] to ChatRoom [0x7f80b7f58530]
[17:17:10:977][Info]Core:linphone: Setting call id [sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7] to ChatRoom [0x7f80b7f58530]
[17:17:10:978][Info]Core:linphone: Setting call id [sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7] to ChatRoom [0x7f80b7f58530]
[17:17:10:980][Info]Core:linphone: Stun packet of length 20 sent on rtp for session [0x7f80ba894000]
[17:17:10:980][Info]Core:linphone: Stun packet of length 20 sent on rtcp for session [0x7f80ba894000]
[17:17:10:988][Info]Core:linphone: Linphone core [0x7f80b9809200] notified [call_state_changed]
[17:17:10:988][Info]Core:linphone: MediaSession (local address sip:+--redacted_callee--@--ProxyGlobalIPv4-- remote address sip:+--redacted_caller--@192.0.2.1) has been accepted
[17:17:10:990][Warning]Core:linphone: Getting reference signal but no echo to synchronize on.
[17:17:10:990][Warning]Core:linphone: Not enough ref samples, using zeroes
[17:17:10:990][Info]Core:linphone: MSAudioMixer [0x600004915c20] is entering bypass mode.
[17:17:11:000][Info]Core:linphone: Samples are back.
[17:17:11:077][Info]Core:linphone: channel [0x7f80bfbe8000]: starting recv background task with id=[44].
[17:17:11:077][Info]Core:linphone: channel [0x7f80bfbe8000]: received [481] new bytes from [TLS://sip.example.test:5061]:
ACK sip:[--myGlobalIPv6--]:54674;transport=tls SIP/2.0
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bK4c6663305f10eed85a16d7d8471cb47e.0
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK4890d15e16ede920489c48258b435249.Xxd5XeQ1YucwnEZtyTZkbQ__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->;tag=2wZIVxd
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 10 ACK
Max-Forwards: 20
Content-Length: 0

[17:17:11:079][Info]Core:linphone: channel [0x7f80bfbe8000] [481] bytes parsed
[17:17:11:079][Info]Core:linphone: Incoming INVITE has ACK, dialog is happy
[17:17:11:079][Info]Core:linphone: channel [0x7f80bfbe8000]: ending recv background task with id=[44].
[17:17:11:098][Info]Core:linphone: channel [0x7f80bfbe8000]: starting recv background task with id=[45].
[17:17:11:098][Info]Core:linphone: channel [0x7f80bfbe8000]: received [481] new bytes from [TLS://sip.example.test:5061]:
BYE sip:[--myGlobalIPv6--]:54674;transport=tls SIP/2.0
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bK08e1feeb29e981f85a16d7d8471cb47e.0
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK00fcc17563454b031b54173674bb640c.Il0RaJR+V35jQGVXyen6lg__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->;tag=2wZIVxd
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 11 BYE
Max-Forwards: 20
Content-Length: 0

[17:17:11:099][Info]Core:linphone: channel [0x7f80bfbe8000] [481] bytes parsed
[17:17:11:099][Info]Core:linphone: transaction [0x6000049adfe0]: starting transaction background task with id=[46].
[17:17:11:099][Info]Core:linphone: Changing [server] [BYE] transaction [0x6000049adfe0], from state [INIT] to [TRYING]
[17:17:11:099][Info]Core:linphone: Changing [server] [BYE] transaction [0x6000049adfe0], from state [TRYING] to [COMPLETED]
[17:17:11:099][Info]Core:linphone: channel [0x7f80bfbe8000]: message sent to [TLS://sip.example.test:5061], size: [547] bytes
SIP/2.0 200 Ok
Via: SIP/2.0/TLS [--ProxyGlobalIPv6--]:5061;branch=z9hG4bK08e1feeb29e981f85a16d7d8471cb47e.0
Via: SIP/2.0/UDP [--ProxyGlobalIPv6_2--]:5060;branch=z9hG4bK00fcc17563454b031b54173674bb640c.Il0RaJR+V35jQGVXyen6lg__
From: <sip:+--redacted_caller--@192.0.2.1>;tag=44f6aab8
To: <sip:+--redacted_callee--@--ProxyGlobalIPv4-->;tag=2wZIVxd
Call-ID: sssvxlBcj7hM7Jd5QJ@sipgt-7d42f1d7
CSeq: 11 BYE
User-Agent: Linphone-Desktop/5.1.2 (MacBook-Pro.local) osx/13.5 Qt/5.15.2 LinphoneSDK/5.2.97
Supported: replaces, outbound, gruu, record-aware
Content-Length: 0

[17:17:11:099][Info]Core:linphone: Dialog [0x600008414000]: now updated by transaction [0x6000049adfe0].
[17:17:11:099][Info]Core:linphone: Dialog [0x600008414000] deleted (is_expired=0)

SDK logs URL

No response

systemcrash commented 1 year ago

Note: the IPv4 192.0.2.1 is a stand-in, redacted valid globally routable IPv4.

Evidently the TLS config handling causes this:

[17:17:10:724][Error]Core:linphone: fast_header_address parser error for ["Paul" <sip:paul@:-1>]
[17:17:10:724][Warning]Core:linphone: Cannot create Address, bad uri ["Paul" <sip:paul@:-1>]
systemcrash commented 1 year ago

Changing from TLS to TCP does not resolve this (TCP has default port 5060 configured):

[17:17:10:724][Error]Core:linphone: fast_header_address parser error for ["Paul" <sip:paul@:-1>]
[17:17:10:724][Warning]Core:linphone: Cannot create Address, bad uri ["Paul" <sip:paul@:-1>]
systemcrash commented 1 year ago

FYI string bug: instanciate a --> instantiate a