Skip to content
Snippets Groups Projects

Incoming call is displayed to user after it has immediately failed (for a few times) / or you hear the call ringing without viewing any notification

    • Open Issue created by Elys @El4

    Update: You can get the call without any noticiation but you'll hear the ringing forever: #999 (comment 45879)

    Update: #999 (comment 44908)

    Always reproduced!

    using newest version of Jami Android 20221107-01 and Jami 202211101600 Windows 10

    I was able to reproduce again (sameuseraccount (Android) -> sameuseraccount (Windows 10)).

    Reproduced if two devices use different networks AND if two devices use the same WLAN

    I think if you make a call useraccount 1 -> useraccount 2 even if the green dot of your own contact in the contact list on Windows 10 is not visible the Android version will still "remember" the call and as soon as the green dot is visible (on Windows 10) the call will succeed.

    EDIT: Maybe you have to make a call successfully before (Android -> Windows 10) and then JUST exit Windows 10 to reproduce.

    EDIT: I think I now know why and how it fails?

    1. Make a call before you can view the green dot of your contact (?)
    2. Make a call shortly before you can view the green dot of your contact (?) / or as soon as you would see the green dot
    3. The other peer should receive the call after ten seconds (but you'll never know)?

    Sometimes you have to exit Jami (just) on the smartphone a couple of times (over 20 times?) to reproduce?

    Just reproduced a couple of times again:

    DISABLE "run in background"

    Steps to reproduce (You actually just have to exit ONE device; NOT BOTH, but I think you have to enable TURN, even if you use the same network) (See: #999 (comment 38603))

    EDIT: I was also able to reproduce Android -> Windows 10 (sameuseraccount -> sameuseraccount); different network

    (The Windows 10 user and the Android user have themselves already in the contact list)

    Steps to reproduce:

    1. Android: Open Jami and keep Jami running (more than 30 seconds)
    2. Now the Windows 10 user opens Jami
    3. As soon as the Windows 10 user opens Jami, (BEFORE the green dot of the Android user is visible on Windows 10) the Android user makes one call (Android -> Windows 10), quickly a second call and maybe you also need a third call - they will all immediately fail
    4. Now wait for a few seconds or even longer (nobody does anything; meanwhile the Windows 10 views the green dot of the Android user)
    5. The Windows 10 user will receive a call (but the Android user will never notice)

    I think you can't reproduce if the green dot is not gone- for example if just the Windows 10 user exits Jami but as soon as he opens Jami again the green dot is already there? In that case I wasn't able to reproduce I think ...

    Android <-> Android

    1. Open Jami and quickly make a first call (maybe even before I can see the green dot ?? (Can't tell because of issue #994 (closed)) - it will immediately fail
    2. Now after a few seconds (or even just one second) make the second call - it will immediately fail
    3. Now wait
    4. Now the Android tablet will receive a call after 10 seconds or more (but the smartphone user will never be able to view the call)

    I had a few possibilities:

    • Sometimes you don't reproduce?
    • Sometimes the other device just gets one call (2 calls failed)
    • Sometimes the other device gets both two calls (2 calls failed)
    • Sometimes you need to make a third call (after a few seconds) and the other device will receive the third call AND the second call

    Option B:

    Another option how to reproduce this issue:

    EDIT: I think I was even able to reproduce even if you make a call after you can view the green dot of the Android contact but BEFORE the green dot of your own account refreshes again.

    1. Just open Jami on Android (never exit; keep Jami running at least 30 seconds; Maybe you've already closed Jami on Windows 10)
    2. Now the Windows 10 user opens Jami
    3. Make a call Android -> Windows 10 (before the Windows 10 user can view the green dot of the Android contact): It will immediately fail
    4. Make a second call Android -> Windows 10 (before the Windows 10 user can view the green dot of the Android contact): It will try to connect; However (just) the Android user now stops the call ("connecting" [although this time it might would work])
    5. Now the Android user makes another call - it will immediately fail (again)
    6. Maybe the Android user makes again another call - immediately fail (Sometimes it it will show "connecting" again and the call might successfully work)
    7. Maybe all peers need to wait a few seconds
    8. Now just the Windows 10 user will receive a call - the Android user will never notice
    Edited

    Designs

    Child items ...

    • Activity

    • Elys
      Elys @El4 ·
      Author

      Maybe also an issue because of the Windows 10 version of Jami

    • Elys mentioned in issue #1083 (closed)

      mentioned in issue #1083 (closed)

    • Elys
      Elys @El4 ·
      Author

      EDIT: Maybe also related to: jami-project#1388 (closed)

    • Elys mentioned in issue jami-project#1388 (closed)

      mentioned in issue jami-project#1388 (closed)

    • Elys
      Elys @El4 ·
      Author

      You might reproduce #976 (closed) if you follow these steps: jami-project#1388 (closed)

      At least previous versions of Jami (Android)?

    • Elys
      Elys @El4 ·
      Author

      Successfully reproduced:

      • Open Jami (Android) and wait ~30 seconds
      • Open Jami (Windows 10) BUT wait ~ 10 or ~15 seconds (nor too short nor too long!!) [after you see the green dot]
      • Windows 10: Now make a video call
      • Windows 10: Outgoing call fails

      HOWEVER:

      • Android: You receive a video call you can answer in video or decline
      • even if you want to answer Android just shows a grey screen (and Windows 10 will never receive the call)

      EDIT: If I start Jami (Windows 10) again I suddenly get this issue: jami-project#1391 (closed) (I see my own user account with the wrong date)

      Edited by Elys
    • Elys
      Elys @El4 ·
      Author

      Also reproduced: Android -> Windows 10

    • Mohamed Chibani marked this issue as related to jami-project#1388 (closed)

      marked this issue as related to jami-project#1388 (closed)

    • Elys
      Elys @El4 ·
      Author

      As mentioned: I reproduced using a "real" Jami account ("sameusername" (Windows 10) <-> "sameusername" (Android) )

      Maybe you can also try the same steps using a SIP account.

    • Elys mentioned in issue jami-client-qt#705 (closed)

      mentioned in issue jami-client-qt#705 (closed)

    • Elys mentioned in issue #1091 (closed)

      mentioned in issue #1091 (closed)

    • Elys mentioned in issue jami-project#442 (closed)

      mentioned in issue jami-project#442 (closed)

    • Mehdi Ghayour added BacklogHigh label

      added BacklogHigh label

    • Mehdi Ghayour added to epic &35 (closed)

      added to epic &35 (closed)

    • Elys mentioned in issue jami-daemon#730 (closed)

      mentioned in issue jami-daemon#730 (closed)

    • Mohamed Chibani marked this issue as related to jami-daemon#730 (closed)

      marked this issue as related to jami-daemon#730 (closed)

    • Sébastien Blin assigned to @sblin

      assigned to @sblin

    • Sébastien Blin added to-check label

      added to-check label

    • Sébastien Blin
      Sébastien Blin @sblin ·
      Owner

      @El4 Hi. I think I know why, but cannot confirm with the info you give:

      Can you retrieve logs of a failed call (or the first one succeeded?)

      (In client-qt, General settings, Troubleshoot, Open logs, and reproduce the issue while the troubleshoot window is opened)?

      I guess the call is taking a relayed address (the connection in the logs will show [relay]), in this case it will be related to jami-daemon#746 (closed)

    • Elys
      Elys @El4 ·
      Author

      Thanks for your answer! I will try in a few minutes / hours again.

      (Just wanted to mention after the merge of the patch issue (jami-daemon#730 (closed)) was only Windows 10 -> Android; I think before both directions had this issue)

      I am not a developer so maybe this does not relate to my issue and is just coincidence.

      Edited by Elys
    • Sébastien Blin
      Sébastien Blin @sblin ·
      Owner

      I think it's platform unrelated, but timing related, so having a device slower than the other may impact (which is generally the case between a desktop and a mobile)

    • Elys
      Elys @El4 ·
      Author

      Strange ... suddenly everything works (however... I got the android update ... but I think in the past in happens randomly so I keep testing)

      At the moment I make calls Jami account 1 -> Jami account 2

      In the past I made calls Jami account 1 <-> Jami account 1

      Does this make a difference?

      I think I was never able to reproduce the following bug (anymore):

      • Open Jami (Android) and wait ~30 seconds
      • Open Jami (Windows 10) BUT wait ~ 10 or ~15 seconds (nor too short nor too long!!) [after you see the green dot]
      • Windows 10: Now make a video call
      • Windows 10: Outgoing call fails
      • Sébastien Blin
        Sébastien Blin @sblin ·
        Owner

        Does this make a difference?

        Yes it can, because the initiator is not the same, so the order of events may change.

        Also, I suppose that your android phone was on a different network (like with mobile data on, wifi off)

        It's cool if everything work, but the real reason is a mystery if we don't have the logs I guess.

      • Elys
        Elys @El4 ·
        Author

        I will try with Jami Account 1 <-> Jami Account 1 again.

        But I remember the logs showed "Sub-call failed". Please have a look at jami-project#1388 (comment 34638)

        This was the error message (Windows 10 client; "sameuseraccount1"<->"sameuseraccount1") I got.

        Now I tried different user accounts. But I reproduced these issues (before the last Android update) jami-project#1388 (comment 36389)

      • Sébastien Blin
        Sébastien Blin @sblin ·
        Owner

        I saw this log, but it's not really usable, it misses all the log before (candidates used, status of the ICE nego). And let's stick to one scenario at a time, I don't even look at the rest yet.

      • Elys
        Elys @El4 ·
        Author

        I already described some related connecting issues here: jami-client-qt#776 (different user accounts "Jami-account 1" -> "Jami account 2")

        However, I will try to reproduce this issue which is a bit difficult because I can't use the logging option of Jami - I am not fast enough to immediately make a call and immediately go to settings -> Logs etc. ... so I have to use the cmd.exe option)

        I will answer as soon as I get this issue and the logs.

      • Elys
        Elys @El4 ·
        Author

        I was able to reproduce this issue (jami-client-qt#776):

        Step 1:

        1. Alice alreads opened the Jami (Android) app so it is running
        2. Bob opens the Jami (Windows 10) app
        3. Bob makes a video call (Windows 10 -> Android) immediately after he sees the green dot of Alice in the contact list (jami-project#1388 (comment 34674))
        4. Bob just sees "Connecting"

        Here are the logs ( I removed my identifier the ID (numbers and words) changed to "Identifier-ID"; my other peers ID was changed to 12345 )

        [1659644184.468|21260|jamiaccount.cpp   :1921 ] [Account 71431662118e9c51] Starting account...
[1659644184.472|21260|jamiaccount.cpp   :1762 ] [Account 71431662118e9c51] Bootstrap node: bootstrap.jami.net
[1659644184.474|16508|jamiaccount.cpp   :2047 ] [Account 71431662118e9c51] Dht status: IPv4 connecting; IPv6 disconnected
[1659644184.475|19944|jamiaccount.cpp   :1782 ] [Account 71431662118e9c51] Track presence for 12345
[1659644184.497|19944|manager.cpp       :2619 ] Set accounts order : 71431662118e9c51/
[1659644184.498|19944|manager.cpp       :1713 ] Saving Configuration to XDG directory C:\Users\TEST\AppData\Local\jami\dring.yml
[1659644184.503|16508|jamiaccount.cpp   :2047 ] [Account 71431662118e9c51] Dht status: IPv4 connected; IPv6 disconnected
[1659644184.504|16508|jamiaccount.cpp   :2479 ] [Account 71431662118e9c51] connected
[1659644184.505|16508|jamiaccount.cpp   :3445 ] [Account 71431662118e9c51] Store DHT public IPv4 address : 77.119.105.240
[1659644184.505|18672|jamiaccount.cpp   :3771 ] [Account 71431662118e9c51] Refresh cache for TURN server resolution
[1659644184.756|18672|jamiaccount.cpp   :3843 ] [Account 71431662118e9c51] Cache refreshed for TURN resolution
[1659644184.934|19944|fileutils.cpp     :164  ] Path expansion not implemented, returning original
[1659644188.414|21260|jamiaccount.cpp   :3885 ] [Account 71431662118e9c51] Request SIP connection to peer 12345 on device 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644188.415|21260|jamiaccount.cpp   :3912 ] [Account 71431662118e9c51] Ask 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8 for a new SIP channel
[1659644188.417|21260|jamiaccount.cpp   :1871 ] Buddy 12345 online
[1659644188.418|16508|jamiaccount.cpp   :3445 ] [Account 71431662118e9c51] Store DHT public IPv4 address : 77.119.105.240
[1659644188.423|16508|ice_transport.cpp :332  ] [ice:000001C8AE74A3B0] Creating IceTransport session for "71431662118e9c51"
[1659644188.428|16508|ice_transport.cpp :408  ] [ice:000001C8AE74A3B0] Initializing the session - comp count 1 - as a slave
[1659644188.429|16508|ice_transport.cpp :446  ] [ice:000001C8AE74A3B0] Add host candidates
[1659644188.431|16508|ice_transport.cpp :910  ] [ice:000001C8AE74A3B0] added host stun config for TCP transport
[1659644188.431|16508|ice_transport.cpp :910  ] [ice:000001C8AE74A3B0] added host stun config for TCP transport
[1659644188.433|16508|ice_transport.cpp :910  ] [ice:000001C8AE74A3B0] added host stun config for TCP transport
[1659644188.433|16508|ice_transport.cpp :995  ] [ice:000001C8AE74A3B0] Add srflx reflexive candidates [192.168.1.2:9 : 77.119.105.240:9] for comp 1
[1659644188.434|16508|ice_transport.cpp :468  ] [ice:000001C8AE74A3B0] Added generic srflx candidates:
[1659644188.436|16508|ice_transport.cpp :322  ] [ice (TCP)] added turn server '51.254.39.157', port 3478
[1659644188.454|16508|jamiaccount.cpp   :2047 ] [Account 71431662118e9c51] Dht status: IPv4 connected; IPv6 connecting
[1659644188.545|14132|ice_transport.cpp :710  ] [ice:000001C8AE74A3B0] TCP initialization success
[1659644188.547|14132|ice_transport.cpp :788  ] [ice:000001C8AE74A3B0] as slave
[1659644188.547|14132|ice_transport.cpp :883  ] [ice:000001C8AE74A3B0] (local) ufrag=16496df1, pwd=5af141bb26e901eb0bb32ea6
[1659644188.549|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706431 192.168.1.2 50593 typ host tcptype passive
[1659644188.550|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706175 192.168.1.2 9 typ host tcptype active
[1659644188.551|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706431 fe80::e97d:ff72:a0f3:3226 50594 typ host tcptype passive
[1659644188.551|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706175 fe80::e97d:ff72:a0f3:3226 9 typ host tcptype active
[1659644188.553|18112|connectionmanager.cpp:305  ] Added local ICE candidate Sc0a80102 1 TCP 1694498303 77.119.105.240 9 typ srflx tcptype active
[1659644188.553|18112|connectionmanager.cpp:305  ] Added local ICE candidate R33fe279d 1 TCP 16777215 51.254.39.157 26605 typ relay tcptype passive
[1659644188.554|18112|connectionmanager.cpp:319  ] [Account 71431662118e9c51] Request connection to 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644190.373|19944|manager.cpp       :1013 ] try outgoing call to 'ring:12345' with account '71431662118e9c51'
[1659644190.375|19944|jamiaccount.cpp   :422  ] [Account 71431662118e9c51] Calling peer 12345
[1659644190.376|19944|sipcall.cpp       :144  ] [call:6292945616133843] Create a new [OUTGOING] SIP call with 2 media
[1659644190.377|19944|audio_rtp_session.cpp:56   ] Created Audio RTP session: 000001C8AD904750 - call Id 6292945616133843
[1659644190.378|19944|ringbuffer.cpp    :55   ] Create new RingBuffer 6292945616133843
[1659644190.378|19944|sipcall.cpp       :1930 ] [call:6292945616133843] Added media @0: type [AUDIO] enabled [YES] muted [NO] label [audio_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.379|19944|video_rtp_session.cpp:72   ] [000001C8AE165A50] Video RTP session created for call 6292945616133843
[1659644190.380|19944|sipcall.cpp       :1930 ] [call:6292945616133843] Added media @1: type [VIDEO] enabled [YES] muted [NO] label [video_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.381|19944|sipcall.cpp       :1933 ] [call:6292945616133843] Created 2 Media streams
[1659644190.382|19944|manager.cpp       :604  ] [1659644190.382|16508|jamiaccount.cpp   :3445 ] ----- Switch current call id to '6292945616133843' -----
[Account 71431662118e9c51] Store DHT public IPv4 address : 77.119.105.240
[1659644190.387|16508|ice_transport.cpp :332  ] [ice:000001C8AE7E24E0] Creating IceTransport session for "6292945616133843"
[1659644190.389|16508|sipcall.cpp       :3136 ] [call:6292945616133843] Successfully created media ICE transport [ice:000001C8AD8E9AB0]
[1659644190.390|16508|sipcall.cpp       :3296 ] [call:6292945616133843] Setting ICE session [000001C8AD8E9AB0]
[1659644190.391|16508|sipcall.cpp       :3156 ] [call:6292945616133843] Init media ICE transport
[1659644190.391|16508|ice_transport.cpp :408  ] [ice:000001C8AE7E24E0] Initializing the session - comp count 4 - as a master
[1659644190.394|16508|ice_transport.cpp :446  ] [ice:000001C8AE7E24E0] Add host candidates
[1659644190.394|16508|ice_transport.cpp :910  ] [ice:000001C8AE7E24E0] added host stun config for UDP transport
[1659644190.395|16508|ice_transport.cpp :910  ] [ice:000001C8AE7E24E0] added host stun config for UDP transport
[1659644190.395|16508|ice_transport.cpp :910  ] [ice:000001C8AE7E24E0] added host stun config for UDP transport
[1659644190.398|16508|ice_transport.cpp :995  ] [ice:000001C8AE7E24E0] Add srflx reflexive candidates [192.168.1.2:22921 : 77.119.105.240:22921] for comp 1
[1659644190.399|16508|ice_transport.cpp :995  ] [ice:000001C8AE7E24E0] Add srflx reflexive candidates [192.168.1.2:22722 : 77.119.105.240:22722] for comp 2
[1659644190.400|16508|ice_transport.cpp :995  ] [ice:000001C8AE7E24E0] Add srflx reflexive candidates [192.168.1.2:22602 : 77.119.105.240:22602] for comp 3
[1659644190.401|16508|ice_transport.cpp :995  ] [ice:000001C8AE7E24E0] Add srflx reflexive candidates [192.168.1.2:22114 : 77.119.105.240:22114] for comp 4
[1659644190.402|16508|ice_transport.cpp :468  ] [ice:000001C8AE7E24E0] Added generic srflx candidates:
[1659644190.402|16508|ice_transport.cpp :322  ] [ice (UDP)] added turn server '51.254.39.157', port 3478
[1659644190.459|16508|jamiaccount.cpp   :461  ] [Account 71431662118e9c51] Calling DHT peer 12345
[1659644190.461|16508|contact_list.cpp  :68   ] Can't set certificate status for existing contacts 12345
[1659644190.462|16508|call.cpp          :245  ] [call:6292945616133843] state change 0/0, cnx 0/1, code 0
[1659644190.463|16508|sipcall.cpp       :144  ] [call:594450073883137] Create a new [OUTGOING] SIP call with 2 media
[1659644190.463|16508|audio_rtp_session.cpp:56   ] Created Audio RTP session: 000001C8AC3CD520 - call Id 594450073883137
[1659644190.464|16508|ringbuffer.cpp    :55   ] Create new RingBuffer 594450073883137
[1659644190.465|16508|sipcall.cpp       :1930 ] [call:594450073883137] Added media @0: type [AUDIO] enabled [YES] muted [NO] label [audio_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.465|16508|video_rtp_session.cpp:72   ] [000001C8AC0E1AB0] Video RTP session created for call 594450073883137
[1659644190.466|16508|sipcall.cpp       :1930 ] [call:594450073883137] Added media @1: type [VIDEO] enabled [YES] muted [NO] label [video_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.467|16508|sipcall.cpp       :1933 ] [call:594450073883137] Created 2 Media streams
[1659644190.467|16508|call.cpp          :451  ] [call:6292945616133843] add subcall 594450073883137
[1659644190.468|16508|sipcall.cpp       :3296 ] [call:594450073883137] Setting ICE session [000001C8AD8E9AB0]
[1659644190.469|16508|sipcall.cpp       :144  ] [call:5549157672164494] Create a new [OUTGOING] SIP call with 2 media
[1659644190.470|16508|audio_rtp_session.cpp:56   ] Created Audio RTP session: 000001C8AC3C63B0 - call Id 5549157672164494
[1659644190.471|16508|ringbuffer.cpp    :55   ] Create new RingBuffer 5549157672164494
[1659644190.471|16508|sipcall.cpp       :1930 ] [call:5549157672164494] Added media @0: type [AUDIO] enabled [YES] muted [NO] label [audio_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.472|16508|video_rtp_session.cpp:72   ] [000001C8AD98E830] Video RTP session created for call 5549157672164494
[1659644190.473|16508|sipcall.cpp       :1930 ] [call:5549157672164494] Added media @1: type [VIDEO] enabled [YES] muted [NO] label [video_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644190.475|16508|sipcall.cpp       :1933 ] [call:5549157672164494] Created 2 Media streams
[1659644190.475|16508|call.cpp          :245  ] [call:5549157672164494] state change 0/0, cnx 0/1, code 0
[1659644190.478|16508|call.cpp          :451  ] [call:6292945616133843] add subcall 5549157672164494
[1659644190.478|16508|sipcall.cpp       :3296 ] [call:5549157672164494] Setting ICE session [000001C8AD8E9AB0]
[1659644190.479|16508|jamiaccount.cpp   :580  ] [call 6292945616133843] No channeled socket with this peer. Send request
[1659644190.480|16508|jamiaccount.cpp   :3885 ] [Account 71431662118e9c51] Request SIP connection to peer 12345 on device 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644190.480|16508|jamiaccount.cpp   :3912 ] [Account 71431662118e9c51] Ask 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8 for a new SIP channel
[1659644190.481|16508|jamiaccount.cpp   :3445 ] [Account 71431662118e9c51] Store DHT public IPv4 address : 77.119.105.240
[1659644190.486|16508|ice_transport.cpp :332  ] [ice:000001C8B1B89B70] Creating IceTransport session for "71431662118e9c51"
[1659644190.487|16508|ice_transport.cpp :408  ] [ice:000001C8B1B89B70] Initializing the session - comp count 1 - as a slave
[1659644190.488|16508|ice_transport.cpp :446  ] [ice:000001C8B1B89B70] Add host candidates
[1659644190.489|16508|ice_transport.cpp :910  ] [ice:000001C8B1B89B70] added host stun config for TCP transport
[1659644190.490|16508|ice_transport.cpp :910  ] [ice:000001C8B1B89B70] added host stun config for TCP transport
[1659644190.490|16508|ice_transport.cpp :910  ] [ice:000001C8B1B89B70] added host stun config for TCP transport
[1659644190.491|16508|ice_transport.cpp :995  ] [ice:000001C8B1B89B70] Add srflx reflexive candidates [192.168.1.2:9 : 77.119.105.240:9] for comp 1
[1659644190.494|16508|ice_transport.cpp :468  ] [ice:000001C8B1B89B70] Added generic srflx candidates:
[1659644190.494|16508|ice_transport.cpp :322  ] [ice (TCP)] added turn server '51.254.39.157', port 3478
[1659644190.524|20116|ice_transport.cpp :710  ] [ice:000001C8AE7E24E0] UDP initialization success
[1659644190.526|20116|ice_transport.cpp :770  ] [ice:000001C8AE7E24E0] as master
[1659644190.526|20116|ice_transport.cpp :883  ] [ice:000001C8AE7E24E0] (local) ufrag=5af141bb, pwd=26e901eb0bb32ea612db153c
[1659644190.605| 2740|ice_transport.cpp :710  ] [ice:000001C8B1B89B70] TCP initialization success
[1659644190.607| 2740|ice_transport.cpp :788  ] [ice:000001C8B1B89B70] as slave
[1659644190.608| 2740|ice_transport.cpp :883  ] [ice:000001C8B1B89B70] (local) ufrag=69525f90, pwd=16496df15af141bb26e901eb
[1659644190.609|17164|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706431 192.168.1.2 50598 typ host tcptype passive
[1659644190.609|17164|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706175 192.168.1.2 9 typ host tcptype active
[1659644190.611|17164|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706431 fe80::e97d:ff72:a0f3:3226 50599 typ host tcptype passive
[1659644190.611|17164|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706175 fe80::e97d:ff72:a0f3:3226 9 typ host tcptype active
[1659644190.612|17164|connectionmanager.cpp:305  ] Added local ICE candidate Sc0a80102 1 TCP 1694498303 77.119.105.240 9 typ srflx tcptype active
[1659644190.613|17164|connectionmanager.cpp:305  ] Added local ICE candidate R33fe279d 1 TCP 16777215 51.254.39.157 13344 typ relay tcptype passive
[1659644190.614|17164|connectionmanager.cpp:319  ] [Account 71431662118e9c51] Request connection to 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644193.953|16508|account_manager.cpp:205  ] announcing device at Identifier-ID
[1659644193.964|16508|archive_account_manager.cpp:525  ] Building device sync from 2ee2818b138cf0718bec822911f77b601f44ac51ba9bf5bad9e7b6df97f7ff2a
[1659644197.086|16508|account_manager.cpp:669  ] Found 1 devices
[1659644214.623|16508|account_manager.cpp:211  ] device announced at Identifier-ID
[1659644218.555|18112|connectionmanager.cpp:336  ] no response from DHT to E2E request.
[1659644218.560|21260|call.cpp          :245  ] [1659644218.560|18672|call.cpp          :245  ] [call:5549157672164494] state change 0/5, cnx 1/0, code 0
[call:594450073883137] state change 0/5, cnx 0/0, code 6
[1659644218.571|21260|ice_transport.cpp :337  ] [ice:000001C8AE74A3B0] destroying 000001C8AE787F98
[1659644219.072|21260|ice_transport.cpp :351  ] [ice:000001C8AE74A3B0] Destroying ice_strans 000001C8AE787F98
[1659644219.077|21260|ice_transport.cpp :669  ] [ice:000001C8AE74A3B0] Timer heap flushed after 0 ms
[1659644219.081|21260|ice_transport.cpp :383  ] [ice:000001C8AE74A3B0] done destroying
[1659644219.089|21260|call.cpp          :523  ] [call:6292945616133843] subcall 5549157672164494 failed
[1659644219.095|21260|call.cpp          :546  ] [call:6292945616133843] remains 1 subcall(s)
[1659644219.105|21260|manager.cpp       :2026 ] [call:5549157672164494] Sub-call failed
[1659644219.112|21260|manager.cpp       :1650 ] [call:5549157672164494] Remove local audio
[1659644219.116|21260|ringbufferpool.cpp:262  ] Unbind call 5549157672164494 from all bound calls
[1659644219.121|21260|sipcall.cpp       :1512 ] [call:5549157672164494] removeCall()
[1659644219.132|21260|call_factory.cpp  :72   ] Removing call 5549157672164494
[1659644219.144|21260|call_factory.cpp  :75   ] Remaining 2 call
[1659644219.147|21260|call.cpp          :245  ] [call:5549157672164494] state change 5/6, cnx 0/0, code 0
[1659644219.161|21260|audio_rtp_session.cpp:218  ] [000001C8AC3C63B0] Stopping receiver
[1659644219.179|21260|audio_rtp_session.cpp:65   ] Destroyed Audio RTP session: 000001C8AC3C63B0 - call Id 5549157672164494
[1659644219.194|21260|ringbuffer.cpp    :60   ] Destroy RingBuffer 5549157672164494
[1659644219.197|21260|video_rtp_session.cpp:227  ] [000001C8AD98E830] Stop video RTP sender: input [] - muted [NO]
[1659644219.203|21260|video_rtp_session.cpp:292  ] [000001C8AD98E830] Stopping receiver
[1659644219.205|21260|video_rtp_session.cpp:78   ] [000001C8AD98E830] Video RTP session destroyed
[1659644219.207|21260|call.cpp          :523  ] [call:6292945616133843] subcall 594450073883137 failed
[1659644219.209|21260|call.cpp          :245  ] [call:6292945616133843] state change 0/5, cnx 1/0, code 5
[1659644219.211|21260|call.cpp          :276  ] [call:6292945616133843] emit client call state change FAILURE, code 5
[1659644219.215|21260|sipcall.cpp       :1512 ] [call:6292945616133843] removeCall()
[1659644219.219|21260|call_factory.cpp  :72   ] Removing call 6292945616133843
[1659644219.221|21260|call_factory.cpp  :75   ] Remaining 1 call
[1659644219.222|21260|call.cpp          :245  ] [call:6292945616133843] state change 5/6, cnx 0/0, code 0
[1659644219.223|21260|sipcall.cpp       :3064 ] - Call 6292945616133843 with 12345@ring.dht:
[1659644219.225|21260|sipcall.cpp       :3065 ]         - Duration: 0 us
[1659644219.226|21260|sipcall.cpp       :3067 ]         - Media: type [AUDIO] enabled [YES] muted [NO] label [audio_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644219.231|21260|sipcall.cpp       :3067 ]         - Media: type [VIDEO] enabled [YES] muted [NO] label [video_0] source [camera://video=@device_pnp_\\?\root#image#0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global] secure [YES]
[1659644219.236|21260|call.cpp          :276  ] [call:6292945616133843] emit client call state change OVER, code 0
[1659644219.237|21260|manager.cpp       :2026 ] [call:594450073883137] Sub-call failed
[1659644219.239|21260|manager.cpp       :1650 ] [call:594450073883137] Remove local audio
[1659644219.240|21260|ringbufferpool.cpp:262  ] Unbind call 594450073883137 from all bound calls
[1659644219.241|21260|sipcall.cpp       :1512 ] [call:594450073883137] removeCall()
[1659644219.244|21260|call_factory.cpp  :72   ] Removing call 594450073883137
[1659644219.245|21260|call_factory.cpp  :75   ] Remaining 0 call
[1659644219.246|21260|call.cpp          :245  ] [call:594450073883137] state change 5/6, cnx 0/0, code 0
[1659644219.247|21260|audio_rtp_session.cpp:218  ] [1659644219.247|18672|ice_transport.cpp :337  ] [000001C8AC3CD520] Stopping receiver
[ice:000001C8AE7E24E0] destroying 000001C8B1A53068
[1659644219.253|21260|audio_rtp_session.cpp:65   ] Destroyed Audio RTP session: 000001C8AC3CD520 - call Id 594450073883137
[1659644219.255|21260|ringbuffer.cpp    :60   ] Destroy RingBuffer 594450073883137
[1659644219.256|21260|video_rtp_session.cpp:227  ] [000001C8AC0E1AB0] Stop video RTP sender: input [] - muted [NO]
[1659644219.257|21260|video_rtp_session.cpp:292  ] [000001C8AC0E1AB0] Stopping receiver
[1659644219.257|21260|video_rtp_session.cpp:78   ] [000001C8AC0E1AB0] Video RTP session destroyed
[1659644219.258|21260|audio_rtp_session.cpp:218  ] [000001C8AD904750] Stopping receiver
[1659644219.260|18112|conversationrepository.cpp:1685 ] New message added with id: d1a8a90e13c56b1ef2cb81f23f1fc8e2d05c8cb3
[1659644219.261|21260|audio_rtp_session.cpp:65   ] Destroyed Audio RTP session: 000001C8AD904750 - call Id 6292945616133843
[1659644219.264|21260|ringbuffer.cpp    :60   ] Destroy RingBuffer 6292945616133843
[1659644219.269|21260|video_rtp_session.cpp:227  ] [000001C8AE165A50] Stop video RTP sender: input [] - muted [NO]
[1659644219.269|21260|video_rtp_session.cpp:292  ] [000001C8AE165A50] Stopping receiver
[1659644219.271|21260|video_rtp_session.cpp:78   ] [000001C8AE165A50] Video RTP session destroyed
[1659644219.272|21260|message_engine.cpp:103  ] [message 2358460327498433] Retry sending
[1659644219.272|21140|message_engine.cpp:324  ] [Account 71431662118e9c51] saved 1 messages to C:\Users\TEST\.cache\jami\71431662118e9c51\messages
[1659644219.272|21260|message_engine.cpp:103  ] [message 1397106197659210] Retry sending
[1659644219.276|16508|jamiaccount.cpp   :3885 ] [Account 71431662118e9c51] Request SIP connection to peer 12345 on device 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644219.277|16508|jamiaccount.cpp   :3912 ] [Account 71431662118e9c51] Ask 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8 for a new SIP channel
[1659644219.277| 6620|message_engine.cpp:324  ] [Account 71431662118e9c51] saved 2 messages to C:\Users\TEST\.cache\jami\71431662118e9c51\messages
[1659644219.279|16508|jamiaccount.cpp   :3358 ] [Account 71431662118e9c51] [message 1397106197659210] Sending message for device 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644219.282|16508|jamiaccount.cpp   :3445 ] [Account 71431662118e9c51] Store DHT public IPv4 address : 77.119.105.240
[1659644219.287|16508|ice_transport.cpp :332  ] [ice:000001C8AE4EF700] Creating IceTransport session for "71431662118e9c51"
[1659644219.288|16508|ice_transport.cpp :408  ] [ice:000001C8AE4EF700] Initializing the session - comp count 1 - as a slave
[1659644219.290|16508|ice_transport.cpp :446  ] [ice:000001C8AE4EF700] Add host candidates
[1659644219.292|16508|ice_transport.cpp :910  ] [ice:000001C8AE4EF700] added host stun config for TCP transport
[1659644219.294|16508|ice_transport.cpp :910  ] [ice:000001C8AE4EF700] added host stun config for TCP transport
[1659644219.294|16508|ice_transport.cpp :910  ] [ice:000001C8AE4EF700] added host stun config for TCP transport
[1659644219.295|16508|ice_transport.cpp :995  ] [ice:000001C8AE4EF700] Add srflx reflexive candidates [192.168.1.2:9 : 77.119.105.240:9] for comp 1
[1659644219.297|16508|ice_transport.cpp :468  ] [ice:000001C8AE4EF700] Added generic srflx candidates:
[1659644219.298|16508|ice_transport.cpp :322  ] [ice (TCP)] added turn server '51.254.39.157', port 3478
[1659644219.400|21428|ice_transport.cpp :710  ] [ice:000001C8AE4EF700] TCP initialization success
[1659644219.401|21428|ice_transport.cpp :788  ] [ice:000001C8AE4EF700] as slave
[1659644219.402|21428|ice_transport.cpp :883  ] [ice:000001C8AE4EF700] (local) ufrag=69525f90, pwd=16496df15af141bb26e901eb
[1659644219.404|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706431 192.168.1.2 50631 typ host tcptype passive
[1659644219.406|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hc0a80102 1 TCP 2130706175 192.168.1.2 9 typ host tcptype active
[1659644219.407|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706431 fe80::e97d:ff72:a0f3:3226 50632 typ host tcptype passive
[1659644219.408|18112|connectionmanager.cpp:305  ] Added local ICE candidate Hb9cb0f80 1 TCP 2130706175 fe80::e97d:ff72:a0f3:3226 9 typ host tcptype active
[1659644219.410|18112|connectionmanager.cpp:305  ] Added local ICE candidate Sc0a80102 1 TCP 1694498303 77.119.105.240 9 typ srflx tcptype active
[1659644219.410|18112|connectionmanager.cpp:305  ] Added local ICE candidate R33fe279d 1 TCP 16777215 51.254.39.157 17773 typ relay tcptype passive
[1659644219.412|18112|connectionmanager.cpp:319  ] [Account 71431662118e9c51] Request connection to 969394fb5e33f738db2b1d825f0cbf3cd7066a25cd2c068cd662ed8c676273a8
[1659644219.622|18672|ice_transport.cpp :351  ] [ice:000001C8AE7E24E0] Destroying ice_strans 000001C8B1A53068
[1659644219.623|18672|ice_transport.cpp :669  ] [ice:000001C8AE7E24E0] Timer heap flushed after 0 ms
[1659644219.624|18672|ice_transport.cpp :383  ] [ice:000001C8AE7E24E0] done destroying
[1659644220.623|17164|connectionmanager.cpp:336  ] no response from DHT to E2E request.
[1659644220.628|21260|ice_transport.cpp :337  ] [ice:000001C8B1B89B70] destroying 000001C8B1CB2D28
[1659644221.115|21260|ice_transport.cpp :351  ] [ice:000001C8B1B89B70] Destroying ice_strans 000001C8B1CB2D28
[1659644221.126|21260|ice_transport.cpp :669  ] [ice:000001C8B1B89B70] Timer heap flushed after 0 ms
[1659644221.129|21260|ice_transport.cpp :383  ] [ice:000001C8B1B89B70] done destroying
[1659644249.415|18112|connectionmanager.cpp:336  ] no response from DHT to E2E request.
[1659644249.418|21260|ice_transport.cpp :337  ] [ice:000001C8AE4EF700] destroying 000001C8AE82C038
[1659644249.929|21260|ice_transport.cpp :351  ] [ice:000001C8AE4EF700] Destroying ice_strans 000001C8AE82C038
[1659644249.931|21260|ice_transport.cpp :669  ] [ice:000001C8AE4EF700] Timer heap flushed after 0 ms
[1659644249.932|21260|ice_transport.cpp :383  ] [ice:000001C8AE4EF700] done destroying
[1659644250.766|16508|jamiaccount.cpp   :3340 ] [Account 71431662118e9c51] [message 1397106197659210] Put encrypted ok
[1659644259.924|16508|account_manager.cpp:669  ] Found 1 devices
[1659644259.927|16508|message_engine.cpp:154  ] [message 2358460327498433] Message sent: success
[1659644259.933|16508|message_engine.cpp:168  ] [message 2358460327498433] Status changed to SENT
[1659644259.936| 2520|message_engine.cpp:324  ] [Account 71431662118e9c51] saved 2 messages to C:\Users\Test\.cache\jami\71431662118e9c51\messages
[1659644269.025|16508|account_manager.cpp:669  ] Found 1 devices
[1659644279.285|21260|jamiaccount.cpp   :3383 ] [Account 71431662118e9c51] [message 1397106197659210] Timeout
[1659644279.286|21260|message_engine.cpp:154  ] [message 1397106197659210] Message sent: failure
[1659644279.288|21260|message_engine.cpp:190  ] [message 1397106197659210] Status changed to IDLE
[1659644345.438|16508|jamiaccount.cpp   :2047 ] [Account 71431662118e9c51] Dht status: IPv4 connected; IPv6 disconnected
[1659644398.530|16508|jamiaccount.cpp   :2047 ] [Account 71431662118e9c51] Dht status: IPv4 connected; IPv6 connecting
        Edited by Elys
      • Sébastien Blin
        Sébastien Blin @sblin ·
        Owner

        Ok, so it's not related to the scenario I got. you just have no response from DHT (ideally logs from the other side in this specific case will be better)

        So not related to the work I did today

      • Sébastien Blin
        Sébastien Blin @sblin ·
        Owner

        However, I will try to reproduce this issue which is a bit difficult because I can't use the logging option of Jami - I am not fast enough to immediately make a call and immediately go to settings -> Logs etc. ... so I have to use the cmd.exe option)

        jami-qt.exe -f <file> will retrieve logs from the beginning

      • Elys
        Elys @El4 ·
        Author

        But why does it always work if I wait 30 seconds (or more)? I never have any connectivity issues if I wait more than 30 seconds?

        Just reproduced jami-client-qt#776 (comment 36507) if you open Jami very shortly after you opened the Windows 10 client (but nearly all at the same time).

        Shall I continue at jami-client-qt#776 (comment 36507) ?

        Edited by Elys
      • Sébastien Blin
        Sébastien Blin @sblin ·
        Owner

        because the presence is announced I guess or any other timing issue. Hard to answer without knowing the reason for sure

      • Elys
        Elys @El4 ·
        Author

        I will try to reproduce this bug tomorrow using sameaccount <-> sameaccount.

        So I try all issues of the other topic and get the logs (both sides).

      • Elys
        Elys @El4 ·
        Author

        Just reproduced (nearly?) the same issue using Android - Android (and "sameuseraccount" -"sameuseraccount")

        EDIT: All contacts are already in the contact list you NEVER add a contact first

        both devices same WiFi

        I actually had to make two calls:

        1. The first call will fail (I have to guess when the green dot is visible because of issue #994 (closed))
        2. Now make second call (after a few seconds). It will also fail.
        3. Now wait ~30 seconds or more (no user writes messages/makes another call ... so do NOTHING)
        4. Suddenly just one user will receive a call - The other user will never know
        Edited by Elys
      • Elys
        Elys @El4 ·
        Author

        I just was able to reproduce:

        I used the same network (WLAN of the router; internet enabled!) for both devices

        I made a call sameuseraccount (Mate 20 Pro; EMUI 12) → sameuseraccount (Tablet Android 8.1 Oreo)

        I only need to exit Jami on the smartphone (I keep Jami on the Android tablet running and DON'T exit)

        But I think I was only able to reproduce if I enabled turn. (Although same network so I don't need turn)

        Steps to reproduce (Android Tablet keeps always running and Jami is open):

        Mate 20 Pro:

        1. Open Jami and quickly make a first call (maybe even before I can see the green dot ?? (Can't tell because of issue #994 (closed)) - it will immediately fail
        2. Now after a few seconds (or even just one second) make the second call - it will immediately fail
        3. Now wait
        4. Now the Android tablet will receive a call after 10 seconds or more (but the smartphone user will never be able to view the call)
        Edited by Elys
      • Elys
        Elys @El4 ·
        Author

        The next time I was not able to reproduce

        This time I just exit Jami on the Android tablet

        1. I make a call sameuseraccount (Mate 20 Pro; EMUI 12) → sameuseraccount (Tablet Android 8.1 Oreo) as soon as I open Jami on the Android tablet
        2. Sometimes I can have the first (two) calls fail
        3. If I make a third call I receive the call AND another previously call at the same time?

        EDIT: Just reproduced again (steps #999 (comment 38603)) but this time I got BOTH failed calls (call 1 + 2)

        Edited by Elys
      • Please register or sign in to reply
    • Sébastien Blin removed to-check label

      removed to-check label

    • Sébastien Blin removed BacklogHigh label

      removed BacklogHigh label

    • Sébastien Blin added BacklogMedium label

      added BacklogMedium label

    • Elys
      Elys @El4 ·
      Author

      I think I found no differences between "sameuseraccount"(Windows 10) -> "sameuseraccount"(Android) and different useraccounts ... but I'll keep testing

    • Elys mentioned in issue jami-client-qt#776

      mentioned in issue jami-client-qt#776

    • Elys changed title from Android: Outgoing call fails but after a few seconds you receive the call (Windows 10) to Android: Outgoing call fails but after a few seconds you receive the call

      changed title from Android: Outgoing call fails but after a few seconds you receive the call (Windows 10) to Android: Outgoing call fails but after a few seconds you receive the call

    • Elys changed the description

      changed the description

    • Elys mentioned in issue jami-daemon#781 (closed)

      mentioned in issue jami-daemon#781 (closed)

    • Sébastien Blin added non-reproducible label

      added non-reproducible label

    • Sébastien Blin removed from epic &35 (closed)

      removed from epic &35 (closed)

    • Sébastien Blin unassigned @sblin

      unassigned @sblin

    • Sébastien Blin removed BacklogMedium label

      removed BacklogMedium label

    • Elys changed title from Android: Outgoing call fails but after a few seconds you receive the call to Android: Outgoing call fails but after a few seconds you receive the call (turn enabled?) Version 20220906-01

      changed title from Android: Outgoing call fails but after a few seconds you receive the call to Android: Outgoing call fails but after a few seconds you receive the call (turn enabled?) Version 20220906-01

    • Elys changed the description

      changed the description

    • Elys changed the description

      changed the description

    • Elys mentioned in issue #1141 (closed)

      mentioned in issue #1141 (closed)

    • Elys changed the description

      changed the description

    • Elys
      Elys @El4 ·
      Author

      I was able to reproduce a similar/the same issue (Windows 10 -> Android; useraccount1 -> useraccount2) if you start Jami (Android) and immediately make a few video calls BEFORE the Windows 10 user can view the green dot: Jami (Windows 10) will stuck in "Searching" ... and the call won't immediately fail?

      I will keep testing.

      Edited by Elys
    • Elys changed title from Android: Outgoing call fails but after a few seconds you receive the call (turn enabled?) Version 20220906-01 to Android: Outgoing call fails but after a few seconds you receive the call (sameuseraccount -> sameuseraccount)

      changed title from Android: Outgoing call fails but after a few seconds you receive the call (turn enabled?) Version 20220906-01 to Android: Outgoing call fails but after a few seconds you receive the call (sameuseraccount -> sameuseraccount)

    • Elys changed the description

      changed the description

    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    • Loading
    Please register or sign in to reply