Hello.
I’m suffering with very strange problem.
I’m using Asterisk 13.29.2 with chan_dongle and SIP.
My extension.conf is:
[globals]
USER_1=MY_USERNAME
DONGLE_0=dongle0
[general]
autofallthrough=yes
;----------------------------------------------------------------------------------------------------------------------------------------------------
[macro-sip_qos]
exten => s,1,set(PACKETS_RECEIVED=${CHANNEL(rtpqos,audio,rxcount)})
exten => s,n,Verbose(******************************)
exten => s,n,set(PACKETS_SENT=${CHANNEL(rtpqos,audio,txcount)})
exten => s,n,set(RECV_PACKETS_LOST=${CHANNEL(rtpqos,audio,rxploss)})
exten => s,n,set(SENT_PACKETS_LOST=${CHANNEL(rtpqos,audio,txploss)})
exten => s,n,Set(JITTER_RECV=${MATH(${MATH(${RECV_PACKETS_LOST}/${PACKETS_RECEIVED}),float)}*100,float)}); Calculating loss of Received packets in %
exten => s,n,Set(JITTER_SENT=${MATH(${MATH(${SENT_PACKETS_LOST}/${PACKETS_SENT}),float)}*100,float)}); Calculating loss of Sent packets in %
exten => s,n,set(JITTER_RECV_ROUNDED=${SHELL(printf "%.2f\n" $(echo "${JITTER_RECV}" | bc -l))}); Rounding float numbers to two decimals (13.2164 -> 13.22)
exten => s,n,set(JITTER_SENT_ROUNDED=${SHELL(printf "%.2f\n" $(echo "${JITTER_SENT}" | bc -l))}); Rounding float numbers to two decimals (13.2164 -> 13.22)
exten => s,n,set(PING_MIN=${SHELL(printf "%.0f\n" $(echo "${MATH(${CHANNEL(rtpqos,audio,minrtt)}*1000))}" | bc -l))}); Rounding on int ping_min average value (53.499 -> 53)
exten => s,n,set(PING_AVERAGE=${SHELL(printf "%.0f\n" $(echo "${MATH(${CHANNEL(rtpqos,audio,rtt)}*1000))}" | bc -l))}); Rounding on int ping average value (53.499 -> 53)
exten => s,n,set(PING_MAX=${SHELL(printf "%.0f\n" $(echo "${MATH(${CHANNEL(rtpqos,audio,maxrtt)}*1000))}" | bc -l))}); Rounding on int ping_max average value(53.501 -> 54)
exten => s,n,NoOp(Local RECV Jitter: ${CHANNEL(rtpqos,audio,rxjitter)})
exten => s,n,NoOp(Local SENT Jitter: ${CHANNEL(rtpqos,audio,txjitter)})
exten => s,n,NoOp(Local Jitter Max: ${CHANNEL(rtpqos,audio,local_maxjitter)})
exten => s,n,NoOp(Remote Jitter Max: ${CHANNEL(rtpqos,audio,remote_maxjitter)})
exten => s,n,NoOp(ALL: ${CHANNEL(rtpqos,audio,all)})
exten => s,n,NoOp(Local Jitter Min: ${CHANNEL(rtpqos,audio,local_minjitter)})
;----------------------------------------------------------------------------------------------------------------------------------------------------
;----------------------------------------------------------------------------------------------------------------------------------------------------
[macro-before-call-066]
exten => s,1,AGI(dongle_stat.sh,"${USER_1}","${DONGLE_0}")
same => n,Set(CDR(start_)=${SHELL(date "+%H:%M:%S %d.%b.%Y")})
same => n,set(CDR(codec1)=${CHANNEL(audioreadformat)})
same => n,set(CDR(codec2)=${CHANNEL(audiowriteformat)})
exten => h,1,macro(sip_qos)
;----------------------------------------------------------------------------------------------------------------------------------------------------
;----------------------------------------------------------------------------------------------------------------------------------------------------
[macro-after-incoming_CALL-066]
exten => s,1,System(STRFTIME(${EPOCH},,%d.%m.%Y | %H:%M:%S))
same => n,set(CDR(duration_)=${CDR(duration)})
same => n,set(CDR(codec1)=${CHANNEL(audioreadformat)})
same => n,set(CDR(codec2)=${CHANNEL(audiowriteformat)})
same => n,Verbose(${USER_AGENT})
same => n,macro(sip_qos)
same => n,Hangup()
;----------------------------------------------------------------------------------------------------------------------------------------------------
;----------------------------------------------------------------------------------------------------------------------------------------------------
[066-incoming_CALL]
exten => s,1,Macro(before-call-066)
same => n,System(echo '${STRFTIME(${EPOCH},,%d.%m.%Y | %H:%M:%S)} - Incoming call from: ${CALLERID(num)}' >> /var/log/asterisk/incoming-calls.txt)
same => n,Dial(SIP/${USER_1})
same => n,Hangup()
exten => h,1,Macro(after-incoming_CALL-066)
same => n,Hangup()
;----------------------------------------------------------------------------------------------------------------------------------------------------
;----------------------------------------------------------------------------------------------------------------------------------------------------
[macro-after-outgoing_CALL-066]
exten => s,1,System(STRFTIME(${EPOCH},,%d.%m.%Y | %H:%M:%S))
;same => n,set(CDR(call_from_full)=${CHANNEL(from)})
same => n,macro(sip_qos)
same => n,Hangup()
;----------------------------------------------------------------------------------------------------------------------------------------------------
;----------------------------------------------------------------------------------------------------------------------------------------------------
[outgoing_CALL-066]
exten => _0[1,2,3,6,800].,1,Macro(before-call-066);
same => n,System(echo '${STRFTIME(${EPOCH},,%d.%m.%Y %H:%M:%S)} - Called Number: ${EXTEN}' >> /var/log/asterisk/outgoing-calls.txt);
same => n,Set(Called_number=${EXTEN});
same => n,Dial(Dongle/${DONGLE_0}/${EXTEN});
same => n,Hangup()
exten => _+381[1,2,3,6,800].,1,Macro(before-call-066)
same => n,System(echo '${STRFTIME(${EPOCH},,%d.%m.%Y %H:%M:%S)} - Called Number: ${EXTEN}' >> /var/log/asterisk/outgoing-calls.txt);
same => n,Set(Called_number=${EXTEN});
same => n,Dial(Dongle/${DONGLE_0}/${EXTEN})
same => n,Hangup();
exten => h,1,Macro(after-outgoing_CALL-066)
same => n,Hangup()
;----------------------------------------------------------------------------------------------------------------------------------------------------
The problem with what I faceing is that when I make an outgoing call my “sip_qos” macro working correctly and it is able to pick up data from channel.
Here are the result from CLI:
== Using SIP RTP CoS mark 5
> 0x2848808 -- Strict RTP learning after remote address set to: 192.168.xx.xxx:4068
-- Executing [+381xxxxxxxx@outgoing_CALL-066:1] Macro("SIP/MY_USERNAME-0000004b", "before-call-066") in new stack
-- Executing [s@macro-before-call-066:1] AGI("SIP/MY_USERNAME-0000004b", "dongle_stat.sh,"MY_USERNAME","dongle0"") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dongle_stat.sh
-- Remote UNIX connection
-- Remote UNIX connection disconnected
-- Remote UNIX connection
-- Remote UNIX connection disconnected
-- <SIP/MY_USERNAME-0000004b>AGI Script dongle_stat.sh completed, returning 0
-- Executing [s@macro-before-call-066:2] Set("SIP/MY_USERNAME-0000004b", "CDR(start_)=03:20:46 23.Feb.2020
-- ") in new stack
-- Executing [s@macro-before-call-066:3] Set("SIP/MY_USERNAME-0000004b", "CDR(codec1)=ulaw") in new stack
-- Executing [s@macro-before-call-066:4] Set("SIP/MY_USERNAME-0000004b", "CDR(codec2)=ulaw") in new stack
-- Executing [+381xxxxxxxx@outgoing_CALL-066:2] System("SIP/MY_USERNAME-0000004b", "echo '23.02.2020 03:20:46 - Called Number: +381xxxxxxxx' >> /var/log/asterisk/outgoing-calls.txt") in new stack
-- Executing [+381xxxxxxxx@outgoing_CALL-066:3] Set("SIP/MY_USERNAME-0000004b", "Called_number=+381xxxxxxxx") in new stack
-- Executing [+381xxxxxxxx@outgoing_CALL-066:4] Dial("SIP/MY_USERNAME-0000004b", "Dongle/dongle0/+381xxxxxxxx") in new stack
-- Called Dongle/dongle0/+381xxxxxxxx
-- Dongle/dongle0-010000004b is making progress passing it to SIP/MY_USERNAME-0000004b
> 0x2848808 -- Strict RTP switching to RTP target address 192.168.xx.xxx:4068 as source
> 0x2848808 -- Strict RTP learning complete - Locking on source address 192.168.xx.xxx:4068
-- Dongle/dongle0-010000004b answered SIP/MY_USERNAME-0000004b
-- Channel Dongle/dongle0-010000004b joined 'simple_bridge' basic-bridge <985df83b-6074-494e-a2bb-8a1d6813fc72>
-- Channel SIP/MY_USERNAME-0000004b joined 'simple_bridge' basic-bridge <985df83b-6074-494e-a2bb-8a1d6813fc72>
[Feb 23 03:20:52] WARNING[9160][C-0000004d]: chan_iax2.c:1241 jb_warning_output: Resyncing the jb. last_delay 0, this delay -5111, threshold 1000, new offset 5111
[Feb 23 03:20:56] WARNING[9248][C-0000004d]: channel.c:1079 channel_indicate: [Dongle/dongle0-010000004b] Don't know how to indicate condition 32
-- Channel SIP/MY_USERNAME-0000004b left 'simple_bridge' basic-bridge <985df83b-6074-494e-a2bb-8a1d6813fc72>
-- Channel Dongle/dongle0-010000004b left 'simple_bridge' basic-bridge <985df83b-6074-494e-a2bb-8a1d6813fc72>
== Spawn extension (outgoing_CALL-066, +381xxxxxxxx, 4) exited non-zero on 'SIP/MY_USERNAME-0000004b'
-- Executing [h@outgoing_CALL-066:1] Macro("SIP/MY_USERNAME-0000004b", "after-outgoing_CALL-066") in new stack
-- Executing [s@macro-after-outgoing_CALL-066:1] System("SIP/MY_USERNAME-0000004b", "STRFTIME(1582424465,,%d.%m.%Y | %H:%M:%S)") in new stack
-- Executing [s@macro-after-outgoing_CALL-066:2] Macro("SIP/MY_USERNAME-0000004b", "sip_qos") in new stack
-- Executing [s@macro-sip_qos:1] Set("SIP/MY_USERNAME-0000004b", "PACKETS_RECEIVED=916") in new stack
-- Executing [s@macro-sip_qos:2] Verbose("SIP/MY_USERNAME-0000004b", "******************************") in new stack
******************************
-- Executing [s@macro-sip_qos:3] Set("SIP/MY_USERNAME-0000004b", "PACKETS_SENT=697") in new stack
-- Executing [s@macro-sip_qos:4] Set("SIP/MY_USERNAME-0000004b", "RECV_PACKETS_LOST=0") in new stack
-- Executing [s@macro-sip_qos:5] Set("SIP/MY_USERNAME-0000004b", "SENT_PACKETS_LOST=0") in new stack
-- Executing [s@macro-sip_qos:6] Set("SIP/MY_USERNAME-0000004b", "JITTER_RECV=0.000000") in new stack
-- Executing [s@macro-sip_qos:7] Set("SIP/MY_USERNAME-0000004b", "JITTER_SENT=0.000000") in new stack
-- Executing [s@macro-sip_qos:8] Set("SIP/MY_USERNAME-0000004b", "JITTER_RECV_ROUNDED=0.00
-- ") in new stack
-- Executing [s@macro-sip_qos:9] Set("SIP/MY_USERNAME-0000004b", "JITTER_SENT_ROUNDED=0.00
-- ") in new stack
-- Executing [s@macro-sip_qos:10] Set("SIP/MY_USERNAME-0000004b", "PING_MIN=2
-- ") in new stack
-- Executing [s@macro-sip_qos:11] Set("SIP/MY_USERNAME-0000004b", "PING_AVERAGE=2
-- ") in new stack
-- Executing [s@macro-sip_qos:12] Set("SIP/MY_USERNAME-0000004b", "PING_MAX=2
-- ") in new stack
-- Executing [s@macro-sip_qos:13] NoOp("SIP/MY_USERNAME-0000004b", "Local RECV Jitter: 0.000000") in new stack
-- Executing [s@macro-sip_qos:14] NoOp("SIP/MY_USERNAME-0000004b", "Local SENT Jitter: 0.000504") in new stack
-- Executing [s@macro-sip_qos:15] NoOp("SIP/MY_USERNAME-0000004b", "Local Jitter Max: 0.023731") in new stack
-- Executing [s@macro-sip_qos:16] NoOp("SIP/MY_USERNAME-0000004b", "Remote Jitter Max: 6.000000") in new stack
-- Executing [s@macro-sip_qos:17] NoOp("SIP/MY_USERNAME-0000004b", "ALL: ssrc=848396944;themssrc=68506390;lp=0;rxjitter=0.000000;rxcount=916;txjitter=0.000504;txcount=697;rlp=0;rtt=0.001922") in new stack
-- Executing [s@macro-sip_qos:18] NoOp("SIP/MY_USERNAME-0000004b", "Local Jitter Min: 0.000017") in new stack
-- Executing [s@macro-after-outgoing_CALL-066:3] Hangup("SIP/MY_USERNAME-0000004b", "") in new stack
== Spawn extension (macro-after-outgoing_CALL-066, s, 3) exited non-zero on 'SIP/MY_USERNAME-0000004b' in macro 'after-outgoing_CALL-066'
== Spawn extension (outgoing_CALL-066, h, 1) exited non-zero on 'SIP/MY_USERNAME-0000004b'
The problem start if I get the incoming call. In this case I can not get the sip qos parameters and it yell errors : Unknown or unavailable item requested…
CLI output in case of incoming call:
Connected to Asterisk 13.29.2 currently running on orangepipc (pid = 6035)
-- Executing [s@066-incoming_CALL:1] Macro("Dongle/dongle0-010000004c", "before-call-066") in new stack
-- Executing [s@macro-before-call-066:1] AGI("Dongle/dongle0-010000004c", "dongle_stat.sh,"MY_USERNAME","dongle0"") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dongle_stat.sh
-- Remote UNIX connection
-- Remote UNIX connection disconnected
-- Remote UNIX connection
-- Remote UNIX connection disconnected
-- <Dongle/dongle0-010000004c>AGI Script dongle_stat.sh completed, returning 0
-- Executing [s@macro-before-call-066:2] Set("Dongle/dongle0-010000004c", "CDR(start_)=03:22:10 23.Feb.2020
-- ") in new stack
-- Executing [s@macro-before-call-066:3] Set("Dongle/dongle0-010000004c", "CDR(codec1)=slin") in new stack
-- Executing [s@macro-before-call-066:4] Set("Dongle/dongle0-010000004c", "CDR(codec2)=slin") in new stack
-- Executing [s@066-incoming_CALL:2] System("Dongle/dongle0-010000004c", "echo '23.02.2020 | 03:22:10 - Incoming call from: 3735' >> /var/log/asterisk/incoming-calls.txt") in new stack
-- Executing [s@066-incoming_CALL:3] Dial("Dongle/dongle0-010000004c", "SIP/MY_USERNAME") in new stack
== Using SIP RTP CoS mark 5
-- Called SIP/MY_USERNAME
-- SIP/MY_USERNAME-0000004c is ringing
-- SIP/MY_USERNAME-0000004c is ringing
-- SIP/MY_USERNAME-0000004c is ringing
> 0xb4241ca8 -- Strict RTP learning after remote address set to: 192.168.xx.xxx:4070
-- SIP/MY_USERNAME-0000004c answered Dongle/dongle0-010000004c
-- Channel SIP/MY_USERNAME-0000004c joined 'simple_bridge' basic-bridge <a2fd3407-cb4a-430d-ac4c-7ed3e6cb16d8>
-- Channel Dongle/dongle0-010000004c joined 'simple_bridge' basic-bridge <a2fd3407-cb4a-430d-ac4c-7ed3e6cb16d8>
> 0xb4241ca8 -- Strict RTP switching to RTP target address 192.168.xx.xxx:4070 as source
> 0xb4241ca8 -- Strict RTP learning complete - Locking on source address 192.168.xx.xxx:4070
-- Channel SIP/MY_USERNAME-0000004c left 'simple_bridge' basic-bridge <a2fd3407-cb4a-430d-ac4c-7ed3e6cb16d8>
-- Channel Dongle/dongle0-010000004c left 'simple_bridge' basic-bridge <a2fd3407-cb4a-430d-ac4c-7ed3e6cb16d8>
== Spawn extension (066-incoming_CALL, s, 3) exited non-zero on 'Dongle/dongle0-010000004c'
-- Executing [h@066-incoming_CALL:1] Macro("Dongle/dongle0-010000004c", "after-incoming_CALL-066") in new stack
-- Executing [s@macro-after-incoming_CALL-066:1] System("Dongle/dongle0-010000004c", "STRFTIME(1582424545,,%d.%m.%Y | %H:%M:%S)") in new stack
-- Executing [s@macro-after-incoming_CALL-066:2] Set("Dongle/dongle0-010000004c", "CDR(duration_)=15") in new stack
-- Executing [s@macro-after-incoming_CALL-066:3] Set("Dongle/dongle0-010000004c", "CDR(codec1)=slin") in new stack
-- Executing [s@macro-after-incoming_CALL-066:4] Set("Dongle/dongle0-010000004c", "CDR(codec2)=slin") in new stack
-- Executing [s@macro-after-incoming_CALL-066:5] Verbose("Dongle/dongle0-010000004c", "CSipSimple_sagit-26/r2470") in new stack
CSipSimple_sagit-26/r2470
-- Executing [s@macro-after-incoming_CALL-066:6] Macro("Dongle/dongle0-010000004c", "sip_qos") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,rxcount'
-- Executing [s@macro-sip_qos:1] Set("Dongle/dongle0-010000004c", "PACKETS_RECEIVED=") in new stack
-- Executing [s@macro-sip_qos:2] Verbose("Dongle/dongle0-010000004c", "******************************") in new stack
******************************
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,txcount'
-- Executing [s@macro-sip_qos:3] Set("Dongle/dongle0-010000004c", "PACKETS_SENT=") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,rxploss'
-- Executing [s@macro-sip_qos:4] Set("Dongle/dongle0-010000004c", "RECV_PACKETS_LOST=") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,txploss'
-- Executing [s@macro-sip_qos:5] Set("Dongle/dongle0-010000004c", "SENT_PACKETS_LOST=") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
-- Executing [s@macro-sip_qos:6] Set("Dongle/dongle0-010000004c", "JITTER_RECV=") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
-- Executing [s@macro-sip_qos:7] Set("Dongle/dongle0-010000004c", "JITTER_SENT=") in new stack
-- Executing [s@macro-sip_qos:8] Set("Dongle/dongle0-010000004c", "JITTER_RECV_ROUNDED=0.00
-- ") in new stack
-- Executing [s@macro-sip_qos:9] Set("Dongle/dongle0-010000004c", "JITTER_SENT_ROUNDED=0.00
-- ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,minrtt'
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
-- Executing [s@macro-sip_qos:10] Set("Dongle/dongle0-010000004c", "PING_MIN=0
-- ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,rtt'
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
-- Executing [s@macro-sip_qos:11] Set("Dongle/dongle0-010000004c", "PING_AVERAGE=0
-- ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,maxrtt'
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_math.c:264 math: '' is not a valid number
-- Executing [s@macro-sip_qos:12] Set("Dongle/dongle0-010000004c", "PING_MAX=0
-- ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,rxjitter'
-- Executing [s@macro-sip_qos:13] NoOp("Dongle/dongle0-010000004c", "Local RECV Jitter: ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,txjitter'
-- Executing [s@macro-sip_qos:14] NoOp("Dongle/dongle0-010000004c", "Local SENT Jitter: ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,local_maxjitter'
-- Executing [s@macro-sip_qos:15] NoOp("Dongle/dongle0-010000004c", "Local Jitter Max: ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,remote_maxjitter'
-- Executing [s@macro-sip_qos:16] NoOp("Dongle/dongle0-010000004c", "Remote Jitter Max: ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,all'
-- Executing [s@macro-sip_qos:17] NoOp("Dongle/dongle0-010000004c", "ALL: ") in new stack
[Feb 23 03:22:25] WARNING[11494][C-0000004e]: func_channel.c:460 func_channel_read: Unknown or unavailable item requested: 'rtpqos,audio,local_minjitter'
-- Executing [s@macro-sip_qos:18] NoOp("Dongle/dongle0-010000004c", "Local Jitter Min: ") in new stack
-- Executing [s@macro-after-incoming_CALL-066:7] Hangup("Dongle/dongle0-010000004c", "") in new stack
== Spawn extension (macro-after-incoming_CALL-066, s, 7) exited non-zero on 'Dongle/dongle0-010000004c' in macro 'after-incoming_CALL-066'
== Spawn extension (066-incoming_CALL, h, 1) exited non-zero on 'Dongle/dongle0-010000004c'
What I’m doing wrong?
I tried even without macros, I tryed to put even in front of Hangup, but allways same error.
Can someone guide me how to solve this problem?
Even what is interesting is that in case of outgoing call with functions:
same => n,set(CDR(codec1)=${CHANNEL(audioreadformat)})
same => n,set(CDR(codec2)=${CHANNEL(audiowriteformat)})
I got a correct reading of used codec (in this case ulaw), but in case of incoming call with same functions it read codec slin. (But it is set just to be used ulaw)
Why?
Thanks.