Summary:ASTERISK-21722: chan motif behaves wrong
Reporter:Private Name (falves11)Labels:
Date Opened:2013-04-29 10:19:25Date Closed:2013-05-18 22:11:11
Versions:11.3.0 Frequency of
Environment:linux 6.1 redhatAttachments:( 0) asterisk.txt
Description:I am uploading a debug trace. Basically, when my dialer places a call with originate, using chan_local, and then Motif,the channel "thinks" the calls if finished and executes the hangup handler. But the calls is live and well and it can last for hours.
I know it is weird, but I have the trace and I can reproduce it.
The dialer sees the call as Answered on the far end (Motif) and then dials another leg via the same "Local" channel, and I play music on hold.
Comments:By: Rusty Newton (rnewton) 2013-04-29 14:29:51.258-0500

Thank you for taking the time to report this bug and helping to make Asterisk better. Unfortunately, we cannot work on this bug because your description did not include enough information. You may find it helpful to read the Asterisk Issue Guidelines http://www.asterisk.org/developers/bug-guidelines. We would be grateful if you would then provide a more complete description of the problem. At a minimum, we need:

1. the specific steps or actions you took that caused you to encounter the problem,
2. the behavior you expected, and
3. the behavior you actually encountered (in as much detail as possible).

This likely includes output from the console with debug level logging, a SIP trace (if this is SIP related), and configuration information such as dialplan (e.g. extensions.conf) and channel configuration (e.g. sip.conf). Thanks!

Your summary is ambiguous and the description is confusing. I can't tell everything that is happening with only a DEBUG trace. :

*  attach a debug trace with VERBOSE and DEBUG message types enabled (level 5)
*  attach a file showing the dialplan initiated by the local channels.
*  attach motif.conf
*  attach the output of "core show channel <channel>" for the motif channel after the issue occurs.
*  attach the output of "core show hanguphandlers all" as soon as the motif is up.

By: Private Name (falves11) 2013-05-17 20:14:47.989-0500

I invite the engineers to connect to my server directly, while I place a call, and watch the issue. But there is a worse issue with chan_motif. This channel opens a file called /tmp/refs. This file grows unlimitedly and forever, until it reaches several gigs and then Asterisk must be stopped and the file erased. My virtual machines routinely run out of space. That is very traumatic for me. I wish to ask the honorable engineers if there is a workaround for the file issue, or if it is safe to use a Linux command like "truncate file --size=0".
The original issue of the Motif channel is that when the call is initiated with "originate", the Dial command continues, does not remain waiting for the call to close. But the call is well and alive.  

By: Matt Jordan (mjordan) 2013-05-18 11:29:21.890-0500

Several things here.

# The /tmp/refs issue is a bug that was filed under ASTERISK-21785, and was fixed in r388700. It is not yet in a release candidates or a tagged release, but should be in the next RC.
# The issue has not been filed correctly. The instructions linked here by Rusty describe the information that should be provided in an issue.
# The DEBUG log was not generated correctly. When filing issues, please follow the instructions linked here by Rusty.
# This is not a support forum. If you need support, there are multiple ways to get support from the developer community. If you need someone to connect to your machine and provide support, contact the {{asterisk-biz}} mailing list. There are plenty of open source developers who will be willing to provide support for Asterisk.

All of that being said, I'm going to make a few guesses here based on your incomplete log file. *These are guesses. Your log file does not show all of the information needed.*

[Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: channel.c:2661 ast_softhangup_nolock: Soft-Hanging up channel 'Local/19544447408@onsite-0000335e;2'
[Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_stack.c:578 gosub_exec: Channel Local/19544447408@onsite-0000335e;2 has no datastore, so we're allocating one.
[Apr 29 10:11:47] DEBUG[9054][C-00002e7d]: app_stack.c:620 gosub_exec: Setting 'ARG1' to 'args'

The Local channel was hung up, most likely due to a local channel optimization. The next arguments indicate that some GoSub routine was executed on the Local channel's {{;2}} channel. Since hangup handlers are a type of GoSub routine, I'm guessing this is the hangup handler.

Assuming this is correct, then:

The hangup handler was not executed on the Motif channel. It was executed on the Local channel because the Local channel hung up, and because you put the hangup handler on the Local channel instead of the Motif channel. This is a configuration issue and not a bug.

By: Private Name (falves11) 2013-05-18 18:07:44.738-0500

Kindly look at my entire dialplan below. How can I put the hangup handler somewhere else? It does execute when the Motif call is still on.


exten => _X.,1,Set(CHANNEL(hangup_handler_push)=hdlr1,s,1(args))
exten => _X.,n(door),GotoIf($[${LOCK(mutexa)}=1]?:salida)
exten => _X.,n(popping),Set(var=${POP(GLOBAL(data))})
exten => _X.,n,Set(gskip=${MYSQL_GSKIP(${var})})
exten => _X.,n,GotoIf($["${gskip}" > "0"]?popping)
exten => _X.,n,GotoIf($["${var}" = ""]?salida)
exten => _X.,n,Set(R=${UNLOCK(mutexa)})
exten => _X.,n,Set(Target=Motif/google${var}/${EXTEN:-11}@voice.google.com)
exten => _X.,n,Verbose(0,Channel Using ${Target})
exten => _X.,n,Dial(${Target},,D(wwwABCD#)r)
exten => _X.,n,Verbose(0,Channel Using ${Target} ${DIALSTATUS})
exten => _X.,n(salida),Hangup()

exten => s,1,GotoIf($["${REGEX("[1-9]" ${var:0})}" = "0"]?salida)
exten => s,n,Set(R=${LOCK(mutexa)})
exten => s,n,Set(GLOBAL(data)=${var},${GLOBAL(data)})
exten => s,n,Set(R=${UNLOCK(mutexa)})
exten => s,n,Verbose(0,My channels was ${var} for ${CDR(DST)})
exten => s,n(salida),Return()

By: Private Name (falves11) 2013-05-18 18:51:13.718-0500

Note: please remember that the dialer dials Local/${EXTEN}@onsite. This is not a SIP call. In fact, SIP is never in the picture in the entire process. When the call does connect, the dialer sends a second call, again to a Local channel, and I play MusicOnHold. Maybe that is why this behavior is unusual. In theory I could unload chan_sip and it would still work.