Hello Chris,
You said you have been getting 'unexpected result'. What are these unexpected 
results? The report that says "reply: 200 '<< successful >>" shows the url is 
being successfully called. 

I think the "Empty reply from service provider" in the logs shows your php page 
is returning nothing back for the http call. 

You said it works sometimes but not all times, you may have to check the 
stability of your php app, your apache etc. 
 
But a clear explanation of what you mean as not working as expected will help a 
bit. 

Toyin Daniel
-----Original Message-----
From: Christopher Burke <[email protected]>
Sender: [email protected]
Date: Thu, 19 Jul 2012 15:12:11 
To: <[email protected]>
Cc: Deborah Murphy<[email protected]>
Subject: Issue and questions regarding SMS-SERVICE

Hi All,

I have added an sms-service configuration to Kannel, however I am getting
unexpected results. I have tried many different configuration parameters,
however all of these are leading to similar results.

The sms-service configuration is as follows:
group                           = sms-service
keyword = request
get-url                         = "
http://localhost/requestHandler.php?all_word=%a&sender_formatted=%q&sender=%p
"

And my smsbox configuration is:
group                           = smsbox
bearerbox-host                  = localhost
#bearerbox-port = 13000
sendsms-port                    = 13013
global-sender                   = "phone number"
#sendsms-chars                   = "0123456789+" # -+
log-file                        =
"/var/log/kannel/nosql/recv/log_smsbox.log"
log-level                       = 0
access-log                      =
"/var/log/kannel/nosql/recv/acc_smsbox.log"

This works for the first few SMS, however unexpectedly fails. I've tried
for many hours yesterday to do an exact replication of the issue, but I
can't seem to replicate it. I've also tried a more common configuration
which includes setting max-messages to 0 or more, and catch-all to true,
however all of which seem to cause the same issues. There seems to be
nothing offending in the logs, but I've included them below
anyway in-case anybody can help.

An example request I am sending from my sending SMSC to the receiving SMSC
is:

localhost:14013/cgi-bin/sendsms?username=wim&password=wim&to=447797882105
&from=447892010100&text=request *user=foo*hash=bar*request=getProfile

The log output for a successful request on the smsbox access is:

2012-07-19 14:20:34 SMS HTTP-request sender:+447892010100 request: '' url: '
http://localhost/requestHandler.php?all_word=request+*user%3Dfoo*hash%3Dbar*request%3DgetProfile&sender_formatted=%2B447892010100&sender=%2B447892010100'
reply: 200 '<< successful >>'

The the detailed smsbox log is:

2012-07-19 14:20:34 [25774] [4] DEBUG: match found: ^[ ]*(request)[ ]*
2012-07-19 14:20:34 [25774] [4] INFO: Starting to service <request
*user=foo*hash=bar*request=getProfile> from <+447892010100> to
<+447797882105>
2012-07-19 14:20:34 [25774] [4] DEBUG: Started thread 8
(gwlib/fdset.c:poller)
2012-07-19 14:20:34 [25774] [4] DEBUG: Started thread 9
(gwlib/http.c:write_request_thread)
2012-07-19 14:20:34 [25774] [9] DEBUG: Thread 9
(gwlib/http.c:write_request_thread) maps to pid 25774.
2012-07-19 14:20:34 [25774] [9] DEBUG: Queue contains 0 pending requests.
2012-07-19 14:20:34 [25774] [9] DEBUG: Parsing URL `
http://localhost/requestHandler.php?all_word=request+*user%3Dfoo*hash%3Dbar*request%3DgetProfile&sender_formatted=%2B447892010100&sender=%2B447892010100
':
2012-07-19 14:20:34 [25774] [9] DEBUG:   Scheme: http://
2012-07-19 14:20:34 [25774] [9] DEBUG:   Host: localhost
2012-07-19 14:20:34 [25774] [9] DEBUG:   Port: 80
2012-07-19 14:20:34 [25774] [9] DEBUG:   Username: (null)
2012-07-19 14:20:34 [25774] [8] DEBUG: Thread 8 (gwlib/fdset.c:poller) maps
to pid 25774.
2012-07-19 14:20:34 [25774] [9] DEBUG:   Password: (null)
2012-07-19 14:20:34 [25774] [9] DEBUG:   Path: /requestHandler.php
2012-07-19 14:20:34 [25774] [9] DEBUG:   Query:
all_word=request+*user%3Dfoo*hash%3Dbar*request%3DgetProfile&sender_formatted=%2B447892010100&sender=%2B447892010100
2012-07-19 14:20:34 [25774] [9] DEBUG:   Fragment: (null)
2012-07-19 14:20:34 [25774] [9] DEBUG: Connecting nonblocking to <127.0.0.1>
2012-07-19 14:20:34 [25774] [9] DEBUG: HTTP: Opening connection to
`localhost:80' (fd=28).
2012-07-19 14:20:34 [25774] [9] DEBUG: Socket connecting
2012-07-19 14:20:34 [25774] [8] DEBUG: Get info about connecting socket
2012-07-19 14:20:34 [25774] [8] DEBUG: HTTP: Sending request:
2012-07-19 14:20:34 [25774] [8] DEBUG: Octet string at 0x7f87240008e0:
2012-07-19 14:20:34 [25774] [8] DEBUG:   len:  225
2012-07-19 14:20:34 [25774] [8] DEBUG:   size: 1024
2012-07-19 14:20:34 [25774] [8] DEBUG:   immutable: 0
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 47 45 54 20 2f 72 65 71 75
65 73 74 48 61 6e 64   GET /requestHand
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 6c 65 72 2e 70 68 70 3f 61
6c 6c 5f 77 6f 72 64   ler.php?all_word
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 3d 72 65 71 75 65 73 74 2b
2a 75 73 65 72 25 33   =request+*user%3
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 44 66 6f 6f 2a 68 61 73 68
25 33 44 62 61 72 2a   Dfoo*hash%3Dbar*
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 72 65 71 75 65 73 74 25 33
44 67 65 74 50 72 6f   request%3DgetPro
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 66 69 6c 65 26 73 65 6e 64
65 72 5f 66 6f 72 6d   file&sender_form
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 61 74 74 65 64 3d 25 32 42
34 34 37 38 39 32 30   atted=%2B4478920
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 31 30 31 30 30 26 73 65 6e
64 65 72 3d 25 32 42   10100&sender=%2B
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 34 34 37 38 39 32 30 31 30
31 30 30 20 48 54 54   447892010100 HTT
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 50 2f 31 2e 31 0d 0a 48 6f
73 74 3a 20 6c 6f 63   P/1.1..Host: loc
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 61 6c 68 6f 73 74 0d 0a 43
6f 6e 6e 65 63 74 69   alhost..Connecti
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 6f 6e 3a 20 6b 65 65 70 2d
61 6c 69 76 65 0d 0a   on: keep-alive..
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 55 73 65 72 2d 41 67 65 6e
74 3a 20 4b 61 6e 6e   User-Agent: Kann
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 65 6c 2f 73 76 6e 2d 72 34
39 38 30 4d 0d 0a 0d   el/svn-r4980M...
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 0a
                     .
