atefsaeed2010 / datacard

Automatically exported from code.google.com/p/datacard
Other
0 stars 1 forks source link

disconnect using datacardsendsms in manager with wrong number #55

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago
If wrong number is used

action: datacardsendsms
actionid: 4
device: datacard1
number: 3456
message: jelow

then

[Jan 24 23:10:04] ERROR[26006]: chan_datacard.c:426 do_monitor_phone: 
[datacard1] timedout while waiting 'OK' in response to 'SMSTEXT'
    -- [datacard1] Datacard has disconnected
    -- [datacard1] Trying to connect on /dev/ttyUSB2...
    -- [datacard1] Datacard has connected, initializing...
    -- [datacard1] Datacard initialized and ready

Original issue reported on code.google.com by pag...@gmail.com on 24 Jan 2011 at 10:12

GoogleCodeExporter commented 9 years ago
added debug:

[Jan 24 23:23:58] DEBUG[26029]: manager.c:3052 process_message: Manager 
received command 'datacardsendsms'
[Jan 24 23:23:58] DEBUG[26029]: at_queue.c:129 at_queue_add: [datacard1] insert 
task with 2 commands begin with 'AT+CMGS' expected response '> ' at tail of 
queue
[Jan 24 23:23:58] DEBUG[26029]: at_queue.c:249 at_queue_run: [datacard1] write 
command 'AT+CMGS' expected response '> ' length 11
]Jan 24 23:23:58] DEBUG[26029]: at_queue.c:194 at_write: [datacard1] [AT+CMGS=14
[Jan 24 23:23:58] DEBUG[26028]: at_read.c:82 at_read: [datacard1] receive 4 
byte, used 4, free 2044, read 0, write 4
[Jan 24 23:23:58] DEBUG[26028]: at_read.c:97 at_read: [datacard1] [
> ]
[Jan 24 23:23:58] DEBUG[26028]: at_queue.c:224 at_queue_remove_cmd: [datacard1] 
remove command 'AT+CMGS' expected response '> ' real '> ' cmd 1/2 flags 0x00 
from queue
[Jan 24 23:23:58] DEBUG[26028]: at_queue.c:249 at_queue_run: [datacard1] write 
command 'SMSTEXT' expected response 'OK' length 31
[Jan 24 23:23:58] DEBUG[26028]: at_queue.c:194 at_write: [datacard1] 
[001100049121430000A904E8373B0C]
[Jan 24 23:23:58] DEBUG[26028]: at_read.c:82 at_read: [datacard1] receive 2 
byte, used 2, free 2046, read 0, write 2

and then after a while

[24/01/11 23:24:52] paketecuento: [Jan 24 23:24:13] ERROR[26028]: 
chan_datacard.c:426 do_monitor_phone: [datacard1] timedout while waiting 'OK' 
in response to 'SMSTEXT'
[Jan 24 23:24:13] DEBUG[26028]: chan_datacard.c:427 do_monitor_phone: 
[datacard1] timedout while waiting 'OK' in response to 'SMSTEXT'
[Jan 24 23:24:13] DEBUG[26028]: at_queue.c:72 at_queue_remove: [datacard1] 
remove task with 2 command(s) begin with 'AT+CMGS' expected response '> ' from 
queue
    -- [datacard1] Datacard has disconnected

Original comment by pag...@gmail.com on 24 Jan 2011 at 10:26

GoogleCodeExporter commented 9 years ago
may be 15 seconds not enought for SMSC response?

Original comment by bg_...@mail.ru on 24 Jan 2011 at 10:58

GoogleCodeExporter commented 9 years ago
no, need 40 seconds to get 

+CMS ERROR: 500

 :)

Original comment by pag...@gmail.com on 24 Jan 2011 at 11:29

GoogleCodeExporter commented 9 years ago
Problem is:

queue of AT-commands to modem stopped until this timeout, 
and no new commands issued to modem until response to SMS send 
command.

