Re: Problematic Kannel behaviour with large message stores

good !

----- Original Message ----- 
From: "Alexander Malysh" <[email protected]>
To: <[email protected]>
Sent: Friday, September 08, 2006 1:03 PM
Subject: Re: Problematic Kannel behaviour with large message stores


> Hi,
>
> will try todo it next week. I have it up to 80% ready with possibility to
> select store file or store spool...
>
> Thanks,
> Alex
>
> Vincent CHAVANIS wrote:
>
>> Alex,
>>
>> Could you please review you patch to fit the actual CVS tree, as we can
>> test it.
>> Then, how it comes this patch does not have been commited as it was ++2
>>
>> regards
>>
>> Vincent
>>
>> --
>> Telemaque - 06200 NICE - (FR)
>> Service Technique/Reseau - NOC
>> Developpement SMS/MMS/Kiosques
>> http://www.telemaque.fr/
>> [email protected]
>> Tel : +33 4 93 97 71 64 (fax 68)
>> ----- Original Message -----
>> From: "Alexander Malysh" <[email protected]>
>> To: <[email protected]>
>> Sent: Friday, September 08, 2006 12:06 PM
>> Subject: Re: Problematic Kannel behaviour with large message stores
>>
>>
>>> Hi,
>>>
>>> you can search for my patch
>>>
> (http://article.gmane.org/gmane.comp.mobile.kannel.devel/20690/match=spool)
>>> that replaces store file with store spool directory. This works with
>>> similar performance when you put your store dir on reiserfs or tmpfs
>>> under linux. It would be great to hear test results for this patch.
>>> Please note that patch is very old and could not apply that you should
>>> fix manually.
>>>
>>> Thanks,
>>> Alex
>>>
>>> Giulio Harding wrote:
>>>
>>>> We've been doing some more stress-testing of Kannel, this time under
>>>> high-load over long periods of time, an we've encountered some
>>>> problems when the message store grows large, of the order of hundreds
>>>> of thousands of messages (in our case, because we're delivering MTs
>>>> slower than we are receiving MOs, and due to the use of synchronous
>>>> responses to MO HTTP requests, the MTs are queuing at the bearerbox).
>>>> We understand that this is an extreme situation, and unlikely to be
>>>> encountered in normal usage, but we want to cover all our bases
>>>> (worst-case scenarios) and make sure that Kannel behaves correctly/
>>>> predictably in bad situations.
>>>>
>>>> - It seems that reading from the message store during Kannel startup
>>>> is single-threaded, and CPU bound - for large stores (several hundred
>>>> thousand messages), this can result in very long start-up times,
>>>> since Kannel seems to not process any messages in the store until it
>>>> has finished reading them *all* into memory from disk.
>>>>
>>>> - Why can't they simply be processed from disk? (i.e. read message
>>>> from disk, process message, read next message from disk) Given that
>>>> the messages are in a persistent store, why do they need to be in
>>>> memory as well?
>>>>
>>>> - The bearerbox memory usage grows by around 100MB per hundred
>>>> thousand messages in the store, as the messages are read from the
>>>> store, which leads to VM thrashing under extreme circumstances, as
>>>> the bearerbox footprint grows beyond the RAM size of the server...
>>>> For one test, after the initial loading of ~634,000 MTs from the
>>>> store, and bearerbox was using ~780M of RAM. 1+ KB per message seems
>>>> a lot, given that messages seems to be occupying more space in memory
>>>> than on disk (that number of MTs was consuming about 255MB on disc)
>>>>
>>>> - Once messages are read into memory, they seem to be copied into
>>>> another queue (this exacerbates the problem above) - why is this?
>>>>
>>>>
>>>> [from kannel admin page]
>>>>
>>>> ...
>>>>
>>>>     Status: running, uptime 0d 0h 12m 39s
>>>>
>>>>     WDP: received 0 (0 queued), sent 0 (0 queued)
>>>>
>>>> v-------------- *** this number has stopped growing ***
>>>>     SMS: received 0 (329153 queued), sent 4 (0 queued), store size
>>>> 634247
>>>>                         ^--------------- *** this number is growing ***
>>>>     SMS: inbound 0.00 msg/sec, outbound 0.01 msg/sec
>>>>
>>>> ...
>>>>
>>>>
>>>>   (the queue sizes for all the SMPP binds are also growing, so I
>>>> assume their queues are related to this main queue somehow?)
>>>>
>>>> At this point, bearerbox's memory footprint is *still* growing
>>>> (eventually reaching 1264M virtual, 932M resident) and the server is
>>>> spending 60+ percent of CPU cycles on disk IO, as the VM thrashes.
>>>>
>>>> - Finally, Kannel's queue sizes etc. seem to stop growing:
>>>>
>>>>
>>>> [kannel admin page]
>>>>
>>>>     Kannel bearerbox version `cvs-20060830'. Build `Aug 31 2006
>>>> 22:56:51',
>>>>     compiler  `3.4.5  20051201  (Red  Hat 3.4.5-2)'. System Linux,
>>>> release
>>>>     2.6.9-42.0.2.ELsmp, version #1 SMP Wed Aug 23 13:38:27 BST 2006,
>>>> machine
>>>>     x86_64. Hostname grover, IP 127.0.0.1. Libxml version 2.6.16.
>>>> Using native
>>>>     malloc.
>>>>
>>>>     Status: running, uptime 0d 0h 25m 5s
>>>>
>>>>     WDP: received 0 (0 queued), sent 0 (0 queued)
>>>>
>>>>     SMS: received 0 (531104 queued), sent 4 (0 queued), store size
>>>> 634247
>>>>
>>>>     SMS: inbound 0.00 msg/sec, outbound 0.00 msg/sec
>>>>
>>>>     DLR: 0 queued, using internal storage
>>>>
>>>>     No boxes connected
>>>>
>>>>     SMSC connections:
>>>>         test    SMPP:10.100.123.20:7011/7011:test:smpp (online 178s,
>>>> rcvd 0,
>>>>     sent 1, failed 0, queued 25776 msgs)
>>>>         test    SMPP:10.100.123.20:7012/7012:test:smpp (online 177s,
>>>> rcvd 0,
>>>>     sent 1, failed 0, queued 25775 msgs)
>>>>         test    SMPP:10.100.123.20:7013/7013:test:smpp (online 1505s,
>>>> rcvd 0,
>>>>     sent 1, failed 0, queued 25775 msgs)
>>>>         test    SMPP:10.100.123.20:7014/7014:test:smpp (online 1505s,
>>>> rcvd 0,
>>>>     sent 1, failed 0, queued 25776 msgs)
>>>>
>>>>
>>>> BUT, the queue size doesn't match the store size, and Kannel has NOT
>>>> resumed sending those messages (apart from 1 per SMSC, not sure why)
>>>>
>>>> The bearerbox still seems to be busy doing something, even though it
>>>> doesn't seem to be loading messages from store into queues, or
>>>> sending them:
>>>>
>>>>
>>>> [top output]
>>>>
>>>> Mem:   1024580k total,  1009916k used,    14664k free,      248k 
>>>> buffers
>>>> top - 01:46:39 up 1 day,  2:15,  4 users,  load average: 1.68, 2.03,
>>>> 1.81
>>>> Tasks:  82 total,   2 running,  80 sleeping,   0 stopped,   0 zombie
>>>> Cpu(s): 16.5% us,  1.3% sy,  0.0% ni, 49.8% id, 32.1% wa,  0.0% hi,
>>>> 0.3% si
>>>> Mem:   1024580k total,  1009916k used,    14664k free,      332k 
>>>> buffers
>>>> Swap:  2104496k total,   937960k used,  1166536k free,    68740k cached
>>>>
>>>>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>> 18021 kannel    16   0 1265m 812m  924 D 35.3 81.2  18:58.47 bearerbox
>>>>     56 root      15   0     0    0    0 S  0.7  0.0   4:51.60 kswapd0
>>>>
>>>>
>>>> - At this point, it seems that Kannel is somewhat broken... and of
>>>> course, restarting it simply goes through this process all over again
>>>> (reading messages from store, consuming memory, eventually stopping
>>>> and doing nothing)
>>>>
>>>> ADDENDUM:
>>>>
>>>> After waiting a while, the 'SMS' queue counter at the top of the page
>>>> dropped to zero (store size was still ~640k) and the smsbox (which
>>>> hadn't actually connected to the bearerbox until the bearerbox had
>>>> finished all its loading of messages from the store) was finally
>>>> connected, and its queue size had grown to a similar size as the
>>>> bearerbox's queue:
>>>>
>>>>
>>>> [kannel admin page]
>>>>
>>>>     Kannel bearerbox version `cvs-20060830'. Build `Aug 31 2006
>>>> 22:56:51',
>>>>     compiler  `3.4.5  20051201  (Red  Hat 3.4.5-2)'. System Linux,
>>>> release
>>>>     2.6.9-42.0.2.ELsmp, version #1 SMP Wed Aug 23 13:38:27 BST 2006,
>>>> machine
>>>>     x86_64. Hostname grover, IP 127.0.0.1. Libxml version 2.6.16.
>>>> Using native
>>>>     malloc.
>>>>
>>>>     Status: running, uptime 0d 0h 33m 18s
>>>>
>>>>     WDP: received 0 (0 queued), sent 0 (0 queued)
>>>>
>>>>     SMS: received 0 (0 queued), sent 8 (0 queued), store size 634243
>>>>
>>>>     SMS: inbound 0.00 msg/sec, outbound 0.00 msg/sec
>>>>
>>>>     DLR: 0 queued, using internal storage
>>>>
>>>>     Box connections:
>>>>         smsbox:(none), IP 127.0.0.1 (531104 queued), (on-line 0d 0h
>>>> 6m 45s)  <----- *** this is a recent change (originally, while
>>>> bearerbox was busy, no other boxes were connected) ***
>>>>
>>>>     SMSC connections:
>>>>         test    SMPP:10.100.123.20:7011/7011:test:smpp (online 671s,
>>>> rcvd 0,
>>>>     sent 2, failed 0, queued 25775 msgs)
>>>>         test    SMPP:10.100.123.20:7012/7012:test:smpp (online 670s,
>>>> rcvd 0,
>>>>     sent 2, failed 0, queued 25774 msgs)
>>>>         test    SMPP:10.100.123.20:7013/7013:test:smpp (online 1998s,
>>>> rcvd 0,
>>>>     sent 2, failed 0, queued 25776 msgs)
>>>>         test    SMPP:10.100.123.20:7014/7014:test:smpp (online 1998s,
>>>> rcvd 0,
>>>>     sent 2, failed 0, queued 25775 msgs)
>>>>
>>>>
>>>> At this point, 4 more messages have been delivered, but there is no
>>>> other activity, and bearerbox is still chewing up CPU cycles and 
>>>> memory:
>>>>
>>>>
>>>> [top output]
>>>>
>>>> Mem:   1024580k total,  1009916k used,    14664k free,      248k 
>>>> buffers
>>>> top - 01:55:12 up 1 day,  2:23,  4 users,  load average: 1.15, 1.84,
>>>> 1.88
>>>> Tasks:  82 total,   1 running,  81 sleeping,   0 stopped,   0 zombie
>>>> Cpu(s): 15.5% us,  1.2% sy,  0.0% ni, 50.1% id, 32.9% wa,  0.0% hi,
>>>> 0.3% si
>>>> Mem:   1024580k total,  1009892k used,    14688k free,      688k 
>>>> buffers
>>>> Swap:  2104496k total,  1042352k used,  1062144k free,    58272k cached
>>>>
>>>>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>> 18021 kannel    16   0 1297m 770m 1020 S 33.0 77.0  19:48.88 bearerbox
>>>>     56 root      15   0     0    0    0 S  0.3  0.0   5:20.49 kswapd
>>>>
>>>>
>>>> ... after waiting a while further, the server is becoming
>>>> unresponsive, and bearerbox and the VM are still thrashing:
>>>>
>>>> [top output]
>>>>
>>>> Mem:   1024580k total,  1009916k used,    14664k free,      248k 
>>>> buffers
>>>> top - 02:02:01 up 1 day,  2:30,  4 users,  load average: 6.15, 3.51,
>>>> 2.45
>>>> Tasks:  82 total,   1 running,  81 sleeping,   0 stopped,   0 zombie
>>>> Cpu(s):  0.1% us,  0.4% sy,  0.0% ni, 47.5% id, 51.4% wa,  0.1% hi,
>>>> 0.4% si
>>>> Mem:   1024580k total,  1009572k used,    15008k free,      236k 
>>>> buffers
>>>> Swap:  2104496k total,  1038460k used,  1066036k free,    11292k cached
>>>>
>>>>    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
>>>>     56 root      15   0     0    0    0 S  8.4  0.0   5:56.76 kswapd0
>>>>   3011 root      15   0 18824 1436  512 D  6.0  0.1   0:57.46 hald
>>>> 18248 giulio.h  15   0  6148  848  668 R  3.5  0.1   0:07.41 top
>>>>   2443 root      15   0  2548  272  196 S  3.2  0.0   0:02.76 
>>>> irqbalance
>>>>   2920 root      15   0 34996  744  632 S  3.2  0.1   0:24.00 sendmail
>>>> 16918 giulio.h  16   0 53736  376  356 S  3.2  0.0   0:03.72 tail
>>>> 18021 kannel    16   0 1276m 936m 1028 S  0.5 93.6  20:30.30 bearerbox
>>>>
>>>>
>>>> So:
>>>>
>>>> - Any comments on Kannel's behaviour under these circumstances?
>>>> - Apart from stopping Kannel, moving the message store file aside,
>>>> and restarting Kannel, I can't think of any other way of gracefully
>>>> recovering from such a situation - this makes disaster recovery
>>>> difficult...
>>>> - Could Kannel be modified so that it processes stored messages more
>>>> efficiently? (read messages direct from disk, reduce size of messages
>>>> in memory, paralellize processing of stored messages on startup?)
>>>>
>>>> Thanks,
>>>>
>>>> --
>>>> Giulio Harding
>>>> Systems Administrator
>>>>
>>>> m.Net Corporation
>>>> Level 13, 99 Gawler Place
>>>> Adelaide SA 5000, Australia
>>>>
>>>> Tel: +61 8 8210 2041
>>>> Fax: +61 8 8211 9620
>>>> Mobile: 0432 876 733
>>>> MSN: [email protected]
>>>>
>>>> http://www.mnetcorporation.com
>>>
>>> --
>>> Thanks,
>>> Alex
>>>
>>>
>>>
>
> -- 
> Thanks,
> Alex
>
>
>