No sound in playback function

Rioz · August 9, 2019, 5:39am

Asterisk installed and there is a phone registered. Phone is working when dialing but there is no sound hear for playback function. Not sure whether it is caused by the different subnet between asterisk and phone. Anyone can give me a clue and solution?

– Executing [dialed-CHANUNAVAIL@Internal-Main:1] NoOp(“PJSIP/1101-00000000”, “”) in new stack
– Executing [dialed-CHANUNAVAIL@Internal-Main:2] Playback(“PJSIP/1101-00000000”, “pbx-invalid”) in new stack

asterisk
version: 16.5.0
OS: centos 7
firewall: disabled
selinux: disabled
subnet: 10.94.10.*
configuration: keep using default configuration file

IP phone
subnet: 136.138.109.*

david551 · August 9, 2019, 9:08am

Please provide the pjsip protocol logs.

Rioz · August 9, 2019, 4:18pm

May I know where is the pjsip protocol logs? Do I need to enable it and how?

kharwell · August 9, 2019, 4:36pm

Short answer you can issue the following command on the CLI:

*CLI> pjsip set logger on

And then to turn it back off:

*CLI> pjsip set logger off

This will output the SIP traffic to the log and/or console depending on your configuration. Please post those results once obtained.

More information though can be found on the Collecting Debug Information wiki page

Rioz · August 13, 2019, 9:39am

I think it is caused by network/routing. To be more specific, network configuration is shown below. A static route is set for desktop from 136.138.* to 10.94.. However, it seems traffic can’t route back from 10.94. to 136.138.* shown from the log below.

Desktop (soft phone) interface
192.168.* (internet)
136.138.* (internal network)

Asterisk interface
10.94.* (internal network)

