Video not available, but previously was

Asterisk Asterisk Support
1

Same topic: Freepbx community

As mentioned in the topic above, I have a pretty strange issue regarding video calls generated from a Fanvil i62 doorphone to any other device (a LinPhone softphone, Acrobits softphone and i53W from Fanvil too). The issue is that video only from this device isn’t working at all BUT it worked for at least one week after installing (and I was so happy!) and then suddenly it didn’t work anymore. Without any change in the configuration on any device nor the server. No update were done too.

Now I tried many things from the moment the problem arisen:

  1. Updated asterisk to version 20.1 (from 16.30)
  2. Updated the i62 to the latest firmware
  3. Switched various configuration that I don’t even remember right now
  4. Set the transport to UDP and no encryption for ease of debugging (was TLS)
  5. Tried with another Fanvil doorphone i61 that I had laying around on another network but same problem
  6. Debugged estensively but I can see nothing wrong, maybe do you?

I should mention that video between other devices works perfectly fine.

Codecs globally allowed for video are: h265 and h264, the doorphone is using h264. Directmedia is on.

Following various logs I caught:

RTP debug (97-99 payloads are video, seems correctly forwarded)
192.168.1.108 → LinPhone, 94.35.65.161 → i62

[2023-06-30 14:36:36] ERROR[24802]: res_pjsip_session.c:937 handle_incoming_sdp:  105: Couldn't negotiate stream 0:audio-0:audio:sendrecv (nothing)
[2023-06-30 14:36:37] DEBUG[22929][C-00000227]: res_rtp_asterisk.c:7950 ast_rtp_read: (0x7fac50042ed0) RTP NAT: Got audio from other end. Now sending to address 94.35.65.161:8118
Got  RTP packet from    94.35.65.161:8118 (type 00, seq 000013, ts 1867435181, len 000160)
Sent RTP packet to      192.168.1.108:7078 (type 00, seq 004789, ts 1867435176, len 000160)
Got  RTP packet from    94.35.65.161:8118 (type 00, seq 000014, ts 1867435341, len 000160)
Sent RTP packet to      192.168.1.108:7078 (type 00, seq 004790, ts 1867435336, len 000160)
Got  RTP packet from    94.35.65.161:8118 (type 00, seq 000015, ts 1867435501, len 000160)
Sent RTP packet to      192.168.1.108:7078 (type 00, seq 004791, ts 1867435496, len 000160)
Got  RTP packet from    94.35.65.161:8118 (type 00, seq 000016, ts 1867435661, len 000160)
Sent RTP packet to      192.168.1.108:7078 (type 00, seq 004792, ts 1867435656, len 000160)
Got  RTP packet from    94.35.65.161:8118 (type 00, seq 000017, ts 1867435821, len 000160)
Sent RTP packet to      192.168.1.108:7078 (type 00, seq 004793, ts 1867435816, len 000160)
[2023-06-30 14:36:37] DEBUG[22929][C-00000227]: res_rtp_asterisk.c:7950 ast_rtp_read: (0x7fac500aaf20) RTP NAT: Got audio from other end. Now sending to address 94.35.65.161:8120
Got  RTP packet from    94.35.65.161:8120 (type 99, seq 000004, ts 1600994718, len 001440)
Sent RTP packet to      192.168.1.108:9078 (type 97, seq 014641, ts 1600994718, len 001440)
Got  RTP packet from    94.35.65.161:8120 (type 99, seq 000005, ts 1600994718, len 001440)
Sent RTP packet to      192.168.1.108:9078 (type 97, seq 014642, ts 1600994718, len 001440)
Got  RTP packet from    94.35.65.161:8120 (type 99, seq 000006, ts 1600994718, len 001440)
Sent RTP packet to      192.168.1.108:9078 (type 97, seq 014643, ts 1600994718, len 001440)
Got  RTP packet from    94.35.65.161:8120 (type 99, seq 000007, ts 1600994718, len 001440)

