Attached is kamailio debug log while trying to send a MESSAGE to an MSN
contact from my SIP Account. [email protected] is the MSN account
available on the SIP Buddy list. THe MESSAGE send fails and the server sends
back 202 and then 404.

THe debug message is attached. Any input is appreciated.

On Tue, Jun 16, 2009 at 10:00 AM, mani sivaraman <[email protected]>wrote:

> Hi Eric
> Could you please post a working example kamailio.cfg file with the example
> purplemap table contents (remove passwords from it). I guess I'm doing some
> mistake in coding purple_handle_subscribe,  purple_handle_publish() and
> purple_send_message. Your help is really apppreciated.
>
> What IM Client did you use to test/develop purple ? Is it X-Lite ? I would
> like to try purple with that client first. Please let me know. I want to get
> the first PUB/SUB and MESSAGE working bet SIP and MSN or Gmail or yahoo.
>
> Your help is appreciated.
> - Mani
>
>
> On Tue, Jun 16, 2009 at 2:56 AM, Eric PTAK <[email protected]> wrote:
>
>> Hi,
>>
>> The PUBLISH has to be processed normally by the Presence
>> Server (eg handle_publish) to get the response.
>> Then, you can also use purple_handle_publish to propagate you status to
>> external protocols.
>> Whenever, you should not get that error regarding the db entry and the
>> publish sip uri...
>> Need more checks...
>>
>> Eric.
>>
>> 2009/6/15 mani sivaraman <[email protected]>
>>
>>> Hi Eric
>>> I keep getting this error messages when I setup the purplemap table in
>>> mysql and enable purple PUB/SUN processing in openser. I have only one
>>> mapping purplemap table like this. My SIP client is trying to send presence
>>> PUBLISH, but this never gets ACKed by openser server. And I get this error
>>> every time PUB happens "ERROR:purple:find_accounts: result count = 0"
>>>
>>> sip:[email protected]<sip%[email protected]>|
>>> [email protected] | gtalk | xxxx
>>>
>>>
>>> PUBLISH 
>>> sip:[email protected]<sip%[email protected]>from
>>>  [
>>> sip:[email protected]<sip%[email protected]>]
>>> to 
>>> [sip:[email protected]<sip%[email protected]>
>>> ]
>>> Jun 15 14:37:47 [17541] ERROR:purple:find_accounts: result count = 0
>>> SUBSCRIBE 
>>> sip:[email protected]<sip%[email protected]>from
>>>  [
>>> sip:[email protected]<sip%[email protected]>]
>>> to 
>>> [sip:[email protected]<sip%[email protected]>
>>> ]
>>> Jun 15 14:37:47 [17535] INFO:presence:send_notify_request: NOTIFY
>>> sip:[email protected]<sip%[email protected]>via
>>>  sip:[email protected]:6332;transport=udp
>>> on behalf of 
>>> sip:[email protected]<sip%[email protected]>for
>>>  event presence.winfo
>>> SUBSCRIBE 
>>> sip:[email protected]<sip%[email protected]>from
>>>  [
>>> sip:[email protected]<sip%[email protected]>]
>>> to 
>>> [sip:[email protected]<sip%[email protected]>
>>> ]
>>> Jun 15 14:37:47 [17541] ERROR:purple:find_accounts: result count = 0
>>>
>>> Your assistance is appreciated.
>>> Thanks
>>> Mani
>>>
>>>
>>> On Mon, Jun 15, 2009 at 11:13 AM, mani sivaraman <
>>> [email protected]> wrote:
>>>
>>>> That was it. I did that first time and then I forgot to set the env
>>>> variable again. I will add it to ctl script now. Thanks for your help. I
>>>> appreciate it. I will now go on to adding processing of MESSAGE, PUBLISH
>>>> NOTIFY etc.
>>>>
>>>> Thank you
>>>>
>>>>
>>>> On Mon, Jun 15, 2009 at 10:14 AM, Eric PTAK <[email protected]>wrote:
>>>>
>>>>> Did you added LD_PRELOAD=/path/to/your/libpurple.so env var in your ctl
>>>>> script ?
>>>>>
>>>>> Eric.
>>>>>
>>>>> 2009/6/15 mani sivaraman <[email protected]>
>>>>>
>>>>> Thanks for getting back Eric. After opensips I tested the latest
>>>>>> Kamailio 1.5.1 code with purple module. I get the same SIGCHLD core dump 
>>>>>> on
>>>>>> Kamailio as well. I saw Kamailio comes with purple source code. If I load
>>>>>> purple.so and then add the modprobe for purple, I get the core dump. Is
>>>>>> there any thing I can check or look for in the debug to make sure it 
>>>>>> works.
>>>>>> If I unload purple and remove the respective modprobes every thing seems 
>>>>>> to
>>>>>> work fine.
>>>>>>
>>>>>> Thank you
>>>>>>
>>>>>>
>>>>>> On Mon, Jun 15, 2009 at 3:15 AM, Eric PTAK <[email protected]>wrote:
>>>>>>
>>>>>>> Hi mani,
>>>>>>>
>>>>>>> purple module hasn't been tested with opensips, and I can't say if it
>>>>>>> should work.
>>>>>>> but just a question : how did you compile the module ? eg, within
>>>>>>> which project ?
>>>>>>>
>>>>>>> regards,
>>>>>>> eric.
>>>>>>>
>>>>>>> 2009/6/12 mani sivaraman <[email protected]>
>>>>>>>
>>>>>>>>  I compiled and installed opensips 1.5.1 with mysql db and works
>>>>>>>> fine. I compiled and installed the new purple module from outside and
>>>>>>>> installed the same. if I try to load the purple.so module and add 
>>>>>>>> modprobe
>>>>>>>> for purple params, opensips core dumps saying
>>>>>>>>
>>>>>>>> Jun 12 12:06:38 [22121] CRITICAL:core:receive_fd: EOF on 15
>>>>>>>> Jun 12 12:06:38 [22103] INFO:core:handle_sigs: child process 22110
>>>>>>>> exited by a signal 11
>>>>>>>> Jun 12 12:06:38 [22103] INFO:core:handle_sigs: core was generated
>>>>>>>> Jun 12 12:06:38 [22103] INFO:core:handle_sigs: terminating due to
>>>>>>>> SIGCHLD
>>>>>>>> Jun 12 12:06:38 [22104] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22105] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22106] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22107] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22108] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22114] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22109] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22115] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22116] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22117] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22119] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22121] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22112] INFO:core:sig_usr: signal 15 received
>>>>>>>> Jun 12 12:06:38 [22103] NOTICE:presence:destroy: destroy module ...
>>>>>>>>
>>>>>>>>
>>>>>>>> The gdb back trace is not very useful either.
>>>>>>>>
>>>>>>>> (no debugging symbols found)
>>>>>>>> Core was generated by `opensips'.
>>>>>>>> Program terminated with signal 11, Segmentation fault.
>>>>>>>> [New process 22083]
>>>>>>>> #0  0x085a9c6d in ?? ()
>>>>>>>> (gdb) backtrace full
>>>>>>>> #0  0x085a9c6d in ?? ()
>>>>>>>> No symbol table info available.
>>>>>>>> (gdb)
>>>>>>>>
>>>>>>>> Help Any one , Please.
>>>>>>>>
>>>>>>>>
>>>>>>>> _______________________________________________
>>>>>>>> Users mailing list
>>>>>>>> [email protected]
>>>>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> Users mailing list
>>>>> [email protected]
>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>
>>>>>
>>>>
>>>
>>
>
MESSAGE sip:manivasagam.s*[email protected] from 
[sip:[email protected]] to [sip:m                                 
                  anivasagam.s*[email protected]]
Invoking Purple send MESSAGE from [sip:[email protected]] to 
[sip:manivasagam.s*msn....@kmilo                                                
   .smithmicro.com]
Jun 16 11:23:06 [18149] DBG:purple:func_send_message: handling MESSAGE
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 16 11:23:06 [18149] DBG:core:get_hdr_field: content_length=2
Jun 16 11:23:06 [18149] DBG:core:get_hdr_field: found end of header
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=18
Jun 16 11:23:06 [18149] DBG:purple:func_send_message: message from 
<sip:[email protected]>
Jun 16 11:23:06 [18149] DBG:purple:func_send_message: using R-URI as destination
Jun 16 11:23:06 [18149] DBG:purple:purple_send_message_cmd: building MESSAGE cmd
Jun 16 11:23:06 [18149] DBG:purple:purple_new_cmd: allocating cmd
Jun 16 11:23:06 [18149] DBG:purple:purple_send_cmd: writing cmd to pipe
Jun 16 11:23:06 [18149] DBG:purple:purple_send_cmd: cmd has been wrote to pipe
Jun 16 11:23:06 [18149] DBG:purple:func_send_message: message parsed and sent 
to pipe successfully
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 16 11:23:06 [18149] DBG:core:check_via_address: params 172.16.1.125, 
172.16.1.125, 0
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if host==us: 20==9 && 
 [kmilo.smithmicro.com] ==                                                    
[127.0.0.1]
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if port 5060 matches 
port 5060
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if host==us: 20==12 
&&  [kmilo.smithmicro.com] ==                                                   
 [172.16.0.141]
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if port 5060 matches 
port 5060
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if host==us: 20==9 && 
 [kmilo.smithmicro.com] ==                                                    
[127.0.0.1]
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if port 5060 matches 
port 5060
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if host==us: 20==12 
&&  [kmilo.smithmicro.com] ==                                                   
 [172.16.0.141]
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: checking if port 5060 matches 
port 5060
Jun 16 11:23:06 [18149] DBG:core:grep_sock_info: no match for: 
[kmilo.smithmicro.com:5060]
Jun 16 11:23:06 [18149] DBG:core:grep_aliases: comparing host 
[0:kmilo.smithmicro.com:5060] with us [2:kmil                                   
                o.smithmicro.com:5060]
Jun 16 11:23:06 [18149] DBG:core:grep_aliases: match found for: 
[0:kmilo.smithmicro.com:5060]
Jun 16 11:23:06 [18149] DBG:core:check_self: host == me
Jun 16 11:23:06 [18149] DBG:registrar:lookup: 'manivasagam.s*msn.com' Not found 
in usrloc
Jun 16 11:23:06 [18149] DBG:tm:t_newtran: transaction on entrance=(nil)
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=78
Jun 16 11:23:06 [18149] DBG:tm:t_lookup_request: start searching: hash=62816, 
isACK=0
Jun 16 11:23:06 [18149] DBG:tm:matching_3261: RFC3261 transaction matching 
failed
Jun 16 11:23:06 [18149] DBG:tm:t_lookup_request: no transaction found
Jun 16 11:23:06 [18149] DBG:tm:run_reqin_callbacks: trans=0xb56635d8, callback 
type 1, id 0 entered
Jun 16 11:23:06 [18149] DBG:core:parse_headers: flags=ffffffffffffffff
Jun 16 11:23:06 [18149] DBG:core:check_via_address: params 172.16.1.125, 
172.16.1.125, 0
Jun 16 11:23:06 [18149] DBG:core:_shm_resize: resize(0) called
Jun 16 11:23:06 [18149] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jun 16 11:23:06 [18149] DBG:tm:insert_timer_unsafe: [2]: 0xb5663620 (36)
Jun 16 11:23:06 [18149] DBG:tm:_reply_light: reply sent out. buf=0x8194cb8: 
SIP/2.0 4..., shmem=0xb565b718:                                                 
   SIP/2.0 4
Jun 16 11:23:06 [18149] DBG:tm:_reply_light: finished
Jun 16 11:23:06 [18149] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Jun 16 11:23:06 [18149] DBG:core:destroy_avp_list: destroying list (nil)
Jun 16 11:23:06 [18149] DBG:core:receive_msg: cleaning up
Jun 16 11:23:06 [18161] DBG:purple:pipe_reader: received message cmd via pipe 
from <sip:[email protected]                                                   
ithmicro.com> to <sip:manivasagam.s*[email protected]>
Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: handling message cmd
Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: calling 
find_accounts("sip:[email protected]                                     
              cro.com", &naccounts)
Jun 16 11:23:06 [18161] DBG:purple:find_accounts: looking up external account 
for sip:[email protected]                                                   
hmicro.com
Jun 16 11:23:06 [18161] DBG:core:db_do_init: connection 0x818f770 not found in 
pool
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: opening 
connection: mysql://xxxx:[email protected].                                           
        0.141/openser
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: connection type 
is 172.16.0.141 via TCP/IP
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: protocol version 
is 10
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: server version is 
5.0.51a-24+lenny1
Jun 16 11:23:06 [18161] DBG:core:db_new_result: allocate 28 bytes for result 
set at 0x818fc98
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 3 columns returned 
from the query
Jun 16 11:23:06 [18161] DBG:core:db_allocate_columns: allocate 12 bytes for 
result names at 0x8181128
Jun 16 11:23:06 [18161] DBG:core:db_allocate_columns: allocate 12 bytes for 
result types at 0x8181140
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for 
RES_NAMES[0] at 0x818f900
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 
RES_NAMES(0x818f900)[0]=[ext_prot]
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result 
type
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for 
RES_NAMES[1] at 0x818fc28
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 
RES_NAMES(0x818fc28)[1]=[ext_user]
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result 
type
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for 
RES_NAMES[2] at 0x818fa28
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 
RES_NAMES(0x818fa28)[2]=[ext_pass]
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result 
type
Jun 16 11:23:06 [18161] DBG:core:db_allocate_rows: allocate 8 bytes for rows at 
0x8181158
Jun 16 11:23:06 [18161] DBG:core:db_allocate_row: allocate 60 bytes for row 
values at 0x8181168
Jun 16 11:23:06 [18161] DBG:core:db_str2val: converting STRING [prpl-msn-pecan]
Jun 16 11:23:06 [18161] DBG:core:db_str2val: converting STRING 
[[email protected]]
Jun 16 11:23:06 [18161] DBG:core:db_str2val: converting STRING [goriudf]
Jun 16 11:23:06 [18161] DBG:purple:find_accounts: sql query done
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing 3 columns
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing RES_NAMES[0] at 
0x818f900
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing RES_NAMES[1] at 
0x818fc28
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing RES_NAMES[2] at 
0x818fa28
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing result names at 
0x8181128
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing result types at 
0x8181140
Jun 16 11:23:06 [18161] DBG:core:db_free_rows: freeing 1 rows
Jun 16 11:23:06 [18161] DBG:core:db_free_row: freeing row values at 0x8181168
Jun 16 11:23:06 [18161] DBG:core:db_free_rows: freeing rows at 0x8181158
Jun 16 11:23:06 [18161] DBG:core:db_free_result: freeing result set at 0x818fc98
Jun 16 11:23:06 [18161] DBG:core:pool_remove: removing connection from the pool
Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: found 1 extra 
account(s) for <sip:msivara...@kmilo.                                           
        smithmicro.com>Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: 
calling find_users("sip:manivasagam.                                            
       s*[email protected]", &nusers)
Jun 16 11:23:06 [18161] DBG:purple:find_users: looking up external users for 
sip:manivasagam.s*msn....@kmil                                                  
 o.smithmicro.com
Jun 16 11:23:06 [18161] DBG:core:db_do_init: connection 0x818f770 not found in 
pool
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: opening 
connection: mysql://xxxx:[email protected].                                           
        0.141/openser
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: connection type 
is 172.16.0.141 via TCP/IP
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: protocol version 
is 10
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_new_connection: server version is 
5.0.51a-24+lenny1
Jun 16 11:23:06 [18161] DBG:core:db_new_result: allocate 28 bytes for result 
set at 0x818fc98
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 2 columns returned 
from the query
Jun 16 11:23:06 [18161] DBG:core:db_allocate_columns: allocate 8 bytes for 
result names at 0x8181158
Jun 16 11:23:06 [18161] DBG:core:db_allocate_columns: allocate 8 bytes for 
result types at 0x818fa28
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for 
RES_NAMES[0] at 0x818fc28
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 
RES_NAMES(0x818fc28)[0]=[ext_prot]
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result 
type
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: allocate 8 bytes for 
RES_NAMES[1] at 0x818f900
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: 
RES_NAMES(0x818f900)[1]=[ext_user]
Jun 16 11:23:06 [18161] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result 
type
Jun 16 11:23:06 [18161] DBG:core:db_allocate_rows: allocate 8 bytes for rows at 
0x818d108
Jun 16 11:23:06 [18161] DBG:core:db_allocate_row: allocate 40 bytes for row 
values at 0x8181168
Jun 16 11:23:06 [18161] DBG:core:db_str2val: converting STRING [prpl-msn-pecan]
Jun 16 11:23:06 [18161] DBG:core:db_str2val: converting STRING 
[[email protected]]
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing 2 columns
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing RES_NAMES[0] at 
0x818fc28
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing RES_NAMES[1] at 
0x818f900
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing result names at 
0x8181158
Jun 16 11:23:06 [18161] DBG:core:db_free_columns: freeing result types at 
0x818fa28
Jun 16 11:23:06 [18161] DBG:core:db_free_rows: freeing 1 rows
Jun 16 11:23:06 [18161] DBG:core:db_free_row: freeing row values at 0x8181168
Jun 16 11:23:06 [18161] DBG:core:db_free_rows: freeing rows at 0x818d108
Jun 16 11:23:06 [18161] DBG:core:db_free_result: freeing result set at 0x818fc98
Jun 16 11:23:06 [18161] DBG:core:pool_remove: removing connection from the pool
Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: found 1 extra user(s) 
for <sip:manivasagam.s*msn.co                                                   
[email protected]>Jun 16 11:23:06 [18161] 
DBG:purple:pipe_handle_message: calling client_find_account(                    
                               "[email protected]")
Jun 16 11:23:06 [18161] DBG:purple:client_find_account: searching purple 
account for [email protected]                                               
     with plugin prpl-msn-pecan
Jun 16 11:23:06 [18161] DBG:purple:client_find_account: account 
[email protected] not found, creating.
Jun 16 11:23:06 [18161] DBG:purple:pipe_handle_message: account is disconnected 
cannot send message
Jun 16 11:23:06 [18161] DBG:purple:purple_free_cmd: freeing cmd
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users

Reply via email to