[Home]

Summary:ASTERISK-15426: app_sms hangs on a call sending an sms
Reporter:Marco Ripa (madcowzz)Labels:
Date Opened:2010-01-14 05:06:54.000-0600Date Closed:2011-06-07 14:07:45
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_sms
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I'm not sure it's a bug, I'm new to asterisk and I not found anything on this.
Sending an sms to Telecom Italia smsc (4210) causes app_sms to send the sms and then keeps the line busy waiting for something to happen.
I have modified apps_sms.c in the sms_process function commenting the 1734 line:

// h->idle = 0;

This makes app_sms to send the sms and then drop the line because the idle reaches the 80000 value.
Repeat: I'm not sure this is a bug and is more likely to have something wrong with me.


****** ADDITIONAL INFORMATION ******

I own an OpenVox A400P board with one FXO module.
I send the sms through smsq with this sintax:

smsq --motx-channel=dahdi/1/04210 [NUMBER] [MESSAGE]

Sometimes the message is not sent, but without my workaround the line remains busy.
Comments:By: Marco Ripa (madcowzz) 2010-01-14 06:16:59.000-0600

Working on the code I discovered that the problem depends on the error bad stop bit.
When the error occurs app_sms awaits a response from the server that never comes.
Setting the hangup property of h to 1 when the error occurs the call is properly closed immediately after that the message is sent.
So, on line 1799 I added:

if (!bit) {             /* bad stop bit */
ast_log(LOG_NOTICE, "bad stop bit");
                                               h->hangup = 1;
h->ierr = 0xFF;     /* unknown error */

I restored the line 1734, of course.
By: Leif Madsen (lmadsen) 2010-01-14 06:53:02.000-0600

This is actually likely a problem with disconnect supervision on your analog lines. This may or may not be enabled on the lines. Make sure you're using KS (kewlstart) signaling. This may also be something that needs to be enabled by your telco on the line to allow disconnect supervision to happen. I'd err on the side of this not being a bug.
By: Marco Ripa (madcowzz) 2010-01-14 07:58:53.000-0600

This is my dahdi_channels.conf:

; Span 1: WCTDM/4 "Wildcard TDM400P REV E/F Board 5" (MASTER)
;;; line="1 WCTDM/4/0 FXSKS"
signalling=fxs_ks
callerid=asreceived
group=0
context=from-pstn
channel => 1
callerid=
group=
context=default

I don't know how to verify if the disconnect supervision is enabled or not. If you could give me some suggestions.
If my problem is not solvable, would not be fair to add my fix as a feature? maybe with some kind of timeout.
By: Leif Madsen (lmadsen) 2010-01-14 08:59:03.000-0600

The disconnect supervision stuff is enabled in the /etc/dahdi/ directory, and not in chan_dahdi (it's a hardware thing, not an Asterisk thing).

The only way to determine if you have disconnect supervision on the line is to call your telco.

Also, feature requests without patches are not handled on the issue tracker. You'll get better luck if you request it on asterisk-biz with a bounty.
By: Leif Madsen (lmadsen) 2010-01-14 08:59:28.000-0600

Closing for now as this is likely a hardware issue, or telco line issue.
By: David Woodhouse (dwmw2a) 2011-08-21 17:13:38.232-0500

I see the same problem on an ISDN BRI (B200P). It seems unlikely to be disconnect signalling. And even when the original reported saw it on an analogue line, it was an *outgoing* call. Surely there's nothing complicated about hanging up an *outbound* call?

I'm just replacing my ancient Asterisk 1.2 system, on which app_sms was working fine to British Telecom over BRI ISDN. With 1.8 when I run 'smsq' Asterisk doesn't seem to do anything. It doesn't actually attempt to send the message until I restart Asterisk, and then I get:

{noformat}
   -- Attempting call on Local/17094009 for application SMS(0) (Retry 1)
   -- Executing [17094009@default:1] Dial("Local/17094009@default-2ac7;2", "DAHDI/G12/17094009") in new stack
   -- Requested transfer capability: 0x00 - SPEECH
   -- Called DAHDI/G12/17094009
   -- DAHDI/i2/17094009-1 is proceeding passing it to Local/17094009@default-2ac7;2
   -- DAHDI/i2/17094009-1 answered Local/17094009@default-2ac7;2
      > Channel Local/17094009@default-2ac7;1 was answered.
      > Launching SMS(0) on Local/17094009@default-2ac7;1
sms argc 1 queue <0> opts <> addr <> body <>
initial delay 300ms
   -- SMS TX 7F 00
 == Spawn extension (default, 17094009, 1) exited non-zero on 'Local/17094009@default-2ac7;2'
[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:04] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:06] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:08] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:08] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:08] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:08] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:09] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:10] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:10] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:10] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:10] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:11] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:11] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:11] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:11] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:13] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:14] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:14] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:15] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:15] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:15] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:15] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:16] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:16] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:16] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:16] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:18] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:20] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:20] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:20] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:20] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:21] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:21] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:21] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:21] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1800 sms_process: bad stop bit[Aug 21 23:10:23] NOTICE[7257]: app_sms.c:1723 sms_process: Error 255, hanging up
   -- SMS TX 92 01 FF
   -- Span 2: Channel 0/2 got hangup, cause 16
