[Spce-user] No audio between subscribers
Edo
edo.ekunwe at gmail.com
Mon Aug 9 00:48:05 EDT 2021
All,
I have configured the system (Linux spce 5.10.0-8-amd64 #1 SMP Debian
5.10.46-2 (2021-07-20) x86_64) and attempting to make calls between 2
subscribers.
Call is successful but no audio is available on both sides. Log does not
show any major anomaly except saying
-- Media #1 (audio over RTP/AVP) using unknown codec over SSRC and RTCP
Please help
Thanks
See logs below
****
Aug 9 04:22:06 spce rtpengine[831]: NOTICE: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] Creating new call
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Default sink codec is G722/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Output DTMF payload type is 101
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for G722/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec G722/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for G722/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for PCMU/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec PCMU/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for PCMU/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for PCMA/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec PCMA/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for PCMA/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for GSM/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec GSM/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for GSM/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for iLBC/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for iLBC/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for opus/48000/2
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec opus/48000/2
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for opus/48000/2
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for telephone-event/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec telephone-event/8000
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for telephone-event/8000
Aug 9 04:22:06 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Replying to 'offer' from 127.0.0.1:48741 (elapsed time 0.000688
sec)
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Response dump for 'offer' to 127.0.0.1:48741: «{ "sdp": "v=0 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... o=- 0 1 IN IP4 127.0.0.1 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... s=- ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... c=IN IP4 127.0.0.1 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... t=0 0 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... m=audio 30176 RTP/AVP 9 0 8 3 102 120 101 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:9 G722/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:0 PCMU/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:8 PCMA/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:3 GSM/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:102 iLBC/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=fmtp:102 mode=30 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:120 opus/48000/2 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:101 telephone-event/8000 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=fmtp:101 0-15 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=sendrecv ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtcp:30177 ...
Aug 9 04:22:06 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... ", "result": "ok" }»
Aug 9 04:22:06 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:22:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Received command 'answer' from 127.0.0.1:45000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Dump for 'answer' from 127.0.0.1:45000: «{ "supports": [ "load
limit" ], "sdp": "v=0 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... o=Z 0 1 IN IP4 127.0.0.1 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... s=Z ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... c=IN IP4 127.0.0.1 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... t=0 0 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... m=audio 8001 RTP/AVP 0 8 101 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:101 telephone-event/8000 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=fmtp:101 0-16 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=sendrecv ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=direction:both ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... ", "label": "callee", "xmlrpc-callback": "127.0.0.1", "ICE": "remove",
"flags": [ "strict-source", "OSRTP-accept" ], "replace": [ "origin",
"session-connection" ], "rtcp-mux": [ "demux" ], "call-id":
"tsg5T28gIKNxM6drC3HUlw..", "via-branch":
"z9hG4bK9872.3d6e3cdc8c4401d176e576bd06d192eb.0", "received-from": [ "IP4",
"127.0.0.1" ], "from-tag": "2498e50c", "to-tag":
"1E584784-6110914E00002F1F-2B9F9700", "command": "answer" }»
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric inbound codec G722/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric inbound codec GSM/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric inbound codec iLBC/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric inbound codec opus/48000/2
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Default sink codec is PCMU/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Output DTMF payload type is 101
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric outbound codec G722/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric outbound codec GSM/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric outbound codec iLBC/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Eliminating asymmetric outbound codec opus/48000/2
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for PCMU/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec PCMU/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for PCMU/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for PCMA/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec PCMA/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for PCMA/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Creating codec handler for telephone-event/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Sink supports codec telephone-event/8000
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[codec] Using passthrough handler for telephone-event/8000
Aug 9 04:22:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Replying to 'answer' from 127.0.0.1:45000 (elapsed time 0.000313
sec)
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Response dump for 'answer' to 127.0.0.1:45000: «{ "sdp": "v=0 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... o=Z 0 1 IN IP4 127.0.0.1 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... s=Z ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... c=IN IP4 127.0.0.1 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... t=0 0 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... m=audio 30190 RTP/AVP 0 8 101 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=direction:both ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:0 PCMU/8000 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:8 PCMA/8000 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtpmap:101 telephone-event/8000 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=fmtp:101 0-16 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=sendrecv ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... a=rtcp:30191 ...
Aug 9 04:22:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
... ", "result": "ok" }»
Aug 9 04:22:16 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:22:26 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:22:36 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:22:46 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:22:56 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:23:06 spce rtpengine[831]: INFO: [http] HTTP GET from
[::ffff:127.0.0.1]:45000: '/metrics'
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] Closing call due to timeout
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] Final packet stats:
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --- Tag '«2498e50c»' (label 'caller'), created 1:10 ago for branch
'«»', in dialogue with '«1E584784-6110914E00002F1F-2B9F9700»'
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] ------ Media #1 (audio over RTP/AVP) using unknown codec
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --------- Port 127.0.0.1:30190 <> « 192.168.1.17:4002 »,
SSRC «0», 0 p, 0 b, 0 e, 70 ts
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --------- Port 127.0.0.1:30191 <> « 192.168.1.17:4003 »
(RTCP), SSRC «0», 0 p, 0 b, 0 e, 70 ts
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --- Tag '«1E584784-6110914E00002F1F-2B9F9700»' (label 'callee'),
created 1:10 ago for branch
'«z9hG4bK9872.3d6e3cdc8c4401d176e576bd06d192eb.0»', in dialogue with
'«2498e50c»'
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] ------ Media #1 (audio over RTP/AVP) using unknown codec
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --------- Port 127.0.0.1:30176 <> « 127.0.0.1:8001 »,
SSRC «0», 0 p, 0 b, 0 e, 60 ts
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] --------- Port 127.0.0.1:30177 <> « 127.0.0.1:8002 »
(RTCP), SSRC «0», 0 p, 0 b, 0 e, 60 ts
Aug 9 04:23:16 spce rtpengine[831]: INFO: [core] Forking child to close
call with tag «2498e50c» via XMLRPC call to http://127.0.0.1:8090/
Aug 9 04:23:16 spce rtpengine[52014]: INFO: [core] Initiating XMLRPC call
for tag «2498e50c»
Aug 9 04:23:16 spce rtpengine[831]: INFO: [core] Forking child to close
call with tag «1E584784-6110914E00002F1F-2B9F9700» via XMLRPC call to
http://127.0.0.1:8090/
Aug 9 04:23:16 spce rtpengine[52015]: INFO: [core] Initiating XMLRPC call
for tag «1E584784-6110914E00002F1F-2B9F9700»
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Received command 'delete' from 127.0.0.1:47603
Aug 9 04:23:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Dump for 'delete' from 127.0.0.1:47603: «{ "supports": [ "load
limit" ], "call-id": "tsg5T28gIKNxM6drC3HUlw..", "received-from": [ "IP4",
"127.0.0.1" ], "from-tag": "1E584784-6110914E00002F1F-2B9F9700", "to-tag":
"2498e50c", "command": "delete" }»
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[core] Call-ID to delete not found
Aug 9 04:23:16 spce rtpengine[831]: INFO: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Replying to 'delete' from 127.0.0.1:47603 (elapsed time 0.000013
sec)
Aug 9 04:23:16 spce rtpengine[831]: DEBUG: [«tsg5T28gIKNxM6drC3HUlw..»]:
[control] Response dump for 'delete' to 127.0.0.1:47603: «{ "warning":
"Call-ID not found or tags didn't match", "result": "ok" }»
****
--
-----
Ekunwe
EDO Network Services, Inc.
Tel: 601.497.3932
Fax: 601.979.5931
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20210808/e6c85a88/attachment-0001.html>
More information about the Spce-user
mailing list