Zulu 3 issues from outside the LAN


(Jared Busch) #1

I have never done any troubleshooting with Zulu yet as on my PBX (FreePBX 14 hosted on Vultr), it simply works. But, I have a client that setup the free 2 user license to test Zulu as their work from home solution and it is not working right.

Their PBX is on-prem. When on the same LAN (iPhone on WiFi network on the flat LAN) everything works perfectly. So we know Zulu itself is installed and working normally. Great.

But when wifi is turned off and the local person uses cellular, or if I try from my office in Chicagoland, we get an error.

The Zulu app connects. you can attempt to call. It also rings on an incoming call. but it fails after that.

Their router has the appropriate NAT rules in place for their SIP trunk. Those are restricted to their provider’s IP. Port 8002 and 443 were opened to the public and routed in so that WebRTC UCP was accessible. During testing we also simply opened any port and protocols through the router to the PBX, but it made no difference in the behaviour.

Here is the log from a call on my iPhone while on my home office WiFi.

{
    "2020-03-20T16:12:11.118Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - actions/sipaccount - makeCall - Init makeCall",
    "2020-03-20T16:12:11.125Z": "Actions - sipaccount - shouldCallCancel - de0b8d32-e781-4932-baf4-440e0a7684c7 - ",
    "2020-03-20T16:12:11.126Z": "SIPAccount(Lib) - _ua.start, Transport connected/status is: - false - 3",
    "2020-03-20T16:12:11.127Z": "SIPAccount(Lib) - _ua.start, UA registered/status is : - false - 3",
    "2020-03-20T16:12:11.128Z": "WebRTC(log) - resuming",
    "2020-03-20T16:12:11.129Z": "SIPAccount(Lib) - TRANSPORT - onTransportConnecting",
    "2020-03-20T16:12:11.130Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPAccount - _onConnecting - Exec onConnecting",
    "2020-03-20T16:12:11.131Z": "WebRTC(log) - connecting to WebSocket wss://freepbx18.bihler.com:8002/ws",
    "2020-03-20T16:12:11.132Z": "SIPAccount(Lib) - startCallFlow - init - false",
    "2020-03-20T16:12:11.153Z": "actions/sipaccount - shouldCallCancel - false",
    "2020-03-20T16:12:11.248Z": "SIPAccount(Lib) - _didReceiveStartCallAction - {\"callUUID\":\"64c8d9bd-31d3-46dc-aabe-6a4e67aed21a\",\"handle\":\"1327\"}",
    "2020-03-20T16:12:11.258Z": "SIPAccount(Lib) - _ua.invite, Transport connected/status is : - false - 0",
    "2020-03-20T16:12:11.264Z": "SIPAccount(Lib) - _ua.invite, UA registered/status is : - false - 2",
    "2020-03-20T16:12:12.280Z": "WebRTC(log) - Attempting to transition status from 0 to 1",
    "2020-03-20T16:12:12.288Z": "SIPAccount(Lib) - TRANSPORT - onTransportConnected",
    "2020-03-20T16:12:12.292Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPAccount - _onConnected - Exec onConnected",
    "2020-03-20T16:12:12.296Z": "WebRTC(log) - WebSocket wss://freepbx18.bihler.com:8002/ws connected",
    "2020-03-20T16:12:12.299Z": "WebRTC(log) - Constructing non-INVITE client transaction with id z9hG4bK3684122.",
    "2020-03-20T16:12:12.301Z": "initPeerConnection",
    "2020-03-20T16:12:12.303Z": "Using onaddstream which is deprecated",
    "2020-03-20T16:12:12.305Z": "acquiring local media",
    "2020-03-20T16:12:12.310Z": "WebRTC.mediaDevices.enumerateDevices - [{\"groupId\":\"\",\"facing\":\"environment\",\"deviceId\":\"com.apple.avfoundation.avcapturedevice.built-in_video:0\",\"label\":\"Back Camera\",\"kind\":\"videoinput\"},{\"groupId\":\"\",\"facing\":\"front\",\"deviceId\":\"com.apple.avfoundation.avcapturedevice.built-in_video:1\",\"label\":\"Front Camera\",\"kind\":\"videoinput\"},{\"groupId\":\"\",\"deviceId\":\"com.apple.avfoundation.avcapturedevice.built-in_audio:0\",\"label\":\"iPhone Microphone\",\"kind\":\"audioinput\"}]",
    "2020-03-20T16:12:12.313Z": "acquired local media streams",
    "2020-03-20T16:12:12.315Z": "acquire - addStreams DONE",
    "2020-03-20T16:12:12.320Z": "isIceGatheringComplete STATE: - new - TimeOut: - false",
    "2020-03-20T16:12:12.332Z": "RTCIceGatheringState changed: gathering",
    "2020-03-20T16:12:12.333Z": "RTCIceChecking Timeout Created, value: 1500 milliseconds",
    "2020-03-20T16:12:12.334Z": "ICE candidate received: candidate:829193555 1 udp 2122260223 10.254.103.179 63203 typ host generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.335Z": "ICE candidate received: candidate:2340043163 1 udp 2122131711 2607:fc20:762a:503c:8035:1724:8018:3581 63205 typ host generation 0 ufrag BJ6j network-id 15 network-cost 900",
    "2020-03-20T16:12:12.336Z": "ICE candidate received: candidate:1103813564 1 udp 2122003199 fd74:6572:6d6e:7573:c:b27d:e9de:8306 52042 typ host generation 0 ufrag BJ6j network-id 3 network-cost 50",
    "2020-03-20T16:12:12.337Z": "ICE candidate received: candidate:200560887 1 udp 2121872127 fd74:6572:6d6e:7573:d:b27d:e9de:8306 52044 typ host generation 0 ufrag BJ6j network-id 6 network-cost 50",
    "2020-03-20T16:12:12.338Z": "ICE candidate received: candidate:2486661909 1 udp 2121539327 10.254.254.254 58638 typ host generation 0 ufrag BJ6j network-id 5 network-cost 50",
    "2020-03-20T16:12:12.339Z": "ICE candidate received: candidate:829193555 2 udp 2122260222 10.254.103.179 57089 typ host generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.340Z": "ICE candidate received: candidate:2340043163 2 udp 2122131710 2607:fc20:762a:503c:8035:1724:8018:3581 57091 typ host generation 0 ufrag BJ6j network-id 15 network-cost 900",
    "2020-03-20T16:12:12.341Z": "ICE candidate received: candidate:1103813564 2 udp 2122003198 fd74:6572:6d6e:7573:c:b27d:e9de:8306 58726 typ host generation 0 ufrag BJ6j network-id 3 network-cost 50",
    "2020-03-20T16:12:12.342Z": "ICE candidate received: candidate:200560887 2 udp 2121937662 fd74:6572:6d6e:7573:d:b27d:e9de:8306 58727 typ host generation 0 ufrag BJ6j network-id 4 network-cost 50",
    "2020-03-20T16:12:12.343Z": "ICE candidate received: candidate:2486661909 2 udp 2121539326 10.254.254.254 63864 typ host generation 0 ufrag BJ6j network-id 5 network-cost 50",
    "2020-03-20T16:12:12.344Z": "ICE candidate received: candidate:2486661909 2 udp 2121473790 10.254.254.254 53046 typ host generation 0 ufrag BJ6j network-id 9 network-cost 50",
    "2020-03-20T16:12:12.401Z": "WebRTC(log) - State change to \"Completed\" on non-INVITE client transaction with id z9hG4bK3684122.",
    "2020-03-20T16:12:12.407Z": "WebRTC(log) - Constructing non-INVITE client transaction with id z9hG4bK9798586.",
    "2020-03-20T16:12:12.408Z": "WebRTC(log) - Destroyed non-INVITE client transaction with id z9hG4bK3684122.",
    "2020-03-20T16:12:12.409Z": "ICE candidate received: candidate:4259398336 1 udp 1686052607 64.53.199.99 63203 typ srflx raddr 10.254.103.179 rport 63203 generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.410Z": "ICE candidate received: candidate:4259398336 2 udp 1686052606 64.53.199.99 57089 typ srflx raddr 10.254.103.179 rport 57089 generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.429Z": "ICE candidate received: candidate:2146402723 1 tcp 1518280447 10.254.103.179 59691 typ host tcptype passive generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.430Z": "ICE candidate received: candidate:3321480555 1 tcp 1518151935 2607:fc20:762a:503c:8035:1724:8018:3581 59693 typ host tcptype passive generation 0 ufrag BJ6j network-id 15 network-cost 900",
    "2020-03-20T16:12:12.431Z": "ICE candidate received: candidate:1165470727 1 tcp 1517957887 fd74:6572:6d6e:7573:d:b27d:e9de:8306 59696 typ host tcptype passive generation 0 ufrag BJ6j network-id 4 network-cost 50",
    "2020-03-20T16:12:12.432Z": "ICE candidate received: candidate:3669266405 1 tcp 1517559551 10.254.254.254 59698 typ host tcptype passive generation 0 ufrag BJ6j network-id 5 network-cost 50",
    "2020-03-20T16:12:12.433Z": "ICE candidate received: candidate:2146402723 2 tcp 1518280446 10.254.103.179 59700 typ host tcptype passive generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.434Z": "ICE candidate received: candidate:3321480555 2 tcp 1518151934 2607:fc20:762a:503c:8035:1724:8018:3581 59702 typ host tcptype passive generation 0 ufrag BJ6j network-id 15 network-cost 900",
    "2020-03-20T16:12:12.435Z": "ICE candidate received: candidate:256452428 2 tcp 1518023422 fd74:6572:6d6e:7573:c:b27d:e9de:8306 59704 typ host tcptype passive generation 0 ufrag BJ6j network-id 3 network-cost 50",
    "2020-03-20T16:12:12.436Z": "ICE candidate received: candidate:1165470727 2 tcp 1517892350 fd74:6572:6d6e:7573:d:b27d:e9de:8306 59706 typ host tcptype passive generation 0 ufrag BJ6j network-id 6 network-cost 50",
    "2020-03-20T16:12:12.437Z": "ICE candidate received: candidate:3669266405 2 tcp 1517494014 10.254.254.254 59708 typ host tcptype passive generation 0 ufrag BJ6j network-id 9 network-cost 50",
    "2020-03-20T16:12:12.489Z": "WebRTC(log) - State change to \"Completed\" on non-INVITE client transaction with id z9hG4bK9798586.",
    "2020-03-20T16:12:12.490Z": "SIPAccount - _onRegistered - Exec onRegistered",
    "2020-03-20T16:12:12.537Z": "WebRTC(log) - Constructing non-INVITE server transaction with id z9hG4bKPj4d940283-41a1-422b-907a-6ff2263b1f14.",
    "2020-03-20T16:12:12.538Z": "WebRTC(log) - State change to \"Terminated\" on non-INVITE server transaction with id z9hG4bKPj4d940283-41a1-422b-907a-6ff2263b1f14.",
    "2020-03-20T16:12:12.539Z": "WebRTC(log) - Destroyed non-INVITE server transaction with id z9hG4bKPj4d940283-41a1-422b-907a-6ff2263b1f14.",
    "2020-03-20T16:12:12.562Z": "ICE candidate received: candidate:3717173733 2 udp 1685855998 172.58.140.19 25513 typ srflx raddr 192.0.0.1 rport 58725 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.563Z": "ICE candidate received: candidate:3717173733 1 udp 1685855999 172.58.140.19 27753 typ srflx raddr 192.0.0.1 rport 52041 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.582Z": "ICE candidate received: candidate:3717173733 2 udp 1685855998 172.58.140.19 57391 typ srflx raddr 192.0.0.1 rport 58725 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.590Z": "ICE candidate received: candidate:3717173733 1 udp 1685855999 172.58.140.19 34653 typ srflx raddr 192.0.0.1 rport 52041 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.598Z": "ICE candidate received: candidate:2888541 2 udp 41885694 54.183.230.120 59373 typ relay raddr 64.53.199.99 rport 57089 generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.652Z": "ICE candidate received: candidate:1320153005 2 udp 25108222 54.183.230.120 64219 typ relay raddr 64.53.199.99 rport 59688 generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.654Z": "ICE candidate received: candidate:1320153005 1 udp 25108223 54.183.230.120 57187 typ relay raddr 64.53.199.99 rport 59686 generation 0 ufrag BJ6j network-id 1 network-cost 10",
    "2020-03-20T16:12:12.690Z": "ICE candidate received: candidate:2888541 2 udp 41689086 54.183.230.120 49324 typ relay raddr 172.58.140.19 rport 57391 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.698Z": "ICE candidate received: candidate:2888541 1 udp 41689087 54.183.230.120 58944 typ relay raddr 172.58.140.19 rport 34653 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.791Z": "ICE candidate received: candidate:1320153005 2 udp 24911614 54.183.230.120 61859 typ relay raddr 172.58.140.19 rport 48005 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:12.826Z": "ICE candidate received: candidate:1320153005 1 udp 24911615 54.183.230.120 63530 typ relay raddr 172.58.140.19 rport 48141 generation 0 ufrag BJ6j network-id 13 network-cost 900",
    "2020-03-20T16:12:13.838Z": "RTCIceChecking Timeout Triggered after 1500 milliseconds",
    "2020-03-20T16:12:13.846Z": "isIceGatheringComplete STATE: - gathering - TimeOut: - true",
    "2020-03-20T16:12:13.849Z": "triggerIceGatheringComplete is: true",
    "2020-03-20T16:12:13.851Z": "isIceGatheringComplete STATE: - gathering - TimeOut: - true",
    "2020-03-20T16:12:13.854Z": "NEW offer created",
    "2020-03-20T16:12:13.861Z": "WebRTC(log) - Constructing INVITE client transaction with id z9hG4bK1456406.",
    "2020-03-20T16:12:14.210Z": "WebRTC(log) - State change to \"Completed\" on INVITE client transaction with id z9hG4bK1456406.",
    "2020-03-20T16:12:14.212Z": "WebRTC(log) - Constructing INVITE client transaction with id z9hG4bK2040962.",
    "2020-03-20T16:12:14.214Z": "WebRTC(log) - Timer D expired for INVITE client transaction z9hG4bK1456406.",
    "2020-03-20T16:12:14.215Z": "WebRTC(log) - State change to \"Terminated\" on INVITE client transaction with id z9hG4bK1456406.",
    "2020-03-20T16:12:14.366Z": "WebRTC(log) - State change to \"Proceeding\" on INVITE client transaction with id z9hG4bK2040962.",
    "2020-03-20T16:12:14.367Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onProgress - Init onProgress",
    "2020-03-20T16:12:15.004Z": "WebRTC(log) - INVITE dialog sli88tt9psijsgn2n0u4i50tb2ufth3141b8d5-fd7a-42a2-a2ec-582389ba8204 constructed",
    "2020-03-20T16:12:15.008Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onProgress180 - Activating ringback",
    "2020-03-20T16:12:15.046Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onProgress180 - Activating ringback",
    "2020-03-20T16:12:17.745Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - PBXAccount - _onOtherConnection - ",
    "2020-03-20T16:12:19.953Z": "WebRTC(log) - State change to \"Accepted\" on INVITE client transaction with id z9hG4bK2040962.",
    "2020-03-20T16:12:19.969Z": "RTCIceConnectionStatechanged: checking",
    "2020-03-20T16:12:19.970Z": "stream added",
    "2020-03-20T16:12:19.971Z": "WebRTC(log) - INVITE dialog sli88tt9psijsgn2n0u4i50tb2ufth3141b8d5-fd7a-42a2-a2ec-582389ba8204 sending ACK request",
    "2020-03-20T16:12:19.973Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onAccepted - Stopping ringback",
    "2020-03-20T16:12:19.974Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onAccepted - Exec onSessionAccept",
    "2020-03-20T16:12:20.159Z": "WebRTC(log) - INVITE dialog sli88tt9psijsgn2n0u4i50tb2ufth3141b8d5-fd7a-42a2-a2ec-582389ba8204 received INVITE request",
    "2020-03-20T16:12:20.160Z": "WebRTC(log) - re-INVITE received",
    "2020-03-20T16:12:20.168Z": "{\"name\":\"SetRemoteDescriptionFailed\",\"message\":\"Failed to set remote offer sdp: Called with SDP without ice-ufrag and ice-pwd.\"}",
    "2020-03-20T16:12:20.169Z": "WebRTC(log) - State change to \"Completed\" on INVITE server transaction with id z9hG4bKPje22c86db-a69e-4e3b-983a-271e4b677434.",
    "2020-03-20T16:12:20.249Z": "WebRTC(log) - State change to \"Confirmed\" on INVITE server transaction with id z9hG4bKPje22c86db-a69e-4e3b-983a-271e4b677434.",
    "2020-03-20T16:12:20.250Z": "WebRTC(log) - Destroyed INVITE server transaction with id z9hG4bKPje22c86db-a69e-4e3b-983a-271e4b677434.",
    "2020-03-20T16:12:20.251Z": "WebRTC(log) - Destroyed INVITE server transaction with id z9hG4bKPje22c86db-a69e-4e3b-983a-271e4b677434.",
    "2020-03-20T16:12:21.345Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - NetConnectivity - checkPBXConnections - REGULAR PING - ",
    "2020-03-20T16:12:21.532Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - PBXAccount - PingResponse - 187",
    "2020-03-20T16:12:22.959Z": "actions/audio - setSpeaker - Enabled",
    "2020-03-20T16:12:22.986Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onICEConnectionProblem - Exec onConnectionProblem",
    "2020-03-20T16:12:25.961Z": "WebRTC(log) - INVITE dialog sli88tt9psijsgn2n0u4i50tb2ufth3141b8d5-fd7a-42a2-a2ec-582389ba8204 received BYE request",
    "2020-03-20T16:12:25.964Z": "WebRTC(log) - Constructing non-INVITE server transaction with id z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:25.965Z": "WebRTC(log) - State change to \"Completed\" on non-INVITE server transaction with id z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:25.966Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onBye - Exec onSessionBye",
    "2020-03-20T16:12:25.986Z": "Using getLocalStreams which is deprecated",
    "2020-03-20T16:12:25.987Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - SIPCall - _onTerminated - Init end call - InCallManager STOP",
    "2020-03-20T16:12:26.024Z": "WebRTC(log) - INVITE dialog sli88tt9psijsgn2n0u4i50tb2ufth3141b8d5-fd7a-42a2-a2ec-582389ba8204 destroyed",
    "2020-03-20T16:12:26.027Z": "WebRTC(log) - Timer J expired for NON-INVITE server transaction z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:26.030Z": "WebRTC(log) - Destroyed non-INVITE server transaction with id z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:26.034Z": "WebRTC(log) - State change to \"Terminated\" on non-INVITE server transaction with id z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:26.042Z": "WebRTC(log) - Destroyed non-INVITE server transaction with id z9hG4bKPj6cc420d5-62a3-450e-b60f-58dc05d865df.",
    "2020-03-20T16:12:26.046Z": "RTCIceConnectionStatechanged: closed",
    "2020-03-20T16:12:26.654Z": "de0b8d32-e781-4932-baf4-440e0a7684c7 - PBXAccount - _onStreamElement - "
}

So aside from this log, what do I do to troubleshoot Zulu?


(Angel Velasquez) #2

Hello Jared,

I’m afraid the carrier is giving you an IPV6 address … support for ipv6 is not currently supported in Zulu Server, that might be the issue here.


(Jared Busch) #3

I saw the IPv6 info, but my phone is on my wifi which is on my router that has no IPv6 configured.

So why is Zulu using the cellular?


(Angel Velasquez) #4

Hello @sorvani

Sorry for the late response, not sure if it’s Zulu using your cellular data, you can do a test setting up your phone to “airplane mode” and connect it to your wifi and see what happens?

Maybe your ISP is giving you IPv6 too? do that test and let me know if you haven’t figured it out yet.

Thanks!


(system) closed #5

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.