DLR-MO get queued on store until restart

Hi im having this issue, im getting some DLR-MO queued on the store, and
they dont get out until i restart kannel.

My scenario:

I have two kannel boxes (tried svn-r5143M and 1.4.4, both giving me same
results)

From the point of view of the receiving DLRS i think this is the path:
CUSTOMER <=>(opensmppbox) KANNEL1 (smsc smpp) <=> (opensmppbox) KANNEL2
(smsbox http generic) <=> PHP

PHP inyecting DLR calling http://127.0.0.1:13015/sms?username=XXXX
<http://127.0.0.1:13015/sms?username=XXXX&password=XXXX&dlr-mask=1&dlr-mid=X
XXXX-XXXXXXX-XXXXX-XXXXX>
&password=XXXX&dlr-mask=1&dlr-mid=XXXXX-XXXXXXX-XXXXX-XXXXX

I put log level at 0 on everywere, do some wireshark traces also, and i
cannot figure out why im having this issue.

I have this example:


lynx -dump "http://localhost:13000/store-status?password=XXXXXX"


SMS ID                                   Type   Time                Sender
Receiver    SMSC ID BOX ID UDH Message
5168f8be-8f3b-45e5-9e23-5731f99e22c9 DLR-MO 2015-06-09 22:34:13 XXXXXX
+52XXXXXXXX SMPP    SMPP


cat /var/spool/kannel/75/5168f8be-8f3b-45e5-9e23-5731f99e22c9
S+52XXXXXXXXXÿÿÿÿUw°5SMPPÿÿÿÿ$ae26e4cd-041d-4ee1-a884-435483caa6f7
1433907248ÿÿÿÿ$5168f8be-8f3b-45e5-9e23-5731f99e22c9ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ$
ae26e4cd-041d-4ee1-a884-435483caa6f7ÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿSMPPÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿÿ
ÿÿÿÿ

I ask the file for time:
ls --full-time ./75/5168f8be-8f3b-45e5-9e23-5731f99e22c9
-rw------- 1 kannel nogroup 275 2015-06-09 22:34:13.110916048 -0500
./75/5168f8be-8f3b-45e5-9e23-5731f99e22c

And search that time on the logs to see if i found something:

grep 22:34:13 /var/log/kannel/*.log

/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP[SMPP]:
Got request
`/sms?&username=XXXXXX&password=XXXXXX&dlr-mask=1&dlr-mid=ae26e4cd-041d-4ee1
-a884-435483caa6f7'
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP[SMPP]:
Received an HTTP request
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: DLR[mysql]:
Looking for DLR smsc=SMPP, ts=ae26e4cd-041d-4ee1-a884-435483caa6f7,
dst=(null), type=1
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: sql: SELECT
`mask`, `service`, `url`, `source`, `destination`, `boxc_id` FROM `dlr1`
WHERE `smsc`=? AND `ts`=?  LIMIT 1
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: column=mask
buffer_type=253 max_length=0 length=12
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG:
column=service buffer_type=253 max_length=0 length=48
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: column=url
buffer_type=253 max_length=0 length=6144
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG:
column=source buffer_type=253 max_length=0 length=96
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG:
column=destination buffer_type=253 max_length=0 length=96
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG:
column=boxc_id buffer_type=253 max_length=0 length=48
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: DLR[mysql]:
created DLR message for URL <ae26e4cd-041d-4ee1-a884-435483caa6f7>
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: removing DLR
from database
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: sql: DELETE
FROM `dlr1` WHERE `smsc`=? AND `ts`=?  LIMIT 1
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP[SMPP]:
Received DLR for DLR-URL <ae26e4cd-041d-4ee1-a884-435483caa6f7>
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP[SMPP]:
Sending reply
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP:
Resetting HTTPClient for `127.0.0.1'.
/var/log/kannel/http.log:2015-06-09 22:34:13 [5766] [11] DEBUG: HTTP[SMPP]:
Destroying client information

I see that generic HTTP succesfully receive the DLR

/var/log/kannel/kannel_access.log:2015-06-09 22:34:13 Receive DLR
[SMSC:SMPP] [SVC:1433907248] [ACT:] [BINF:]
[FID:ae26e4cd-041d-4ee1-a884-435483caa6f7] [META:] [from:XXXXXXX]
[to:+52XXXXXXXXX] [flags:-1:-1:-1:-1:1] [msg:0:] [udh:0:]

I see DLR on this too...

/var/log/kannel/kannel.log:2015-06-09 22:34:13 [5766] [2] DEBUG: HTTP:
Creating HTTPClient for `127.0.0.1'.
/var/log/kannel/kannel.log:2015-06-09 22:34:13 [5766] [2] DEBUG: HTTP:
Created HTTPClient area 0x24eadd0.
/var/log/kannel/kannel.log:2015-06-09 22:34:13 [5766] [10] DEBUG: HTTP:
Destroying HTTPClient area 0x24eadd0.
/var/log/kannel/kannel.log:2015-06-09 22:34:13 [5766] [10] DEBUG: HTTP:
Destroying HTTPClient for `127.0.0.1'.

This doesnt tells me much more....

More than ten minutes latter and after doing the restart opensmppbox seems
to send the DLR-MO:

grep ae26e4cd-041d-4ee1-a884-435483caa6f7 /var/log/kannel/opensmppbox.log

/var/log/kannel/opensmppbox.log:2015-06-09 22:48:54 [25816] [1] DEBUG:
DLR[mysql]: Looking for DLR smsc=SMPP,
ts=ae26e4cd-041d-4ee1-a884-435483caa6f7, dst=+52XXXXXXX, type=1
/var/log/kannel/opensmppbox.log:2015-06-09 22:48:54 [25816] [1] DEBUG:
DLR[mysql]: created DLR message for URL
<ae26e4cd-041d-4ee1-a884-435483caa6f7>





Traffic its very little, less than one message per second, kannel boxes are
i5 with 32GB of ram.
I dont see any network issue neither.


Hope someone can give me a clue on how to debug better this issue.


PD: changed, username, passwords, source and destination numbers with
XXXXXXXX
PD2: Sorry for my bad english




__________ Información de ESET Smart Security, versión de la base de datos
de firmas de virus 11762 (20150610) __________

El mensaje fue verificado por ESET Smart Security.

http://www.eset-la.com