Re: Possible bug with store

"Alejandro Guerrieri" <[email protected]>
Newsgroups gmane.comp.mobile.kannel.devel
Message-ID <[email protected]> 
Sorry, the previous message should have been sent to the devel list :P

Anyway, I think I've found the problem, and it's not really on
bearerbox/smsbox, but on sqlbox.

The problem seems to arise if I queue a message manually on the sqlbox,
inserting a record on send_sms. If I leave the sms_type field empty, the
message gets delivered, but the sms_type comes as null.

If that message goes to the store and I reboot kannel, the problem arises.
Seems like bearerbox accepts a null sms_type when the message is already
queued, but not if it comes from the store, since it goes through
dispatch_into_queue and it panics.

I can make a patch to not accept NULL on sqlbox's sms_type (using an ENUM
NOT NULL for the field would do the trick IMHO).

I'll make a patch to fix it, any comments?

Regards,

Alejandro

On Thu, Feb 28, 2008 at 8:37 PM, Alejandro Guerrieri <
[email protected]> wrote:

> Dear List,
>
> I'm having problems restarting kannel when messages are on the store (I'm
> using the spool, but the problem happens with the file mode as well).
>
> Sometimes (many times, in fact), if I shutdown kannel when messages are
> being left on the store, I cannot restart without clearing it first.
>
> The error I get is:
>
> 2008-02-28 20:07:08 [27772] [0] PANIC: Not handled sms_type within store!
> 2008-02-28 20:07:08 [27772] [0] PANIC:
> /usr/local/sbin/bearerbox(gw_panic+0xe2) [0x80ce972]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x8055349]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f836]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f204]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f229]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f768]
> 2008-02-28 20:07:08 [27772] [0] PANIC:
> /usr/local/sbin/bearerbox(main+0x7ba) [0x8054dfa]
> 2008-02-28 20:07:08 [27772] [0] PANIC:
> /lib/tls/i686/cmov/libc.so.6(__libc_start_main+0xe0) [0xb791d050]
> 2008-02-28 20:07:08 [27772] [0] PANIC: /usr/local/sbin/bearerbox
> [0x8053b01]
>
> I did a lot of tests, using the msg_dump() function, and in fact the
> messages are in good shape, except for the "sms_type" value, that gets
> loaded with -1. This obviously triggers the "Unhandled sms_type..." message.
>
> I've narrowed the error to bearerbox.c, dispatch_into_queue(Msg). I've
> patched it to dump messages:
>
> static void dispatch_into_queue(Msg *msg)
> {
>     *msg_dump(msg, 0);*
>     gw_assert(msg != NULL),
>     gw_assert(msg_type(msg) == sms);
>
>     *debug("", 0, "TEST sms_type: %d", msg->sms.sms_type);*
>     switch (msg->sms.sms_type) {
>         case mt_push:
>         case mt_reply:
>         case report_mt:
>             gwlist_append(outgoing_sms, msg);
>             break;
>         case mo:
>         case report_mo:
>             gwlist_append(incoming_sms, msg);
>             break;
>         default:
>             panic(0, "Not handled sms_type within store!");
>     }
> }
>
> And this is what I get:
>
> ....
> 2008-02-28 20:12:55 [27893] [0] INFO: Kannel bearerbox II version
> cvs-20080226 starting
> 2008-02-28 20:12:55 [27893] [4] DEBUG: Thread 4
> (gw/bb_boxc.c:sms_to_smsboxes) maps to pid 27893.
> ...
> 2008-02-28 20:12:55 [27893] [5] DEBUG: Thread 5 (gw/bb_boxc.c:smsboxc_run)
> maps to pid 27893.
> 2008-02-28 20:12:55 [27893] [0] DEBUG: Msg object at 0x819e938:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  type: sms
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.sender:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x819ea00:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  5
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 6
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: xx xx xx xx xx
>                                    xxxxx
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.receiver:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x819ea18:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  10
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 11
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: xx xx xx xx xx xx xx xx xx
> xx                     xxxxxxxxxx
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.udhdata:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x819ea40:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.msgdata:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x8197b18:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  156
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 157
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: 55 74 69 6c 69 7a 61 20 65
> 6c 20 6e 75 65 76 6f   Utiliza el nuevo
> ...
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: 69 61 20 61 20 6c 61 20 76
> 65 7a 2e               ia a la vez.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.time: 1202072929
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.smsc_id:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a4450:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  11
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 12
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: xx xx xx xx xx xx xx xx xx
> xx xx                  xxxxxxxxxxx
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.smsc_number:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.service:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a4478:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  7
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 8
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: 33 37 30 30 39 39
> 35                              3700995
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.account:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a44a0:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.id:
> 84de8b2b-ab42-47ae-8d2b-45ecbce50e11
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.sms_type: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.mclass: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.mwi: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.coding: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.compress: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.validity: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.deferred: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.dlr_mask: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.dlr_url:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a44b8:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.pid: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.alt_dcs: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.rpi: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.charset:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a4500:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.boxc_id:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a4518:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  6
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 7
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: 73 71 6c 62 6f
> 78                                 sqlbox
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.binfo:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string at 0x81a4540:
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    len:  17
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    size: 18
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    immutable: 0
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data: 70 72 6f 63 65 73 61 64 6f
> 5f 72 65 63 6f 62 72   procesado_recobr
> 2008-02-28 20:12:55 [27893] [0] DEBUG:    data:
> 6f                                                o
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  Octet string dump ends.
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.msg_left: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.split_parts: (nil)
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.priority: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.resend_try: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG:  sms.resend_time: -1
> 2008-02-28 20:12:55 [27893] [0] DEBUG: Msg object ends.
> *2008-02-28 20:12:55 [27893] [0] DEBUG: TEST sms_type: -1
> *2008-02-28 20:12:55 [27893] [0] PANIC: Not handled sms_type within store!
> 2008-02-28 20:12:55 [27893] [0] PANIC:
> /usr/local/sbin/bearerbox(gw_panic+0xe2) [0x80ce972]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x8055349]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f836]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f204]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f229]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x805f768]
> 2008-02-28 20:12:55 [27893] [0] PANIC:
> /usr/local/sbin/bearerbox(main+0x7ba) [0x8054dfa]
> 2008-02-28 20:12:55 [27893] [0] PANIC:
> /lib/tls/i686/cmov/libc.so.6(__libc_start_main+0xe0) [0xb796e050]
> 2008-02-28 20:12:55 [27893] [0] PANIC: /usr/local/sbin/bearerbox
> [0x8053b01]
>
> This happens with all messages on store (if I replace the panic() with
> debug() I get a line for each and every message!)
>
> So, the messages seems to be ok, but for some reason the sms_type gets
> garbled on the store, or not properly load during init().
>
> Here's an hexdump of the file on disk (I've garbled the numbers for
> privacy):
>
> 00000000  00 00 00 02 00 00 00 05  78 78 78 78 78 00 00 00
> |........xxxxx...|
> 00000010  0a 78 78 78 78 78 78 78  78 78 78 00 00 00 00 00
> |.xxxxxxxxxx.....|
> 00000020  00 00 9c 55 74 69 6c 69  7a 61 20 65 6c 20 6e 75  |...Utiliza el
> nu|
> 00000030  65 76 6f 20 61 6e 69 6f  20 71 75 65 20 63 6f 6d  |evo anio que
> com|
> 00000040  69 65 6e 7a 61 20 70 61  72 61 20 65 73 74 61 62  |ienza para
> estab|
> 00000050  6c 65 63 65 72 20 70 72  6f 79 65 63 74 6f 73 20  |lecer
> proyectos |
> 00000060  72 65 61 6c 69 73 74 61  73 20 79 20 70 6f 73 69  |realistas y
> posi|
> 00000070  62 6c 65 73 2e 20 45 73  20 64 69 66 69 63 69 6c  |bles. Es
> dificil|
> 00000080  20 63 61 6d 62 69 61 72  20 64 65 20 75 6e 20 64  | cambiar de
> un d|
> 00000090  69 61 20 70 61 72 61 20  65 6c 20 6f 74 72 6f 2c  |ia para el
> otro,|
> 000000a0  20 70 72 6f 62 61 20 68  61 63 65 72 6c 6f 20 75  | proba
> hacerlo u|
> 000000b0  6e 20 64 69 61 20 61 20  6c 61 20 76 65 7a 2e 47  |n dia a la
> vez.G|
> 000000c0  a6 2d 61 00 00 00 0b 78  78 78 78 78 78 78 78 78
> |.-a....xxxxxxxxx|
> 000000d0  78 78 ff ff ff ff 00 00  00 07 33 37 30 30 39 39
> |xx........370099|
> 000000e0  35 00 00 00 00 00 00 00  24 38 34 64 65 38 62 32
> |5.......$84de8b2|
> 000000f0  62 2d 61 62 34 32 2d 34  37 61 65 2d 38 64 32 62
> |b-ab42-47ae-8d2b|
> 00000100  2d 34 35 65 63 62 63 65  35 30 65 31 31 ff ff ff
> |-45ecbce50e11...|
> 00000110  ff ff ff ff ff ff ff ff  ff ff ff ff ff ff ff ff
> |................|
> 00000120  ff ff ff ff ff ff ff ff  ff ff ff ff ff 00 00 00
> |................|
> 00000130  00 ff ff ff ff ff ff ff  ff ff ff ff ff 00 00 00
> |................|
> 00000140  00 00 00 00 06 73 71 6c  62 6f 78 00 00 00 11 70
> |.....sqlbox....p|
> 00000150  72 6f 63 65 73 61 64 6f  5f 72 65 63 6f 62 72 6f
> |rocesado_recobro|
> 00000160  ff ff ff ff ff ff ff ff  ff ff ff ff ff ff ff ff
> |................|
> *
> 00000180
>
> Any hints? Anyone else capable of reproducing this?
>
> Regads,
> --
> Alejandro Guerrieri
> Magicom
> http://www.magicom-bcn.net/
> LinkedIn: http://www.linkedin.com/in/aguerrieri




-- 
Alejandro Guerrieri
Magicom
http://www.magicom-bcn.net/
LinkedIn: http://www.linkedin.com/in/aguerrieri
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.