I think not right behaviour waiting until SMS send (or error returned)
with module intended for voice features.

I think intermix SMS and voice for Huawei dongles is bad idea, anybody 
free to use something like smstools and one more dongle for SMS, not for voice 
call.

Maximum that i can do, move control of timeout value to 
configuration file setting.

My decision: i will reduce development of SMS part of chan_datacard to major 
bugfixed only.

Other peoples, of course, free to continue develop SMS support in chan_datacard.

Original comment by bg_...@mail.ru on 28 Jan 2011 at 4:11

GoogleCodeExporter commented 9 years ago
I have a similar problem .. but I don't understand why !

http://wiki.d3xt3r01.tk/index.php/PHP_7bit_PDU_generator

dexter@d3xt3r01 ~/public_html/work_rac/at_modem_command $ php
modem.php 0760905294 "123456789 123456789 123456789 123456789
123456789 123456789 123456789 123456789 123456789 123456789 123456789
123456789 123456789 123456789 123456789 123456789"
HEADER:
Smsc Info Length: 07
Smsc Number Format: 91
Smsc: 0467060015F0
FirstOctet: 0100
Destination Number Length: 0a
Destination Number Format: 81
Destination Number: 7006092549
Proto ID: 00
Data Encoding: 10
Valid Period:
User Data Size: 9f
------------------
DCS: 16
Header: 07910467060015F001000A81700609254900109F
Output: 
31d98c56b3dd7039504c36a3d56c375c0e1493cd6835db0d9703c564335acd76c3e54031d98c56b3
dd7039504c36a3d56c375c0e1493cd6835db0d9703c564335acd76c3e54031d98c56b3dd7039504c
36a3d56c375c0e1493cd6835db0d9703c564335acd76c3e54031d98c56b3dd7039504c36a3d56c37
5c0e1493cd6835db0d9703c564335acd76c3e500
PDU: 
07910467060015F001000A81700609254900109F31D98C56B3DD7039504C36A3D56C375C0E1493CD
6835DB0D9703C564335ACD76C3E54031D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D97
03C564335ACD76C3E54031D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D9703C564335A
CD76C3E54031D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D9703C564335ACD76C3E500
AT+CMGS=152
-----------------------------

Here's what I send to the modem ...
AT+CMGF=0
OK
AT+CSMS=0
+CSMS: 1,1,1
OK
AT+CMGS=152
>07910467060015F001000A81700609254900109F31D98C56B3DD7039504C36A3D56C375C0E1493C
D6835DB0D9703C564335ACD76C3E54031D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D9
703C564335ACD76C3E54031D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D9703C5640
+CMGS: 35
OK
And I do receive the message .. 

So the modem is sending out PDU messages just fine .. 

I also see that on a debug output earlier it is waiting for '> ' .. I only get 
'>' ( without the extra space ) .. 

This is my output debug

   -- [datacard1] Trying to connect on /dev/ttyUSB5...
   -- [datacard1] Datacard has connected, initializing...
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:1831 at_response:
[datacard1] Got AT_CGMI data (manufacturer info)
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:1835 at_response:
[datacard1] Got AT_CGMM data (model info)
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:1839 at_response:
[datacard1] Got AT+CGMR data (firmware info)
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:1843 at_response:
[datacard1] Got AT+CGSN data (IMEI number)
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:1847 at_response:
[datacard1] Got AT+CIMI data (IMSI number)
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:149 at_response_ok:
[datacard1] Operator select parameters set
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:153 at_response_ok:
[datacard1] registration info enabled
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:157 at_response_ok:
[datacard1] registration query sent
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:161 at_response_ok:
[datacard1] Subscriber phone number query successed
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:165 at_response_ok:
[datacard1] Datacard has voice support
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:791 at_response_csca:
[datacard1] CSCA: +40766000510
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:175 at_response_ok:
[datacard1] Supplementary Service Notification enabled successful
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:180 at_response_ok:
[datacard1] SMS operation mode set to PDU
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:184 at_response_ok:
[datacard1] UCS-2 text encoding enabled
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:190 at_response_ok:
[datacard1] SMS storage location is established
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:194 at_response_ok:
[datacard1] SMS new message indication enabled
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:195 at_response_ok:
[datacard1] Datacard has sms support
   -- [datacard1] Datacard initialized and ready
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:291 at_response_ok:
[datacard1] Got signal strength result
[Feb  8 13:08:22] DEBUG[28253]: at_response.c:279 at_response_ok:
[datacard1] Provider query successfully
[Feb  8 13:08:24] NOTICE[28253]: at_response.c:1078 at_response_ccwa:
Call waiting is disabled on device datacard1