core show channel 1

core show channel PJSIP/1005-000006b8
 -- General --
Name: PJSIP/1005-000006b8
Type: PJSIP
UniqueID: 1688128948.3594
LinkedID: 1688128948.3594
Caller ID: 1005
Caller ID Name: LinPhone
Connected Line ID: 2001
Connected Line ID Name: i62
Eff. Connected Line ID: 2001
Eff. Connected Line ID Name: i62
DNID Digits: 2001
Language: it
State: Up (6)
NativeFormats: (ulaw|h264)
WriteFormat: ulaw
ReadFormat: ulaw
 WriteTranscode: No 
ReadTranscode: No 
 Time to Hangup: 0
Elapsed Time: 0h0m9s
Bridge ID: f5757750-d650-4019-a4b2-0db99de29126
 --   PBX   --
Context: macro-dial-one
Extension: s
Priority: 55
Call Group: 0
Pickup Group: 0
Application: Dial
Data: PJSIP/2001/sip:2001@94.35.65.161:8082,,HhTtrb(func-apply-sipheaders^s^1)
Call Identifer: [C-0000022a]
Variables:
BRIDGEPVTCALLID=f726862a-bfed-4758-8c34-722068d30893
BRIDGEPEER=PJSIP/2001-000006b9
DIALEDPEERNUMBER=2001/sip:2001@94.35.65.161:8082
DIALEDPEERNAME=PJSIP/2001-000006b9
DIALSTATUS=ANSWER
PROGRESSTIME_MS=
PROGRESSTIME=
RINGTIME_MS=
RINGTIME=
DIALEDTIME_MS=
DIALEDTIME=
ANSWEREDTIME_MS=
ANSWEREDTIME=
MACRO_DEPTH=2
DB_RESULT=disabled
CWRING=
MACRO_PRIORITY=7
MACRO_CONTEXT=macro-exten-vm
MACRO_EXTEN=s
ARG1=
D_OPTIONS=HhTtr
GOSUB_RETVAL=
PRESENCESTATE_DISPLAY=(Available)
KEEPCID=TRUE
CWIGNORE=
ALERT_INFO=
DSTRING=PJSIP/2001/sip:2001@94.35.65.161:8082
ITER=2
THISDIAL=PJSIP/2001/sip:2001@94.35.65.161:8082
LOOPCNT=1
DEVICES=2001
EXTHASCW=ENABLED
DIALSTATUS_CW=
DEXTEN=2001
ARG3=2001
ARG2=HhTtr
RECMODE=dontcare
CALEERECMODE=dontcare
CALLERRECMODE=dontcare
CALLEE=dontcare
CALLTYPE=internal
REC_POLICY_MODE_SAVE=
MON_FMT=wav
FROMEXTEN=1005
TIMESTR=20230630-144228
YEAR=2023
MONTH=06
DAY=30
NOW=1688128948
REC_STATUS=INITIALIZED
RT=
PICKUPMARK=2001
EXTTOCALL=2001
RingGroupMethod=none
TTL=64
CALLEE_ACCOUNCODE=
DIAL_OPTIONS=HhTtr
AMPUSERCID=1005
AMPUSERCIDNAME=LinPhone
AMPUSER=1005
REALCALLERIDNUM=1005
HOTDESKCALL=0
HOTDESKEXTEN=1005
HOTDESCKCHAN=1005-000006b8
CHANEXTEN=1005-000006b8
CHANEXTENCONTEXT=1005-000006b8
CHANCONTEXT=
TOUCH_MONITOR=1688128948.3594
ARG5=0
ARG4=0
RINGTIMER=15
SIPDOMAIN=192.168.1.1
CDR Variables:
level 1: cnum=1005
level 1: cnam=LinPhone
level 1: dnid=2001
level 1: clid="LinPhone" <105>
level 1: src=1005
level 1: dst=s
level 1: dcontext=macro-dial-one
level 1: channel=PJSIP/1005-000006b8
level 1: dstchannel=PJSIP/2001-000006b9
level 1: lastapp=Dial
level 1: lastdata=PJSIP/2001/sip:2001@94.35.65.161:8082,,HhTtrb(func-apply-sipheaders^s^1)
level 1: start=1688128948.988062
level 1: answer=1688128950.051784
level 1: end=0.000000
level 1: duration=8
level 1: billsec=7
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1688128948.3594
level 1: linkedid=1688128948.3594
level 1: sequence=4368

 -- Streams --
