Can not send SMS when more than 11 SMS in queue


(Hamidreza Mahmoudi) #1

Hello
can not send sms when I have more than 10 or 11 schedule SMS in sms queue.
im using latest version of playsms.

here is log :

 - - 2018-07-30 19:06:58 PID5b5f2288b2da1 - L2 simplerate_hook_rate_deduct # enter smslog_id:598  - - 2018-07-30 19:06:58 PID5b5f2288b2da1 - L2 simplebilling_hook_billing_post # saving smslog_id:598 rate:1.000 count:1 charge:1 - - 2018-07-30 19:06:58 PID5b5f2288b2da1 - L2 simplebilling_hook_billing_post # saved smslog_id:598 id:480
- - 2018-07-30 19:06:58 PID5b5f2288b2da1 - L2 sendsms_process # end
- - 2018-07-30 19:06:58 PID5b5f2288b2da1 - L2 sendsmsd # result queue_code:5f68be8d28e252e84cbd3ad717f19bfc to:0939xxxxxx flag:1 smslog_id:598
- - 2018-07-30 19:06:59 PID5b5f2288b2da1 - L2 sendsmsd # finish processing queue_code:5f68be8d28e252e84cbd3ad717f19bfc uid:1 sender_id: queue_count:1 sms_count:1
- - 2018-07-30 19:07:22 PID5b5f1fae82bcc - L2 gammu_hook_getsmsstatus # smslog_id:583 unlink the_fn:/var/spool/gammu-01/sent/OUTA20180730_190658_00_0939xxxxxx_583100011100010.txtd p_status:1 smsc:gsmserial
- - 2018-07-30 19:07:23 PID5b5f1fae82bcc - L2 simplebilling__finalize # saving smslog_id:583
- - 2018-07-30 19:07:23 PID5b5f1fae82bcc - L2 simplebilling__finalize # saved smslog_id:583
- - 2018-07-30 19:07:27 PID5b5f1fae82bcc - L2 gammu_hook_getsmsstatus # smslog_id:598 unlink the_fn:/var/spool/gammu-01/sent/OUTA20180730_190658_00_0939xxxxxx_598100011100010.txtd p_status:1 smsc:gsmserial
- - 2018-07-30 19:07:28 PID5b5f1fae82bcc - L2 simplebilling__finalize # saving smslog_id:598
- - 2018-07-30 19:07:28 PID5b5f1fae82bcc - L2 simplebilling__finalize # saved smslog_id:598
- - 2018-07-30 19:27:43 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:3010b4d4c58e60bfcf225d77dd14fa87
- - 2018-07-30 19:27:44 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:a1010069153a9e85041ea5f217eea8fb
- - 2018-07-30 19:27:44 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:00ff110fdad6bd49f7dc577ec16a33ea
- - 2018-07-30 19:27:44 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:6cea6238af2e60466f4df16deb31e9fb
- - 2018-07-30 19:28:33 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:3010b4d4c58e60bfcf225d77dd14fa87
- - 2018-07-30 19:28:33 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:a1010069153a9e85041ea5f217eea8fb
- - 2018-07-30 19:28:33 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:00ff110fdad6bd49f7dc577ec16a33ea
- - 2018-07-30 19:28:33 PID5b5f26298dc50 - L2 playsmsd__sendsmsd # enforce finish process queue:6cea6238af2e60466f4df16deb31e9fb
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms_queue_create # saving queue_code:3793a7ca557db3c4d7c461628fae47d3 src: scheduled:2018-07-30 19:30:48
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms_queue_create # saved queue_code:3793a7ca557db3c4d7c461628fae47d3 id:573
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms_queue_push # saving queue_code:3793a7ca557db3c4d7c461628fae47d3 dst:0939xxxxxx
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms_queue_push # saved queue_code:3793a7ca557db3c4d7c461628fae47d3 smslog_id:598
192.168.1.3 192.168.1.51 2018-07-30 19:30:48 PID5b5f282041503 admin L2 sendsms # end queue_code:3793a7ca557db3c4d7c461628fae47d3 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms_queue_create # saving queue_code:67445a8251842f533737c614582762d5 src: scheduled:2018-07-30 19:34:23
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms_queue_create # saved queue_code:67445a8251842f533737c614582762d5 id:574
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms_queue_push # saving queue_code:67445a8251842f533737c614582762d5 dst:0939xxxxxx
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms_queue_push # saved queue_code:67445a8251842f533737c614582762d5 smslog_id:599
192.168.1.3 192.168.1.51 2018-07-30 19:34:23 PID5b5f28f6f0c8f admin L2 sendsms # end queue_code:67445a8251842f533737c614582762d5 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms_queue_create # saving queue_code:034151f7db6a69ff41281096f2d6d4d2 src: scheduled:2018-07-30 19:37:16
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms_queue_create # saved queue_code:034151f7db6a69ff41281096f2d6d4d2 id:575
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms_queue_push # saving queue_code:034151f7db6a69ff41281096f2d6d4d2 dst:0939xxxxxx
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms_queue_push # saved queue_code:034151f7db6a69ff41281096f2d6d4d2 smslog_id:600
192.168.1.3 192.168.1.51 2018-07-30 19:37:16 PID5b5f29a3e5327 admin L2 sendsms # end queue_code:034151f7db6a69ff41281096f2d6d4d2 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0

