Account's balance decreases even when message is not delivered using Nexmo

playSMS Help
1

Hello,

This case of study applies to messages sent trough Nexmo gateway and when the queue rate fix is applied (sleep 1). Regardless if the message is sent or not the balance is decreasing per each message.

Here is a copy of part of the log of a lot sent today.

Thanks,

Miguel.

  • 2015-06-23 12:52:27 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:52:27 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055101237 credit:1941.000 count:1 rate:1.000 charge:1 balance:1940
    • 2015-06-23 12:52:27 PID55898a3974e98 - L2 sendsms # saving smslog_id:73017 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055101237 type:text unicode:0 status:0
    • 2015-06-23 12:52:27 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:73017 id:72998
      174.36.197.195 162.242.242.235 2015-06-23 12:52:27 PID55898ecb330a6 - L2 nexmo__callback # pushed msisdn:13055101030 to:13056771044 network-code:310090 messageId:02000000691D14A0 price:0.00480000 status:accepted scts:1506231652 err-code:1 client-ref:73016 message-timestamp:2015-06-23 16:52:47
      174.36.197.195 162.242.242.235 2015-06-23 12:52:27 PID55898ecb330a6 - L2 nexmo__callback # dlr uid:2 smslog_id:73016 message_id:02000000691D14A0 status:accepted
    • 2015-06-23 12:52:27 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:73015
    • 2015-06-23 12:52:27 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:73015
    • 2015-06-23 12:52:27 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:73016
    • 2015-06-23 12:52:27 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:73016
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:73017 message_id:030000008149F9CA status:0 error:
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:73017
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1940
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1940
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:73017 msglen:159 count:1 rate:1.000 charge:1 credit:1941.000 balance:1940
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:73017 rate:1.000 credit:1941.000 count:1 charge:1
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:73017 id:43975
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsms_process # end
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsmsd # result queue_code:d560d6a67438bd30bbf24f7cdc932986 to:13055101237 flag:1 smslog_id:73017
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsmsd # sending queue_code:d560d6a67438bd30bbf24f7cdc932986 smslog_id:73018 to:13055101299 sms_count:1000 counter:988
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055101299 credit:1940.000 count:1 rate:1.000 charge:1 balance:1939
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsms # saving smslog_id:73018 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055101299 type:text unicode:0 status:0
    • 2015-06-23 12:52:28 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:73018 id:72999
      174.36.197.201 162.242.242.235 2015-06-23 12:52:28 PID55898ecc5a49a - L2 nexmo__callback # pushed msisdn:13055101237 to:13056771044 network-code:310090 messageId:030000008149F9CA price:0.00480000 status:accepted scts:1506231652 err-code:1 client-ref:73017 message-timestamp:2015-06-23 16:52:48
      174.36.197.201 162.242.242.235 2015-06-23 12:52:28 PID55898ecc5a49a - L2 nexmo__callback # dlr uid:2 smslog_id:73017 message_id:030000008149F9CA status:accepted
    • 2015-06-23 12:52:29 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:73017
    • 2015-06-23 12:52:29 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:73017
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:73018 message_id:02000000691D1514 status:0 error:
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:73018
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1939
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1939
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:73018 msglen:159 count:1 rate:1.000 charge:1 credit:1940.000 balance:1939
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:73018 rate:1.000 credit:1940.000 count:1 charge:1
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:73018 id:43976
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsms_process # end
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsmsd # result queue_code:d560d6a67438bd30bbf24f7cdc932986 to:13055101299 flag:1 smslog_id:73018
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsmsd # sending queue_code:d560d6a67438bd30bbf24f7cdc932986 smslog_id:73019 to:13055101325 sms_count:1000 counter:989
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055101325 credit:1939.000 count:1 rate:1.000 charge:1 balance:1938
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsms # saving smslog_id:73019 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055101325 type:text unicode:0 status:0
    • 2015-06-23 12:52:29 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:73019 id:73000
      174.36.197.201 162.242.242.235 2015-06-23 12:52:29 PID55898ecd86e2e - L2 nexmo__callback # pushed msisdn:13055101299 to:13056771044 network-code:310090 messageId:02000000691D1514 price:0.00480000 status:accepted scts:1506231652 err-code:1 client-ref:73018 message-timestamp:2015-06-23 16:52:50
      174.36.197.201 162.242.242.235 2015-06-23 12:52:30 PID55898ecd86e2e - L2 nexmo__callback # dlr uid:2 smslog_id:73018 message_id:02000000691D1514 status:accepted
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:73019 message_id:02000000691D1549 status:0 error:
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:73019
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1938
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1938
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:73019 msglen:159 count:1 rate:1.000 charge:1 credit:1939.000 balance:1938
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:73019 rate:1.000 credit:1939.000 count:1 charge:1
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:73019 id:43977
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsms_process # end
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsmsd # result queue_code:d560d6a67438bd30bbf24f7cdc932986 to:13055101325 flag:1 smslog_id:73019
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsmsd # sending queue_code:d560d6a67438bd30bbf24f7cdc932986 smslog_id:73020 to:13055101616 sms_count:1000 counter:990
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055101616 credit:1938.000 count:1 rate:1.000 charge:1 balance:1937
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsms # saving smslog_id:73020 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055101616 type:text unicode:0 status:0
    • 2015-06-23 12:52:30 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:73020 id:73001
      174.36.197.195 162.242.242.235 2015-06-23 12:52:30 PID55898ecec1689 - L2 nexmo__callback # pushed msisdn:13055101325 to:13056771044 network-code:310260 messageId:02000000691D1549 price:0.00480000 status:accepted scts:1506231652 err-code:1 client-ref:73019 message-timestamp:2015-06-23 16:52:51
      174.36.197.195 162.242.242.235 2015-06-23 12:52:30 PID55898ecec1689 - L2 nexmo__callback # dlr uid:2 smslog_id:73019 message_id:02000000691D1549 status:accepted
    • 2015-06-23 12:52:31 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:73018
    • 2015-06-23 12:52:31 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:73018
    • 2015-06-23 12:52:31 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:73019
    • 2015-06-23 12:52:31 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:73019
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:73020 message_id:030000008149FAA6 status:0 error:
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:73020
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1937
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1937
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:73020 msglen:159 count:1 rate:1.000 charge:1 credit:1938.000 balance:1937
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:73020 rate:1.000 credit:1938.000 count:1 charge:1
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:73020 id:43978
    • 2015-06-23 12:52:31 PID55898a3974e98 - L2 sendsms_process # end