Name: audio-0
    Type: audio
    State: sendrecv
    Group: -1
    Formats: (ulaw|alaw|g722)
    Metadata:
Name: video-1
    Type: video
    State: sendonly
    Group: -1
    Formats: (h264)
    Metadata:

core show channel 2

core show channel PJSIP/2001-000006bb
 -- General --
Name: PJSIP/2001-000006bb
Type: PJSIP
UniqueID: 1688129097.3597
LinkedID: 1688129097.3596
Caller ID: 2001
Caller ID Name: i62
Connected Line ID: 1005
Connected Line ID Name: LinPhone
Eff. Connected Line ID: 1005
Eff. Connected Line ID Name: LinPhone
DNID Digits: (N/A)
Language: it
State: Up (6)
NativeFormats: (ulaw|h264)
WriteFormat: ulaw
ReadFormat: ulaw
WriteTranscode: No 
ReadTranscode: No 
Time to Hangup: 0
Elapsed Time: 0h0m7s
Bridge ID: aec80ebf-9ffb-4bc2-a30e-287bff8f5c4d
 --   PBX   --
Context: from-internal
Extension: 
Priority: 1
Call Group: 0
Pickup Group: 0
Application: AppDial
Data: (Outgoing Line)
Call Identifer: [C-0000022b]
Variables:
BRIDGEPVTCALLID=Yf8E-Bl2ba
BRIDGEPEER=PJSIP/1005-000006ba
GOSUB_RETVAL=
sipkey=
SIPHEADERKEYS=
TECH=PJSIP
DIALEDPEERNUMBER=2001/sip:2001@94.35.65.161:8082
KEEPCID=TRUE
CWIGNORE=
MON_FMT=wav
FROMEXTEN=1005
TIMESTR=20230630-144457
YEAR=2023
MONTH=06
DAY=30
REC_STATUS=INITIALIZED
PICKUPMARK=2001
EXTTOCALL=2001
TTL=64
CALLEE_ACCOUNCODE=
DIAL_OPTIONS=HhTtr
RINGTIMER=15
CDR Variables:
level 1: clid="i62" <2001>
level 1: src=2001
level 1: dcontext=from-internal
level 1: channel=PJSIP/2001-000006bb
level 1: lastapp=AppDial
level 1: lastdata=(Outgoing Line)
level 1: start=1688129097.668297
level 1: answer=1688129098.802445
level 1: end=1688129098.807336
level 1: duration=1
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1688129097.3597
level 1: linkedid=1688129097.3596
level 1: sequence=4371

 -- Streams --
Name: audio-0
    Type: audio
    State: sendrecv
    Group: -1
    Formats: (ulaw|alaw|g726|g722)
    Metadata:
Name: video-1
    Type: video
    State: recvonly
    Group: -1
    Formats: (h264)
    Metadata:

PJSIP Logging enabled