[Aug 21 23:10:24] NOTICE[7257]: app_sms.c:2032 sms_exec: ast_read failed
   -- Hungup 'DAHDI/i2/17094009-1'
[Aug 21 23:10:24] NOTICE[7257]: pbx_spool.c:362 attempt_thread: Call completed to Local/17094009
{noformat}
By: David Woodhouse (dwmw2a) 2011-08-22 05:16:02.956-0500

Oh, I see. It's not us hanging up; it's the recipient of the call. And yes, there's definitely something weird going on. We are *told* of the hangup, but we still keep trying to read data...

{noformat}
   -- SMS RX 95 09 01 00 11 80 22 11 31 93 40 99
   -- SMS TX 94 00
PRI Span: 2
PRI Span: 2 < Protocol Discriminator: Q.931 (8)  len=12
PRI Span: 2 < TEI=106 Call Ref: len= 1 (reference 6/0x6) (Sent to originator)
PRI Span: 2 < Message Type: DISCONNECT (69)
PRI Span: 2 < [08 02 80 90]
PRI Span: 2 < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0)  Spare: 0  Location: User (0)
PRI Span: 2 <                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
PRI Span: 2 < [1e 02 82 88]
PRI Span: 2 < Progress Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0)  0: 0  Location: Public network serving the local user (2)
PRI Span: 2 <                               Ext: 1  Progress Description: Inband information or appropriate pattern now available. (8) ]
PRI Span: 2 Received message for call 0xb70066c0 on link 0x98e8578 TEI/SAPI 106/0
PRI Span: 2 -- Processing IE 8 (cs0, Cause)
PRI Span: 2 -- Processing IE 30 (cs0, Progress Indicator)
PRI Span: 2 -- Found active call: 0xb70066c0 cref:32774
PRI Span: 2 q931.c:8707 post_handle_q931_message: Call 32774 enters state 12 (Disconnect Indication).  Hold state: Idle
[Aug 22 11:13:42] NOTICE[22775]: app_sms.c:1805 sms_process: bad stop bit
[Aug 22 11:13:42] NOTICE[22775]: app_sms.c:1805 sms_process: bad stop bit
[Aug 22 11:13:42] NOTICE[22775]: app_sms.c:1805 sms_process: bad stop bit
[Aug 22 11:13:42] NOTICE[22775]: app_sms.c:1805 sms_process: bad stop bit
{noformat}

By: David Woodhouse (dwmw2a) 2011-08-22 06:27:13.377-0500

Ah, this seems to have been caused by having 'inbanddisconnect=yes' in chan_dahdi.conf.

The {{DISCONNECT}} doesn't then cause a hangup. Is there a way for app_sms to detect a {{DISCONNECT}}? Or is there a way to make the inbanddisconnect work only before the call is established? I want the recorded messages saying "this number has been changed to..." but I don't think I ever want inband audio after a call was *connected* and then disconnects.
By: David Woodhouse (dwmw2) 2011-08-24 08:26:24.151-0500

I have merged a version of this fix into the patch attached to issue ASTERISK-18331

Please test and confirm (in that bug) that it works for you.