2

where do you see the status that the message wasn’t sent ?

anton

3

Hi Anton,

In My Sent Messages report.

4

your pasted log did not shown any failed message so its pretty hard to guess

try this, I think this has been told several times here:

do this to get the log:

tail -f /var/log/playsms/playsms.log -n0 | tee test1.txt

and then send 1 or 2 successful message and 1 or 2 failed message

then ctrl+c the tail above and paste the test1.txt here (or PM me)

anton

5

Sure Anton, im really sorry. I just thought i had pasted failed messages.

Please see down below:

  1. This is apparently a landline call and yet is charged:
    • 2015-06-23 12:51:56 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:51:56 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055080073 credit:1966.000 count:1 rate:1.000 charge:1 balance:1965
    • 2015-06-23 12:51:56 PID55898a3974e98 - L2 sendsms # saving smslog_id:72992 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055080073 type:text unicode:0 status:0
    • 2015-06-23 12:51:56 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:72992 id:72973
      174.36.197.201 162.242.242.235 2015-06-23 12:51:56 PID55898eac86266 - L2 nexmo__callback # pushed msisdn:13055078442 to:13056771044 network-code:US-UNKNOWN messageId:030000008149F3BE price:0 status:failed scts:1506231652 err-code:1 client-ref:72991 message-timestamp:2015-06-23 16:52:17
      174.36.197.201 162.242.242.235 2015-06-23 12:51:56 PID55898eac86266 - L2 nexmo__callback # dlr uid:2 smslog_id:72991 message_id:030000008149F3BE status:failed
    • 2015-06-23 12:51:57 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:72990
    • 2015-06-23 12:51:57 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:72990
    • 2015-06-23 12:51:57 PID5579ab2682b0c - L2 simplebilling__finalize # saving smslog_id:72991
    • 2015-06-23 12:51:57 PID5579ab2682b0c - L2 simplebilling__finalize # saved smslog_id:72991
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:72992 message_id:02000000691D0F9A status:0 error:
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:72992
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1965
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1965
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:72992 msglen:159 count:1 rate:1.000 charge:1 credit:1966.000 balance:1965
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:72992 rate:1.000 credit:1966.000 count:1 charge:1
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:72992 id:43950
    • 2015-06-23 12:51:57 PID55898a3974e98 - L2 sendsms_process # end
    • 2015-06-23 12:51:49 PID55898a3974e98 - L2 sendsms_process # start
    • 2015-06-23 12:51:49 PID55898a3974e98 - L2 simplerate__cansend # allowed user uid:2 sms_to:13055065252 credit:1972.000 count:1 rate:1.000 charge:1 balance:1971
    • 2015-06-23 12:51:49 PID55898a3974e98 - L2 sendsms # saving smslog_id:72986 u:2 g:0 gw:nexmo smsc:linkedipulcnm001 s:13056771044 d:13055065252 type:text unicode:0 status:0
    • 2015-06-23 12:51:49 PID55898a3974e98 - L2 sendsms_process # saved smslog_id:72986 id:72967
      174.36.197.201 162.242.242.235 2015-06-23 12:51:49 PID55898ea5313cc - L2 nexmo__callback # pushed msisdn:13055063391 to:13056771044 network-code:US-UNKNOWN messageId:030000008149F28A price:0 status:failed scts:1506231652 err-code:1 client-ref:72985 message-timestamp:2015-06-23 16:52:09
      174.36.197.201 162.242.242.235 2015-06-23 12:51:49 PID55898ea5313cc - L2 nexmo__callback # dlr uid:2 smslog_id:72985 message_id:030000008149F28A status:failed
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 nexmo__outgoing # sent smslog_id:72986 message_id:030000008149F2C1 status:0 error:
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 simplerate__deduct # enter smslog_id:72986
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saving uid:2 balance:1971
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 credit_hook_rate_setusercredit # saved uid:2 balance:1971
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 simplerate__deduct # user uid:2 parent_uid: smslog_id:72986 msglen:159 count:1 rate:1.000 charge:1 credit:1972.000 balance:1971
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 simplebilling__post # saving smslog_id:72986 rate:1.000 credit:1972.000 count:1 charge:1
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 simplebilling__post # saved smslog_id:72986 id:43944
    • 2015-06-23 12:51:50 PID55898a3974e98 - L2 sendsms_process # end
    • 2015-06-23 12:51:50
6

can you enable logstate 3 (set on config.php and restart playsmsd, then re-test), so that we can get more info on L3, those log seems for L2 only

anton

7

L3 exposes usernames/passwords, please be careful when you paste

anton

8

hold on, was this your thread ?

https://groups.google.com/d/msg/playsmsusergroup/99ysuQWjFPI/OM4TGyHefRUJ

I know I remember this issue. Yes, its actually the limitation on playSMS when handling Nexmo. The temporary fix is on above link.

anton

9

Yes Anton. That was exactly me.
Thanks. Maybe when i updated from rc-7 or rc-9 to 1.0 i lost the fix.
I will try and let you know but for sure this will be the fix.

10

@anton same problem using kannel.

The credit always deducted if message was sent and failed too