[Aug 12 10:43:59] <— Received SIP request (1030 bytes) from UDP:136.138.1.20:57145 —>
[Aug 12 10:43:59] INVITE sip:1103@10.94.1.239 SIP/2.0
[Aug 12 10:43:59] Via: SIP/2.0/UDP 136.138.1.20:57145;rport;branch=z9hG4bKPj5a9d81a1135a48f98990b4efd0491dcc
[Aug 12 10:43:59] Max-Forwards: 70
[Aug 12 10:43:59] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:43:59] To: sip:1103@10.94.1.239
[Aug 12 10:43:59] Contact: “1101” sip:1101@136.138.1.20:57145;ob
[Aug 12 10:43:59] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:43:59] CSeq: 19367 INVITE
[Aug 12 10:43:59] Route: sip:10.94.1.239;lr
[Aug 12 10:43:59] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Aug 12 10:43:59] Supported: replaces, 100rel, timer, norefersub
[Aug 12 10:43:59] Session-Expires: 1800
[Aug 12 10:43:59] Min-SE: 90
[Aug 12 10:43:59] User-Agent: MicroSIP/3.19.8
[Aug 12 10:43:59] Content-Type: application/sdp
[Aug 12 10:43:59] Content-Length: 365
[Aug 12 10:43:59]
[Aug 12 10:43:59] v=0
[Aug 12 10:43:59] o=- 3774595843 3774595843 IN IP4 192.168.1.80
[Aug 12 10:43:59] s=pjmedia
[Aug 12 10:43:59] b=AS:84
[Aug 12 10:43:59] t=0 0
[Aug 12 10:43:59] a=X-nat:0
[Aug 12 10:43:59] m=audio 4000 RTP/AVP 0 8 3 101
[Aug 12 10:43:59] c=IN IP4 192.168.1.80
[Aug 12 10:43:59] b=TIAS:64000
[Aug 12 10:43:59] a=rtcp:4001 IN IP4 192.168.1.80
[Aug 12 10:43:59] a=sendrecv
[Aug 12 10:43:59] a=rtpmap:0 PCMU/8000
[Aug 12 10:43:59] a=rtpmap:8 PCMA/8000
[Aug 12 10:43:59] a=rtpmap:3 GSM/8000
[Aug 12 10:43:59] a=rtpmap:101 telephone-event/8000
[Aug 12 10:43:59] a=fmtp:101 0-16
[Aug 12 10:43:59] a=ssrc:802051384 cname:4bd51b97293f0aad
[Aug 12 10:43:59]
[Aug 12 10:43:59] <— Transmitting SIP response (560 bytes) to UDP:136.138.1.20:57145 —>
[Aug 12 10:43:59] SIP/2.0 401 Unauthorized
[Aug 12 10:43:59] Via: SIP/2.0/UDP 136.138.1.20:57145;rport=57145;received=136.138.1.20;branch=z9hG4bKPj5a9d81a1135a48f98990b4efd0491dcc
[Aug 12 10:43:59] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:43:59] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:43:59] To: sip:1103@10.94.1.239;tag=z9hG4bKPj5a9d81a1135a48f98990b4efd0491dcc
[Aug 12 10:43:59] CSeq: 19367 INVITE
[Aug 12 10:43:59] WWW-Authenticate: Digest realm=“asterisk”,nonce=“1565577839/ea6dd23a65ca96354b1bb8e0b49aefe7”,opaque=“2fb6c6c63ff2c549”,algorithm=md5,qop=“auth”
[Aug 12 10:43:59] Server: Asterisk PBX 16.5.0
[Aug 12 10:43:59] Content-Length: 0
[Aug 12 10:43:59]
[Aug 12 10:43:59]
[Aug 12 10:43:59] <— Received SIP request (409 bytes) from UDP:136.138.1.20:57145 —>
[Aug 12 10:43:59] ACK sip:1103@10.94.1.239 SIP/2.0
[Aug 12 10:43:59] Via: SIP/2.0/UDP 136.138.1.20:57145;rport;branch=z9hG4bKPj5a9d81a1135a48f98990b4efd0491dcc
[Aug 12 10:43:59] Max-Forwards: 70
[Aug 12 10:43:59] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:43:59] To: sip:1103@10.94.1.239;tag=z9hG4bKPj5a9d81a1135a48f98990b4efd0491dcc
[Aug 12 10:43:59] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:43:59] CSeq: 19367 ACK
[Aug 12 10:43:59] Route: sip:10.94.1.239;lr
[Aug 12 10:43:59] Content-Length: 0
[Aug 12 10:43:59]
[Aug 12 10:43:59]
[Aug 12 10:44:00] <— Received SIP request (1329 bytes) from UDP:136.138.1.20:57145 —>
[Aug 12 10:44:00] INVITE sip:1103@10.94.1.239 SIP/2.0
[Aug 12 10:44:00] Via: SIP/2.0/UDP 192.168.1.80:57145;rport;branch=z9hG4bKPj1c5121ea13ab4f329c8a325c858de2c5
[Aug 12 10:44:00] Max-Forwards: 70
[Aug 12 10:44:00] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:00] To: sip:1103@10.94.1.239
[Aug 12 10:44:00] Contact: “1101” sip:1101@136.138.1.20:57145;ob
[Aug 12 10:44:00] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:00] CSeq: 19368 INVITE
[Aug 12 10:44:00] Route: sip:10.94.1.239;lr
[Aug 12 10:44:00] Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Aug 12 10:44:00] Supported: replaces, 100rel, timer, norefersub
[Aug 12 10:44:00] Session-Expires: 1800
[Aug 12 10:44:00] Min-SE: 90
[Aug 12 10:44:00] User-Agent: MicroSIP/3.19.8
[Aug 12 10:44:00] Authorization: Digest username=“3605657CFB45”, realm=“asterisk”, nonce=“1565577839/ea6dd23a65ca96354b1bb8e0b49aefe7”, uri="sip:1103@10.94.1.239", response=“95153a235e8fbc7e3b0db92a44363ea9”, algorithm=md5, cnonce=“32fecc120e104b8a8d65dbfce39c3d2b”, opaque=“2fb6c6c63ff2c549”, qop=auth, nc=00000001
[Aug 12 10:44:00] Content-Type: application/sdp
[Aug 12 10:44:00] Content-Length: 365
[Aug 12 10:44:00]
[Aug 12 10:44:00] v=0
[Aug 12 10:44:00] o=- 3774595843 3774595843 IN IP4 192.168.1.80
[Aug 12 10:44:00] s=pjmedia
[Aug 12 10:44:00] b=AS:84
[Aug 12 10:44:00] t=0 0
[Aug 12 10:44:00] a=X-nat:0
[Aug 12 10:44:00] m=audio 4000 RTP/AVP 0 8 3 101
[Aug 12 10:44:00] c=IN IP4 192.168.1.80
[Aug 12 10:44:00] b=TIAS:64000
[Aug 12 10:44:00] a=rtcp:4001 IN IP4 192.168.1.80
[Aug 12 10:44:00] a=sendrecv
[Aug 12 10:44:00] a=rtpmap:0 PCMU/8000
[Aug 12 10:44:00] a=rtpmap:8 PCMA/8000
[Aug 12 10:44:00] a=rtpmap:3 GSM/8000
[Aug 12 10:44:00] a=rtpmap:101 telephone-event/8000
[Aug 12 10:44:00] a=fmtp:101 0-16
[Aug 12 10:44:00] a=ssrc:802051384 cname:4bd51b97293f0aad
[Aug 12 10:44:00]
[Aug 12 10:44:00] == Setting global variable ‘SIPDOMAIN’ to ‘10.94.1.239’
[Aug 12 10:44:00] <— Transmitting SIP response (361 bytes) to UDP:136.138.1.20:57145 —>
[Aug 12 10:44:00] SIP/2.0 100 Trying
[Aug 12 10:44:00] Via: SIP/2.0/UDP 192.168.1.80:57145;rport=57145;received=136.138.1.20;branch=z9hG4bKPj1c5121ea13ab4f329c8a325c858de2c5
[Aug 12 10:44:00] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:00] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:00] To: sip:1103@10.94.1.239
[Aug 12 10:44:00] CSeq: 19368 INVITE
[Aug 12 10:44:00] Server: Asterisk PBX 16.5.0
[Aug 12 10:44:00] Content-Length: 0
[Aug 12 10:44:00]
[Aug 12 10:44:00]
[Aug 12 10:44:00] – Executing [1103@Long-Distance:1] NoOp(“PJSIP/1101-00000001”, “”) in new stack
[Aug 12 10:44:00] – Executing [1103@Long-Distance:2] Set(“PJSIP/1101-00000001”, “CDR_PROP(disable)=1”) in new stack
[Aug 12 10:44:00] – Executing [1103@Long-Distance:3] Goto(“PJSIP/1101-00000001”, “Internal-Main,1103,1”) in new stack
[Aug 12 10:44:00] – Goto (Internal-Main,1103,1)
[Aug 12 10:44:00] – Executing [1103@Internal-Main:1] Verbose(“PJSIP/1101-00000001”, “1, “User 1101 dialed 1103.””) in new stack
[Aug 12 10:44:00] “User 1101 dialed 1103.”
[Aug 12 10:44:00] – Executing [1103@Internal-Main:2] Set(“PJSIP/1101-00000001”, “SAC_DIALED_EXTEN=1103”) in new stack
[Aug 12 10:44:00] – Executing [1103@Internal-Main:3] GotoIf(“PJSIP/1101-00000001”, “0?dialed-BUSY,1:”) in new stack
[Aug 12 10:44:00] – Executing [1103@Internal-Main:4] Dial(“PJSIP/1101-00000001”, “PJSIP/1103,30”) in new stack
[Aug 12 10:44:00] ERROR[8564]: res_pjsip.c:3533 ast_sip_create_dialog_uac: Endpoint ‘1103’: Could not create dialog to invalid URI ‘1103’. Is endpoint registered and reachable?
[Aug 12 10:44:00] ERROR[8564]: chan_pjsip.c:2509 request: Failed to create outgoing session to endpoint ‘1103’
[Aug 12 10:44:00] WARNING[8569][C-00000002]: app_dial.c:2578 dial_exec_full: Unable to create channel of type ‘PJSIP’ (cause 3 - No route to destination)
[Aug 12 10:44:00] == Everyone is busy/congested at this time (1:0/0/1)
[Aug 12 10:44:00] – Executing [1103@Internal-Main:5] Goto(“PJSIP/1101-00000001”, “dialed-CHANUNAVAIL,1”) in new stack
[Aug 12 10:44:00] – Goto (Internal-Main,dialed-CHANUNAVAIL,1)
[Aug 12 10:44:00] – Executing [dialed-CHANUNAVAIL@Internal-Main:1] NoOp(“PJSIP/1101-00000001”, “”) in new stack
[Aug 12 10:44:00] – Executing [dialed-CHANUNAVAIL@Internal-Main:2] Playback(“PJSIP/1101-00000001”, “pbx-invalid”) in new stack
[Aug 12 10:44:00] > 0x7f57f40344d0 – Strict RTP learning after remote address set to: 192.168.1.80:4000
[Aug 12 10:44:00] <— Transmitting SIP response (915 bytes) to UDP:136.138.1.20:57145 —>
[Aug 12 10:44:00] SIP/2.0 200 OK
[Aug 12 10:44:00] Via: SIP/2.0/UDP 192.168.1.80:57145;rport=57145;received=136.138.1.20;branch=z9hG4bKPj1c5121ea13ab4f329c8a325c858de2c5
[Aug 12 10:44:00] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:00] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:00] To: sip:1103@10.94.1.239;tag=1fce3539-a1db-437c-8c28-41ce79130a81
[Aug 12 10:44:00] CSeq: 19368 INVITE
[Aug 12 10:44:00] Server: Asterisk PBX 16.5.0
[Aug 12 10:44:00] Contact: sip:10.94.1.239:5060
[Aug 12 10:44:00] Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
[Aug 12 10:44:00] Supported: 100rel, timer, replaces, norefersub
[Aug 12 10:44:00] Session-Expires: 1800;refresher=uac
[Aug 12 10:44:00] Require: timer
[Aug 12 10:44:00] Content-Type: application/sdp
[Aug 12 10:44:00] Content-Length: 237
[Aug 12 10:44:00]
[Aug 12 10:44:00] v=0
[Aug 12 10:44:00] o=- 3774595843 3774595845 IN IP4 10.94.1.239
[Aug 12 10:44:00] s=Asterisk
[Aug 12 10:44:00] c=IN IP4 10.94.1.239
[Aug 12 10:44:00] t=0 0
[Aug 12 10:44:00] m=audio 15544 RTP/AVP 0 101
[Aug 12 10:44:00] a=rtpmap:0 PCMU/8000
[Aug 12 10:44:00] a=rtpmap:101 telephone-event/8000
[Aug 12 10:44:00] a=fmtp:101 0-16
[Aug 12 10:44:00] a=ptime:20
[Aug 12 10:44:00] a=maxptime:150
[Aug 12 10:44:00] a=sendrecv
[Aug 12 10:44:00]
[Aug 12 10:44:00] <— Received SIP request (374 bytes) from UDP:136.138.1.20:57145 —>
[Aug 12 10:44:00] ACK sip:10.94.1.239:5060 SIP/2.0
[Aug 12 10:44:00] Via: SIP/2.0/UDP 136.138.1.20:57145;rport;branch=z9hG4bKPj7514b0543b0043aab03dcbfdbb36b77a
[Aug 12 10:44:00] Max-Forwards: 70
[Aug 12 10:44:00] From: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:00] To: sip:1103@10.94.1.239;tag=1fce3539-a1db-437c-8c28-41ce79130a81
[Aug 12 10:44:00] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:00] CSeq: 19368 ACK
[Aug 12 10:44:00] Content-Length: 0
[Aug 12 10:44:00]
[Aug 12 10:44:00]
[Aug 12 10:44:00] – <PJSIP/1101-00000001> Playing ‘pbx-invalid.ulaw’ (language ‘en’)
[Aug 12 10:44:00] > 0x7f57f40344d0 – Strict RTP qualifying stream type: audio
[Aug 12 10:44:00] > 0x7f57f40344d0 – Strict RTP switching source address to 136.138.1.20:4000
[Aug 12 10:44:04] – Executing [dialed-CHANUNAVAIL@Internal-Main:3] Hangup(“PJSIP/1101-00000001”, “”) in new stack
[Aug 12 10:44:04] == Spawn extension (Internal-Main, dialed-CHANUNAVAIL, 3) exited non-zero on ‘PJSIP/1101-00000001’
[Aug 12 10:44:04] – Executing [h@Internal-Main:1] Hangup(“PJSIP/1101-00000001”, “”) in new stack
[Aug 12 10:44:04] == Spawn extension (Internal-Main, h, 1) exited non-zero on ‘PJSIP/1101-00000001’
[Aug 12 10:44:04] <— Transmitting SIP request (442 bytes) to UDP:136.138.1.20:57145 —>
[Aug 12 10:44:04] BYE sip:1101@136.138.1.20:57145;ob SIP/2.0
[Aug 12 10:44:04] Via: SIP/2.0/UDP 10.94.1.239:5060;rport;branch=z9hG4bKPjf9cbdd01-4ed5-4901-9a2e-51249d234e09
[Aug 12 10:44:04] From: sip:1103@10.94.1.239;tag=1fce3539-a1db-437c-8c28-41ce79130a81
[Aug 12 10:44:04] To: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:04] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:04] CSeq: 25656 BYE
[Aug 12 10:44:04] Reason: Q.850;cause=3
[Aug 12 10:44:04] Max-Forwards: 70
[Aug 12 10:44:04] User-Agent: Asterisk PBX 16.5.0
[Aug 12 10:44:04] Content-Length: 0
[Aug 12 10:44:04]
[Aug 12 10:44:04]
[Aug 12 10:44:04] <— Received SIP response (365 bytes) from UDP:136.138.1.20:57145 —>
[Aug 12 10:44:04] SIP/2.0 200 OK
[Aug 12 10:44:04] Via: SIP/2.0/UDP 10.94.1.239:5060;rport=5060;received=10.94.1.239;branch=z9hG4bKPjf9cbdd01-4ed5-4901-9a2e-51249d234e09
[Aug 12 10:44:04] Call-ID: 156bb8f35113460aa473c4c16bd2627f
[Aug 12 10:44:04] From: sip:1103@10.94.1.239;tag=1fce3539-a1db-437c-8c28-41ce79130a81
[Aug 12 10:44:04] To: “1101” sip:1101@10.94.1.239;tag=99bee8163242451290937c72ad693816
[Aug 12 10:44:04] CSeq: 25656 BYE
[Aug 12 10:44:04] Content-Length: 0
[Aug 12 10:44:04]
[Aug 12 10:44:04]

Rioz · August 14, 2019, 12:59am

136.138.* (soft phone) —> 10.94.* (asterisk)
It seems inbound static route should be set. Any clue?
136.138.* (soft phone) <---- 10.94.* (asterisk)

Rioz · August 14, 2019, 8:54am

I fixed it by specifying the IP in softphone.
Thanks all.

system · September 13, 2019, 8:54am

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