*CLI> datacard sms datacard1 0760905294 123456789 123456789 123456789
[datacard1] SMS queued for send with id 0xdce980
*CLI> [Feb  8 13:11:29] DEBUG[28253]: at_response.c:1853 at_response:
[datacard1] Ignoring unknown result: ''
[Feb  8 13:11:41] ERROR[28253]: chan_datacard.c:439 do_monitor_phone:
[datacard1] timedout while waiting 'OK' in response to 'SMSTEXT'
[Feb  8 13:11:41] DEBUG[28253]: chan_datacard.c:440 do_monitor_phone:
[datacard1] timedout while waiting 'OK' in response to 'SMSTEXT'
   -- [datacard1] Datacard has disconnected
[Feb  8 13:11:41] DEBUG[28253]: chan_datacard.c:340
disconnect_datacard: [datacard1] Datacard disconnected
   -- [datacard1] Trying to connect on /dev/ttyUSB5...
   -- [datacard1] Datacard has connected, initializing...
[Feb  8 13:11:54] ERROR[28268]: chan_datacard.c:439 do_monitor_phone:
[datacard1] timedout while waiting 'OK' in response to 'AT'
[Feb  8 13:11:54] DEBUG[28268]: chan_datacard.c:440 do_monitor_phone:
[datacard1] timedout while waiting 'OK' in response to 'AT'
   -- [datacard1] Error initializing Datacard
   -- [datacard1] Datacard has disconnected
[Feb  8 13:11:54] DEBUG[28268]: chan_datacard.c:340
disconnect_datacard: [datacard1] Datacard disconnected
   -- [datacard1] Trying to connect on /dev/ttyUSB5...
   -- [datacard1] Datacard has connected, initializing...
.... back from the start ...

Why does it use 'smstext' for pdu mode !? :/

Original comment by dex...@d3xt3r01.tk on 8 Feb 2011 at 12:04

GoogleCodeExporter commented 9 years ago
Also, if interested, this is my datacard.conf if needed... using ~amd64 gentoo 
with  net-misc/asterisk-1.8.2.3 ( unmasked .. seems ok and stable )

[general]
interval=15
language=en

[K3520_t](!)
context=incoming-datacard
rxgain=3
txgain=-3
autodeletesms=yes
resetdatacard=yes
u2diag=0
usecallingpres=yes
callingpres=allowed
disablesms=no
smsaspdu=yes

[datacard0](K3520_t)
audio=/dev/ttyUSB1
data=/dev/ttyUSB2
group=1

[datacard1](K3520_t)
audio=/dev/ttyUSB4
data=/dev/ttyUSB5
group=1

*CLI> datacard show devices
ID           Group State      RSSI Mode Submode Provider Name  Model
  Firmware          IMEI             IMSI             Number
datacard0    1     Free       31   3    2       Vodafone RO    K3520
  11.315.05.00.00   3534xxxyyy13105  2260xxxyyy23160  0736xxxyyy
datacard1    1     Free       16   3    3       COSMOTE@       K3520
  11.315.05.00.00   3532xxxyyy13038  2260xxxyyy31224  0785xxxyyy