<--- Received SIP request (908 bytes) from UDP:192.168.1.108:55635 --->
INFO sip:192.168.1.1:5160 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.108:55635;branch=z9hG4bK.QSlWqRPeP;rport
From: <sip:1005@192.168.1.1>;tag=2ydcXFYy3
To: <sip:2001@192.168.1.1>;tag=2479dfd0-3946-47de-b7c7-225f9d78312c
CSeq: 36 INFO
Call-ID: t2Y78EOL8k
Max-Forwards: 70
Content-Type: application/media_control+xml
Content-Length: 185
User-Agent: Linphone-Desktop/5.0.17 (Mac-Mini-di-Max.lan) osx/12.6 Qt/5.15.2 LinphoneSDK/5.2.66-2-g24e7882ce
Authorization:  Digest realm="asterisk", nonce="1688140903/76b623acdc88f1f89a5b60716910f851", algorithm=MD5, opaque="58e1ceb84e8d79be", username="105",  uri="sip:192.168.1.1:5160", response="aa9dd92cbd611895941d1b52f5884898", cnonce="NoqMbUfHdxrrjgtr", nc=00000010, qop=auth

<?xml version="1.0" encoding="utf-8" ?><media_control>  <vc_primitive>    <to_encoder>      <picture_fast_update></picture_fast_update>    </to_encoder>  </vc_primitive></media_control>
<--- Transmitting SIP response (316 bytes) to UDP:192.168.1.108:55635 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.108:55635;rport=55635;received=192.168.1.108;branch=z9hG4bK.QSlWqRPeP
Call-ID: t2Y78EOL8k
From: <sip:1005@192.168.1.1>;tag=2ydcXFYy3
To: <sip:2001@192.168.1.1>;tag=2479dfd0-3946-47de-b7c7-225f9d78312c
CSeq: 36 INFO
Server: FPBX-16.0.40.4(16.30.0)
Content-Length:  0


<--- Transmitting SIP request (631 bytes) to UDP:94.35.65.161:8082 --->
INFO sip:2001@94.35.65.161:8082 SIP/2.0
Via: SIP/2.0/UDP x.x.x.x:5160;rport;branch=z9hG4bKPj5f368a55-ddfd-4845-8113-5440bf13a081
From: "LinPhone" <sip:1005@192.168.1.1>;tag=6e3609ba-8448-417d-8f00-f2709d713974
To: <sip:2001@94.35.65.161>;tag=2740845415
Call-ID: 39a1313b-c08d-440a-8052-3869115a0dad
CSeq: 9068 INFO
Max-Forwards: 70
User-Agent: FPBX-16.0.40.4(16.30.0)
Content-Type: application/media_control+xml
Content-Length:   178

<?xml version="1.0" encoding="utf-8" ?>
 <media_control>
  <vc_primitive>
   <to_encoder>
    <picture_fast_update/>
   </to_encoder>
  </vc_primitive>
 </media_control>

<--- Received SIP response (415 bytes) from UDP:94.35.65.161:8082 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP x.x.x.x:5160;rport=5160;branch=z9hG4bKPj5f368a55-ddfd-4845-8113-5440bf13a081
From: "LinPhone" <sip:1005@192.168.1.1>;tag=6e3609ba-8448-417d-8f00-f2709d713974
To: <sip:2001@94.35.65.161>;tag=2740845415
Call-ID: 39a1313b-c08d-440a-8052-3869115a0dad
CSeq: 9068 INFO
Contact: <sip:2001@94.35.65.161:8082>
User-Agent: Fanvil i62 2.12.19.9 0c383e2de1b6
Content-Length: 0


<--- Transmitting SIP request (452 bytes) to TLS:x.x.x.x:1550 --->
OPTIONS sip:103@x.x.x.x:1550;transport=TLS SIP/2.0
Via: SIP/2.0/TLS x.x.x.x:5162;rport;branch=z9hG4bKPjba3329b8-f33f-4f08-a567-d294b7c12d1f;alias
From: <sip:103@192.168.1.1>;tag=13058d76-3156-41c0-81be-2292e1665757
To: <sip:103@x.x.x.x>
Contact: <sip:103@x.x.x.x:5162;transport=TLS>
Call-ID: e2f62950-259f-4fa4-b6a9-09140edb778a
CSeq: 2916 OPTIONS
Max-Forwards: 70
User-Agent: FPBX-16.0.40.4(16.30.0)
Content-Length:  0


