[solved] Message delivered but status is pending in playsms GUI

I need your help for debugging on DLR part,
I have installed Kannel&mysql in one server and Playsms & php in another server, I have done remote db connection, as well as kannel gateway.
The things are working fine sms is successfully delivered but in playsms GUI sent report, it shows that all sent sms in pending status in report. Here is few details,

Server version: Apache/2.4.6 (CentOS)
playsms_version | 1.3.1
Mysql: innodb_version | 5.5.35-MariaDB-33.0
Kannel bearerbox version `1.4.4’.
OS: CentOS 7

Debug log shows that there is no value in DLR report,

2016-07-13 00:04:44 [23073] [7] DEBUG: SMPP[smpp2] handle_pdu, got DLR
2016-07-13 00:04:44 [23073] [7] DEBUG: DLR[internal]: Looking for DLR smsc=smpp2, ts=1614576289, dst=+YYXXXXXXXXXX, type=1
2016-07-13 00:04:44 [23073] [7] DEBUG: DLR[internal]: created DLR message for URL http://x.x.x.x/playsms/index.php?app=call&cat=gateway&plugin=kannel&access=dlr&type=%d&smslog_id=77&uid=1&smsc=kannel
2016-07-13 00:04:44 [23073] [7] DEBUG: new group created smpp’
2016-07-13 00:04:44 [23073] [7] DEBUG: group=smpp’ key=dlr_err’ value=’

Kannel Configuration

cat kannel.conf
group = core
admin-port = 13000
admin-password = xxxxx
status-password = yyyyyy
log-file = "/var/log/kannel/kannel.log"
log-level = 0
access-log = "/var/log/kannel/access.log"
smsbox-port = 13001
store-type = spool
store-location = "/var/spool/kannel/store"
smsbox-max-pending = 100

SMSBOX
group = smsbox
bearerbox-host = localhost

bearerbox-port = 13001
sendsms-port = 13131
sendsms-chars = "0123456789+ "
log-file = "/var/log/kannel/smsbox.log"
log-level = 0
access-log = "/var/log/kannel/access.log"
mo-recode = true

group = smsc
smsc = smpp
smsc-id = smpp1
host = y.y.y.y
port = 5016
transceiver-mode = yes
smsc-username = xxxx
smsc-password = yyyyyy
msg-id-type = 1
system-type = "SMPP"
log-file = "/var/log/kannel/smpp1.log"
log-level = 0
allowed-prefix = "+xxxxx0;+xxxxx1;+xxxxx2"
denied-prefix = “+9;9”

group = smsc
smsc = smpp
smsc-id = smpp2
host = x.x.x.x
port = 5016
transceiver-mode = yes
smsc-username = xxxx
smsc-password = yyyyyy
msg-id-type = 1
system-type = "SMPP"
log-file = "/var/log/kannel/smpp2.log"
log-level = 0
allowed-prefix = "+xxxxx0;+xxxxx1;+xxxxx2"
denied-prefix = “+9;9”

SENDSMS-USER
group = sendsms-user
default-smsc = none
username = xxxxx
password = yyyyy
max-messages = 6
concatenation = true

allowed-prefix = "+xxxxx0;+xxxxx1;+xxxxx2"
denied-prefix = "+9;9"
SMS SERVICE
group = sms-service
keyword = default
omit-empty = true
max-messages = 0
get-url = “http://y.y.y.y/playsms/index.php?app=call&cat=gateway&plugin=kannel&access=geturl&t=%t&q=%q&a=%a&Q=%Q&smsc=%i

Submit playsms log too, level 3

Anton

sorry for hiding IP and MSISDN

==> audit.log <==
y.y.y.y 2016-07-14 06:10:55 PID57872cee374d3 admin ip:x.x.x.x app:main inc:feature_report route:user
y.y.y.y 2016-07-14 06:10:55 PID57872cefab0f1 admin ip:x.x.x.x app:main inc:feature_report route:user
y.y.y.y 2016-07-14 06:10:56 PID57872cefe5eb2 admin ip:x.x.x.x app:main inc:feature_report route:user
y.y.y.y 2016-07-14 06:13:19 PID57872d7ed3374 admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms
y.y.y.y 2016-07-14 06:14:14 PID57872db5be416 admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms_yes X-CSRF-Token:4a5024e6f2af53b8f87e0b72416f014f footerlen:7 maxchar:153 maxchar_unicode:67 hiddcount:918 hiddcount_unicode:402 chars:chars SMS:SMS return_url: p_num_text:xxxxxxxxxx smstemplate: message:test txtcount:11 chars : 1 SMS sms_sender:+yyy12298 sms_footer:@admin sms_schedule:
y.y.y.y 2016-07-14 06:14:14 PID57872db6294e9 admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms
y.y.y.y 2016-07-14 06:19:49 PID57872f0551f4a admin ip:x.x.x.x app:main inc:feature_report route:user
y.y.y.y 2016-07-14 06:19:54 PID57872f0a15abf admin ip:x.x.x.x app:main inc:feature_report route:user
y.y.y.y 2016-07-14 06:20:02 PID57872f12731d3 admin ip:x.x.x.x app:main inc:feature_report route:all_outgoing op:all_outgoing
y.y.y.y 2016-07-14 06:30:36 PID5787318c02ea5 admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms

==> playsms.log <==

    • 2016-07-14 06:14:25 PID57872db6e5088 - L2 simplebilling__post # saving smslog_id:85 rate: credit:0.000 count:1 charge:0
    • 2016-07-14 06:14:25 PID57872db6e5088 - L2 simplebilling__post # saved smslog_id:85 id:85
    • 2016-07-14 06:14:25 PID57872db6e5088 - L3 simplerate__deduct # deduct successful uid:1 parent_uid: smslog_id:85
    • 2016-07-14 06:14:25 PID57872db6e5088 - L3 simplerate__deduct # credit_lowest_limit:0 balance:0 charge:0
    • 2016-07-14 06:14:25 PID57872db6e5088 - L2 sendsms_process # end
    • 2016-07-14 06:14:25 PID57872db6e5088 - L3 sendsms_throttle_count # throttle bucket exists start:2016-07-14 05:59:18 sum:1 limit:20000
    • 2016-07-14 06:14:25 PID57872db6e5088 - L2 sendsmsd # result queue_code:4f7cde42d5d117fff9f94429e7557b2c to:+yyyxxxxxxxxxx flag:1 smslog_id:85
    • 2016-07-14 06:14:25 PID57872db6e5088 - L3 sendsms_throttle_isoverlimit # under quota not overlimit sum:2
    • 2016-07-14 06:14:25 PID57872db6e5088 - L2 sendsmsd # finish processing queue_code:4f7cde42d5d117fff9f94429e7557b2c uid:1 sender_id:+yyy12298 queue_count:1 sms_count:1
    • 2016-07-14 06:14:25 PID57872a068729f - L3 dlrd # id:85 smslog_id:85 p_status:0 uid:1

==> audit.log <==
y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms_yes X-CSRF-Token:881509df23c43dedbaec23576d8e5521 footerlen:7 maxchar:153 maxchar_unicode:67 hiddcount:918 hiddcount_unicode:402 chars:chars SMS:SMS return_url: p_num_text:xxxxxxxxxx smstemplate: message:test txtcount:11 chars : 1 SMS sms_sender:+yyy12298 sms_footer:@admin sms_schedule:

==> playsms.log <==
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L2 sendsms # start uid:1 sender_id:[+yyy12298] smsc:[]
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L3 sendsms # maxlen:918 footerlen:7 footer:[ @admin] msglen:4 message:[test]
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L2 sendsms_queue_create # saving queue_code:b2dbdb333261a61ae750ab57e9122e07 src:+yyy12298 scheduled:2016-07-14 06:31:12
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L2 sendsms_queue_create # saved queue_code:b2dbdb333261a61ae750ab57e9122e07 id:86
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L3 sendsms_manipulate_prefix # before prefix manipulation:[xxxxxxxxxx]
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L3 sendsms_manipulate_prefix # after prefix manipulation:[+yyyxxxxxxxxxx]
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L3 simplerate_hook_rate_getbyprefix # rate not found to:+yyyxxxxxxxxxx default_rate:0
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L3 simplerate_hook_rate_getcharges # uid:1 u:admin len:11 unicode:0 to:+yyyxxxxxxxxxx enable_credit_unicode:1 count:1 rate: charge:0
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L2 sendsms # dst:1 sms_count:1 total_charges:0
x.x.x.x y.y.y.y 2016-07-14 06:31:12 PID578731b06c082 admin L2 sendsms_queue_push # saving queue_code:b2dbdb333261a61ae750ab57e9122e07 dst:+yyyxxxxxxxxxx
x.x.x.x y.y.y.y 2016-07-14 06:31:13 PID578731b06c082 admin L2 sendsms_queue_push # saved queue_code:b2dbdb333261a61ae750ab57e9122e07 smslog_id:86
x.x.x.x y.y.y.y 2016-07-14 06:31:13 PID578731b06c082 admin L2 sendsms # end queue_code:b2dbdb333261a61ae750ab57e9122e07 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0

==> audit.log <==
y.y.y.y 2016-07-14 06:31:13 PID578731b125dea admin ip:x.x.x.x app:main inc:core_sendsms op:sendsms

==> playsms.log <==

    • 2016-07-14 06:31:24 PID578731b1e78af - L3 sendsms_throttle_isoverlimit # under quota not overlimit sum:2
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsmsd # start processing queue_code:b2dbdb333261a61ae750ab57e9122e07 chunk:0 queue_count:1 sms_count:1 scheduled:2016-07-14 06:31:12 uid:1 gpid:0 sender_id:+yyy12298
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsmsd # sending queue_code:b2dbdb333261a61ae750ab57e9122e07 smslog_id:86 to:+yyyxxxxxxxxxx sms_count:1 counter:1
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 sendsms_intercept # msgtemplate modified sms_sender:[+yyy12298] sms_footer:[@admin] sms_to:[+yyyxxxxxxxxxx] sms_msg:[test] uid:[1] gpid:[0] sms_type:[text] unicode:[0] queue_code:[b2dbdb333261a61ae750ab57e9122e07] smsc:[]
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 outgoing_hook_sendsms_intercept # no SMSC found uid:1 parent_uid:0 from:+yyy12298 to:+yyyxxxxxxxxxx
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsms_process # start
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate_hook_rate_getbyprefix # rate not found to:+yyyxxxxxxxxxx default_rate:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate_hook_rate_getcharges # uid:1 u:admin len:11 unicode:0 to:+yyyxxxxxxxxxx enable_credit_unicode:1 count:1 rate: charge:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 simplerate__cansend # allowed user uid:1 sms_to:+yyyxxxxxxxxxx credit:0.000 count:1 rate: charge:0 balance:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsms # saving smslog_id:86 u:1 g:0 gw:kannel smsc:kannel s:+yyy12298 d:+yyyxxxxxxxxxx type:text unicode:0 status:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsms_process # saved smslog_id:86 id:86
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 sendsms # final smslog_id:86 gw:kannel smsc:kannel message:test @admin len:11
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 kannel_hook_sendsms # enter smsc:kannel smslog_id:86 uid:1 to:+yyyxxxxxxxxxx
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 kannel__outgoing # smslog_id:86 response:0: Accepted for delivery
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 dlr # isdlrd:1 smslog_id:86 p_status:0 uid:1
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 kannel__outgoing # end smslog_id:86 p_status:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 simplerate__deduct # enter smslog_id:86
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate_hook_rate_getbyprefix # rate not found to:+yyyxxxxxxxxxx default_rate:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate_hook_rate_getcharges # uid:1 u:admin len:11 unicode:0 to:+yyyxxxxxxxxxx enable_credit_unicode:1 count:1 rate: charge:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 credit_hook_rate_setusercredit # no changes uid:1 balance:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 simplerate__deduct # user uid:1 parent_uid: smslog_id:86 msglen:11 count:1 rate: charge:0 credit:0.000 balance:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 simplebilling__post # saving smslog_id:86 rate: credit:0.000 count:1 charge:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 simplebilling__post # saved smslog_id:86 id:86
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate__deduct # deduct successful uid:1 parent_uid: smslog_id:86
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 simplerate__deduct # credit_lowest_limit:0 balance:0 charge:0
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsms_process # end
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 sendsms_throttle_count # throttle bucket exists start:2016-07-14 05:59:18 sum:2 limit:20000
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsmsd # result queue_code:b2dbdb333261a61ae750ab57e9122e07 to:+yyyxxxxxxxxxx flag:1 smslog_id:86
    • 2016-07-14 06:31:24 PID578731b1e78af - L3 sendsms_throttle_isoverlimit # under quota not overlimit sum:3
    • 2016-07-14 06:31:24 PID578731b1e78af - L2 sendsmsd # finish processing queue_code:b2dbdb333261a61ae750ab57e9122e07 uid:1 sender_id:+yyy12298 queue_count:1 sms_count:1
    • 2016-07-14 06:31:24 PID57872a068729f - L3 dlrd # id:86 smslog_id:86 p_status:0 uid:1

is http://y.y.y.y/ accessible by Kannel ?

anton

we have one way access from playsms to kannel on port 13001,13000
do we need reverse access from kannel to playsms on port 80,443? or on the above ports?

kannel will submit DLR to dlr url

from playsms log I don’t see any information that kannel successfully pushed DLR to playSMS, which mean probably Kannel can’t access the dlr-url (the http://y.y.y.y you mentioned in playsms.log)

- - 2016-07-14 06:31:24 PID578731b1e78af - L3 kannel_hook_sendsms # URL: http://x.x.x.x:13131/cgi-bin/sendsms?username=playsms1&password=playsms1&from=%2Byyy12298&to=%2Byyyxxxxxxxxxx&dlr-mask=27&dlr-url=http%3A%2F%2Fy.y.y.y%2Fplaysms%2Findex.php%3Fapp%3Dcall%26cat%3Dgateway%26plugin%3Dkannel%26access%3Ddlr%26type%3D%25d%26smslog_id%3D86%26uid%3D1%26smsc%3Dkannel&account=admin&text=test+%40admin

anton

I could see in Kannel log:
2016-07-14 05:55:22 [25124] [9] ERROR: Couldn’t fetch http://y.y.y.y/playsms/index.php?app=call&cat=gateway&plugin=kannel&access=dlr&type=1&smslog_id=88&uid=1&smsc=kannel
whats the reason?
the connection from Kannel to Playsms is OK on port 80,
[root@localhost kannel]# telnet 172.16.34.117 80
Trying 172.16.34.117…
Connected to 172.16.34.117.

Thanks for valuable suggestion, the problem is solved, found some interface problem which caused Kannel could not access dlr-url. Simply current IP is replaced by interface IP in SMSc gateway in playsms GUI setting. All things are working fine.
Keep on updating…

1 Like

what kind of interface problem.
since i am also stuck wid same problem as yours?