*CLI> datacard show device settings datacard1
------------- Settings ------------
 Device                  : datacard1
 Audio                   : /dev/ttyUSB4
 Data                    : /dev/ttyUSB5
 IMEI                    :
 IMSI                    :
 Channel Language        : en
 Context                 : incoming-datacard
 Exten                   :
 Group                   : 1
 RX gain                 : 3
 TX gain                 : -3
 U2Diag                  : 0
 Use CallingPres         : Yes
 Default CallingPres     : Presentation Allowed, Network Number
 Auto delete SMS         : Yes
 Disable SMS             : No
 Reset Datacard          : Yes
 SMS PDU                 : No
 Call Waiting            : auto
 DTMF                    : relax
 Minimal DTMF Gap        : 45
 Minimal DTMF Duration   : 80
 Minimal DTMF Interval   : 200

*CLI> datacard show device settings datacard0
------------- Settings ------------
 Device                  : datacard0
 Audio                   : /dev/ttyUSB1
 Data                    : /dev/ttyUSB2
 IMEI                    :
 IMSI                    :
 Channel Language        : en
 Context                 : incoming-datacard
 Exten                   :
 Group                   : 1
 RX gain                 : 3
 TX gain                 : -3
 U2Diag                  : 0
 Use CallingPres         : Yes
 Default CallingPres     : Presentation Allowed, Network Number
 Auto delete SMS         : Yes
 Disable SMS             : No
 Reset Datacard          : Yes
 SMS PDU                 : No
 Call Waiting            : auto
 DTMF                    : relax
 Minimal DTMF Gap        : 45
 Minimal DTMF Duration   : 80
 Minimal DTMF Interval   : 200

Original comment by dex...@d3xt3r01.tk on 8 Feb 2011 at 12:06

GoogleCodeExporter commented 9 years ago
replace value of ATQ_CMD_TIMEOUT_15S if you want.

Original comment by bg_...@mail.ru on 8 Feb 2011 at 2:54

GoogleCodeExporter commented 9 years ago
replaced with 30 .. 

*CLI> [Feb  8 16:13:34] DEBUG[18630]: at_response.c:1853 at_response: 
[datacard1] Ignoring unknown result: ''
    -- [datacard1] Error sending SMS message 0xedc630
[Feb  8 16:14:02] ERROR[18630]: at_response.c:509 at_response_error: 
[datacard1] Error sending SMS message 0xedc630

Original comment by dex...@d3xt3r01.tk on 8 Feb 2011 at 2:58

GoogleCodeExporter commented 9 years ago
Solved for me .. the pdu sent was
0011000A9170060925490000A92131D98C56B3DD7039504C36A3D56C375C0E1493CD6835DB0D9703
B56130

which if decoded:
SMSC#
Sender:+0760905294
TP_PID:00
TP_DCS:00
TP_DCS-popis:Uncompressed Text
class:0
Alphabet:Default

123456789 123456789 123456789 m00
Length:33

using +0760905294 .. which isn't valid ... as soon as I used my number in 
international format without the + .. worked like a charm .. hope this helps 
others !

Original comment by dex...@d3xt3r01.tk on 8 Feb 2011 at 3:19

GoogleCodeExporter commented 9 years ago
ATQ_CMD_TIMEOUT_15S should be 40 or above to solve these kind of problems, but 
on the other hand, the modem is not acception any command until this timeout... 
:(

Original comment by pag...@gmail.com on 8 Feb 2011 at 3:42

GoogleCodeExporter commented 9 years ago
again gain gain 
currently in PDU mode chan_datacard assume number has international format.
etc/extensions.conf:79

Original comment by bg_...@mail.ru on 8 Feb 2011 at 4:57

GoogleCodeExporter commented 9 years ago
yeah, well .. DAMN ! .. and I thought I read everything ! :| Sorry for the 
stress .. I still learned alot :D

Original comment by dex...@d3xt3r01.tk on 8 Feb 2011 at 7:01