2012-07-19 14:20:34 [25774] [8] DEBUG: Octet string dump ends.
2012-07-19 14:20:34 [25774] [8] DEBUG: HTTP: Status line: <HTTP/1.1 200 OK>
2012-07-19 14:20:34 [25774] [8] DEBUG: HTTP: Received response:
2012-07-19 14:20:34 [25774] [8] DEBUG: Octet string at 0x7f8724001190:
2012-07-19 14:20:34 [25774] [8] DEBUG:   len:  232
2012-07-19 14:20:34 [25774] [8] DEBUG:   size: 1024
2012-07-19 14:20:34 [25774] [8] DEBUG:   immutable: 0
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 44 61 74 65 3a 20 54 68 75
2c 20 31 39 20 4a 75   Date: Thu, 19 Ju
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 6c 20 32 30 31 32 20 31 33
3a 32 30 3a 33 34 20   l 2012 13:20:34
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 47 4d 54 0d 0a 53 65 72 76
65 72 3a 20 41 70 61   GMT..Server: Apa
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 63 68 65 2f 32 2e 32 2e 32
32 20 28 55 62 75 6e   che/2.2.22 (Ubun
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 74 75 29 0d 0a 58 2d 50 6f
77 65 72 65 64 2d 42   tu)..X-Powered-B
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 79 3a 20 50 48 50 2f 35 2e
33 2e 31 30 2d 31 75   y: PHP/5.3.10-1u
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 62 75 6e 74 75 33 2e 32 0d
0a 56 61 72 79 3a 20   buntu3.2..Vary:
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 41 63 63 65 70 74 2d 45 6e
63 6f 64 69 6e 67 0d   Accept-Encoding.
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 0a 43 6f 6e 74 65 6e 74 2d
4c 65 6e 67 74 68 3a   .Content-Length:
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 20 31 0d 0a 4b 65 65 70 2d
41 6c 69 76 65 3a 20    1..Keep-Alive:
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 74 69 6d 65 6f 75 74 3d 35
2c 20 6d 61 78 3d 31   timeout=5, max=1
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 30 30 0d 0a 43 6f 6e 6e 65
63 74 69 6f 6e 3a 20   00..Connection:
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 4b 65 65 70 2d 41 6c 69 76
65 0d 0a 43 6f 6e 74   Keep-Alive..Cont
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 65 6e 74 2d 54 79 70 65 3a
20 74 65 78 74 2f 68   ent-Type: text/h
2012-07-19 14:20:34 [25774] [8] DEBUG:   data: 74 6d 6c 0d 0a 0d 0a 0a
                      tml.....
2012-07-19 14:20:34 [25774] [8] DEBUG: Octet string dump ends.
2012-07-19 14:20:34 [25774] [5] DEBUG: message length 35, sending 1 messages
2012-07-19 14:20:34 [25774] [0] DEBUG: Got ACK (0) of
6ccd3df6-5dfe-4473-9700-874f390ae0ac
2012-07-19 14:20:34 [25774] [0] DEBUG: No client - multi-send or ACK to
pull-reply
2012-07-19 14:20:39 [25774] [8] DEBUG: HTTP: Server closed connection,
destroying it <localhost:80:0::><0x7f872c000ad0><fd:28>.

Perhaps I am doing something wrong, as these requests only work some of the
time? In this case the responding SMS was:

2012-07-19 14:20:35 Sent SMS [SMSC:recv_hsl] [SVC:^[ ]*(request)[ ]*]
[ACT:] [BINF:] [FID:] [META:] [from:447797882105] [to:+447892010100]
[flags:-1:0:-1:-1:-1] [msg:35:<Empty reply from service provider>] [udh:0:]

Why is this?

Kind Regards,

Christopher

-- 
*Christopher Burke*
Software Engineer / Smart Card Developer
http://simulity.com
Mobile: +44 7590 571 833
Skype: krslynx

Reply via email to