(Hamidreza Mahmoudi) #2

I check it so many time and i’m sure SMS not sending when SMS queue is more than 10 or 11.
SMS immanently send when I delete some Queue Schedule SMS.

Here is new log and screenshot.

192.168.x.x  192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.x.x  192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms_queue_create # saving queue_code:939699fcba61516fd21a13e17eaf7594 src: scheduled:2018-08-23 06:46:00
192.168.x.x  192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms_queue_create # saved queue_code:939699fcba61516fd21a13e17eaf7594 id:594
192.168.x.x  192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.x.x 192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms_queue_push # saving queue_code:939699fcba61516fd21a13e17eaf7594 dst:0939xxxxxx
192.168.x.x 192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms_queue_push # saved queue_code:939699fcba61516fd21a13e17eaf7594 smslog_id:619
192.168.x.x 192.168.1.55 2018-07-31 07:03:46 PID5b5fca8a1d7fc admin L2 sendsms # end queue_code:939699fcba61516fd21a13e17eaf7594 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0
192.168.x.x 192.168.1.55 2018-07-31 07:04:22 PID5b5fcaada44fb admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.x.x 192.168.1.55 2018-07-31 07:04:22 PID5b5fcaada44fb admin L2 sendsms_queue_create # saving queue_code:1f7a5257f8443cef599dc656c67df88e src: scheduled:2018-08-30 06:57:00
192.168.x.x 192.168.1.55 2018-07-31 07:04:24 PID5b5fcaada44fb admin L2 sendsms_queue_create # saved queue_code:1f7a5257f8443cef599dc656c67df88e id:595
192.168.x.x 192.168.1.55 2018-07-31 07:04:24 PID5b5fcaada44fb admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.x.x 192.168.1.55 2018-07-31 07:04:24 PID5b5fcaada44fb admin L2 sendsms_queue_push # saving queue_code:1f7a5257f8443cef599dc656c67df88e dst:0939xxxxxx
192.168.x.x 192.168.1.55 2018-07-31 07:04:25 PID5b5fcaada44fb admin L2 sendsms_queue_push # saved queue_code:1f7a5257f8443cef599dc656c67df88e smslog_id:620
192.168.x.x 192.168.1.55 2018-07-31 07:04:25 PID5b5fcaada44fb admin L2 sendsms # end queue_code:1f7a5257f8443cef599dc656c67df88e queue_count:1 sms_count:1 failed_queue:0 failed_sms:0
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms # start uid:1 sender_id:[] smsc:[]
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms_queue_create # saving queue_code:e32ec4b2547e81334338ba252e757d02 src: scheduled:2018-07-31 07:04:59
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms_queue_create # saved queue_code:e32ec4b2547e81334338ba252e757d02 id:596
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms # dst_count:1 sms_count:1 total_charges:1
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms_queue_push # saving queue_code:e32ec4b2547e81334338ba252e757d02 dst:0939xxxxxx
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms_queue_push # saved queue_code:e32ec4b2547e81334338ba252e757d02 smslog_id:621
192.168.x.x 192.168.1.55 2018-07-31 07:04:59 PID5b5fcad35211c admin L2 sendsms # end queue_code:e32ec4b2547e81334338ba252e757d02 queue_count:1 sms_count:1 failed_queue:0 failed_sms:0