<--- Received SIP response (564 bytes) from TLS:x.x.x.x:1550 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS x.x.x.x:5162;rport=5162;branch=z9hG4bKPjba3329b8-f33f-4f08-a567-d294b7c12d1f;alias
From: <sip:103@192.168.1.1>;tag=13058d76-3156-41c0-81be-2292e1665757
To: <sip:103@x.x.x.x>;tag=1474432629
Call-ID: e2f62950-259f-4fa4-b6a9-09140edb778a
CSeq: 2916 OPTIONS
Contact: <sip:103@x.x.x.x:1550;transport=tls>
Supported: 100rel, replaces, timer
Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE
Accept: application/sdp, message/sipfrag, application/dtmf-relay
Content-Length: 0


<--- Received SIP request (908 bytes) from UDP:192.168.1.108:55635 --->
INFO sip:192.168.1.1:5160 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.108:55635;branch=z9hG4bK.7LI2zH8rE;rport
From: <sip:1005@192.168.1.1>;tag=2ydcXFYy3
To: <sip:2001@192.168.1.1>;tag=2479dfd0-3946-47de-b7c7-225f9d78312c
CSeq: 37 INFO
Call-ID: t2Y78EOL8k
Max-Forwards: 70
Content-Type: application/media_control+xml
Content-Length: 185
User-Agent: Linphone-Desktop/5.0.17 (Mac-Mini-di-Max.lan) osx/12.6 Qt/5.15.2 LinphoneSDK/5.2.66-2-g24e7882ce
Authorization:  Digest realm="asterisk", nonce="1688140903/76b623acdc88f1f89a5b60716910f851", algorithm=MD5, opaque="58e1ceb84e8d79be", username="105",  uri="sip:192.168.1.1:5160", response="3092f46f02c2dc84feedc7b111bd0df7", cnonce="~ENluZufWUsUtY5u", nc=00000011, qop=auth

<?xml version="1.0" encoding="utf-8" ?><media_control>  <vc_primitive>    <to_encoder>      <picture_fast_update></picture_fast_update>    </to_encoder>  </vc_primitive></media_control>
<--- Transmitting SIP response (316 bytes) to UDP:192.168.1.108:55635 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.108:55635;rport=55635;received=192.168.1.108;branch=z9hG4bK.7LI2zH8rE
Call-ID: t2Y78EOL8k
From: <sip:1005@192.168.1.1>;tag=2ydcXFYy3
To: <sip:2001@192.168.1.1>;tag=2479dfd0-3946-47de-b7c7-225f9d78312c
CSeq: 37 INFO
Server: FPBX-16.0.40.4(16.30.0)
Content-Length:  0


<--- Transmitting SIP request (631 bytes) to UDP:94.35.65.161:8082 --->
INFO sip:2001@94.35.65.161:8082 SIP/2.0
Via: SIP/2.0/UDP x.x.x.x:5160;rport;branch=z9hG4bKPj9fc0e7af-f32e-48e7-a8b4-3cee2cb3ebcd
From: "LinPhone" <sip:1005@192.168.1.1>;tag=6e3609ba-8448-417d-8f00-f2709d713974
To: <sip:2001@94.35.65.161>;tag=2740845415
Call-ID: 39a1313b-c08d-440a-8052-3869115a0dad
CSeq: 9069 INFO
Max-Forwards: 70
User-Agent: FPBX-16.0.40.4(16.30.0)
Content-Type: application/media_control+xml
Content-Length:   178

<?xml version="1.0" encoding="utf-8" ?>
 <media_control>
  <vc_primitive>
   <to_encoder>
    <picture_fast_update/>
   </to_encoder>
  </vc_primitive>
 </media_control>