(Anton Raharja) #3

ok, this looks like a tough one to debug.

can you do this for me, so that I can examine your full log.

  1. do not use the server for production, do not do anything else but for testing. if you can’t then no one can help you I suppose, its pretty hard to examine mixed debug log

  2. stop playsmsd, playsmsd stop

  3. empty playsms.log (cat /dev/null > /var/log/playsms/playsms.log, I assume its in that path)

  4. empty the queue, no queue at all, no sending or receiving sms activities

  5. change the loglevel to 3 on config.php, the default is 2

  6. start playsmsd again, playsmsd start

  7. do the test, send or do whatever so that the queue become 11 or 12 just like you said it would stop working properly

  8. give some time, don’t do anything else

  9. when you think the problem occurred, the bug can be repeated, then save playsmsd.log file and send it to my email, dont paste here, send it to antonrd@gmail.com (please redact numbers, usernames, passwords, any kind of privacy issues)

anton


(Hamidreza Mahmoudi) #4

Thank you.
I sent logs to your mail.


(Anton Raharja) #5

Hi,

I want to make sure, please check your timezone setup:

This is my server’s time, its in UTC:

$ date
Wed Aug  1 03:22:21 UTC 2018

And then I check where is my php.ini, both for cli and fpm (I use nginx, if you use different webserver probably not in fpm folder):

$ php -i | grep php.ini
Configuration File (php.ini) Path => /etc/php/7.0/cli
Loaded Configuration File => /etc/php/7.0/cli/php.ini

I looked for date.timezone option and set it to my timezone Asia/Jakarta, its UTC+7:

$ cat /etc/php/7.0/cli/php.ini | grep date.timezone
; http://php.net/date.timezone
date.timezone = Asia/Jakarta

I also set it in fpm php.ini, not just cli php.ini:

$ cat /etc/php/7.0/fpm/php.ini | grep date.timezone
; http://php.net/date.timezone
date.timezone = Asia/Jakarta

Please note you need to restart php fpm when you changed fpm php.ini.

In playSMS I set my default timezone to +0700 (its UTC+7):

Restart playsmsd and start test again.

as a reference please read this:


(Hamidreza Mahmoudi) #6

Hi
All of my settings like you ( Asia/tehran ).
My php and fpm confing path is like your settings.
And my server’s time is +4:30 GMT Tehran time.


(Anton Raharja) #7

Confirmed its a bug. I know what happened, and currently being fixed.

sendsmsd_queue value in config.php limiting the number of queue that can be processed at one time. But since your 10 other queues were scheduled for later then the 11th queue and the next will not be processed until the earlier 10 scheduled SMS sent.

Screenshot%20from%202018-08-01%2020-25-08

See this:

Those queue are sorted latest on the top. The first on the top wont get sent at 20.45 if the other 10 at the bottom processed/sent. It will be sent around 21.00 soon after the other 10 sent.

temporary solution

edit config.php, set sendsmsd_queue to 0 and restart playsmsd

anton


(Anton Raharja) #8

please try this fix:

download this playsmsd.php:

wget -c https://raw.githubusercontent.com/antonraharja/playSMS/9e665715c7efd9bbb8e6db5916bb52c296571e83/daemon/linux/bin/playsmsd.php

replace your current playsmsd with downloaded playsmsd.php

the default location is in /usr/local/bin, you need to rename playsmsd.php to playsmsd

restart new playsmsd

anton


(Hamidreza Mahmoudi) #9

Thank you in advance.
Fixed the bug.


(Hamidreza Mahmoudi) #10

Is this OK with huge sms queue? More than 200sms.


(Anton Raharja) #11

yes, should be ok

anton