<--- Received SIP response (415 bytes) from UDP:94.35.65.161:8082 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP x.x.x.x:5160;rport=5160;branch=z9hG4bKPj9fc0e7af-f32e-48e7-a8b4-3cee2cb3ebcd
From: "LinPhone" <sip:1005@192.168.1.1>;tag=6e3609ba-8448-417d-8f00-f2709d713974
To: <sip:2001@94.35.65.161>;tag=2740845415
Call-ID: 39a1313b-c08d-440a-8052-3869115a0dad
CSeq: 9069 INFO
Contact: <sip:2001@94.35.65.161:8082>
User-Agent: Fanvil i62 2.12.19.9 0c383e2de1b6
Content-Length: 0

asterisk debug output

== Spawn extension (func-apply-sipheaders, s, 13) exited non-zero on 'PJSIP/2001-00000016'
    -- PJSIP/2001-00000016 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- Called PJSIP/2001/sip:2001@94.35.65.161:8082
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
  == Using SIP RTP Audio CoS mark 5
  == Using SIP RTP Video TOS bits 136
  == Using SIP RTP Video TOS bits 136 in TCLASS field.
  == Using SIP RTP Video CoS mark 4
       > 0x7f816c3faa30 -- Strict RTP learning after remote address set to: 192.168.1.11:10200
       > 0x7f816c482700 -- Strict RTP learning after remote address set to: 192.168.1.11:10202
       > 0x7f816c3faa30 -- Strict RTP qualifying stream type: audio
    -- PJSIP/2001-00000016 answered PJSIP/1005-00000015
       > 0x7f816c4882b0 -- Strict RTP learning after remote address set to: 192.168.1.108:7078
       > 0x7f816c414b60 -- Strict RTP learning after remote address set to: 192.168.1.108:9078
    -- Channel PJSIP/2001-00000016 joined 'simple_bridge' basic-bridge <49ea1057-ebf3-4645-8d94-1a0e9797821a>
    -- Channel PJSIP/1005-00000015 joined 'simple_bridge' basic-bridge <49ea1057-ebf3-4645-8d94-1a0e9797821a>
       > 0x7f816c3faa30 -- Strict RTP switching source address to 94.35.65.161:8086
       > 0x7f816c482700 -- Strict RTP qualifying stream type: video
       > 0x7f816c482700 -- Strict RTP switching source address to 94.35.65.161:8094
       > 0x7f816c4882b0 -- Strict RTP switching to RTP target address 192.168.1.108:7078 as source
       > 0x7f816c414b60 -- Strict RTP switching to RTP target address 192.168.1.108:9078 as source
       > 0x7f816c3faa30 -- Strict RTP learning complete - Locking on source address 94.35.65.161:8086
       > 0x7f816c4882b0 -- Strict RTP learning complete - Locking on source address 192.168.1.108:7078
       > 0x7f816c482700 -- Strict RTP learning complete - Locking on source address 94.35.65.161:8094
       > 0x7f816c414b60 -- Strict RTP learning complete - Locking on source address 192.168.1.108:9078

I point out again that video stopped working without any change in the configuration and never recovered.
I am currently trying to capture the packets with Wireshark but will take a bit, I was able to only catch the one coming from my device (I’m not expert in it).

I hope someone (jcolp :pray:) could help with this one!

2

I tried today looking more traces in Wireshark and I found a pretty useful tool (Videosnarf) even though is outdated it still works pretty fine. I was able to retrieve videos with test calls from two other devices on different networks, but with the doorphone I was able to only retrieve the video I was sending myself and not the one from the doorbell. Any clue?

3

After many debugging and research I found the problem was the router on the doorphone side. I did change it but I didn’t remember so the problems all started there…

The router is a Tenda 4G03 (a 4G router). I tried disabling the firewall and everything but nothing helped. The cause I think it is the slow speed achieved by this device or some strange firmware firewall that blocks some types of connections. Switching back to the trusted YPLink Archer MR200 fixes everything (I changed it because it had some other problems).

Long story short: at least for me, do not use a Tenda 4g router with FreePBX/asterisk!

4

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