[SR-Users] SIP-XMPP problem, please help
Martin Pohančeník
pohancenik.martin at gmail.com
Tue Apr 5 09:54:12 CEST 2011
These are logged messages from kamailio debug (I hope it is suffieciet .. or
not too much text):
"Message SIP -> XMPP worked correctly like this:"
...
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:630]: SIP Request:
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:632]: method: <MESSAGE>
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:634]: uri: <sip:XMPP_client*xmpp.uniza.sk@
sip.uniza.sk>
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:636]: version: <SIP/2.0>
...
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: xmpp [xmpp.c:381]:
cmd_send_message
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: xmpp [xmpp.c:415]:
message from <sip:SIP_client at sip.uniza.sk>
Apr 5 09:12:36 server /usr/sbin/kamailio[21200]: DEBUG: xmpp [xmpp.c:424]:
using R-URI as destination
Apr 5 09:12:36 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:242]: got pipe cmd 2
Apr 5 09:12:36 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:157]: do_send_message_component from=[
sip:SIP_client at sip.uniza.sk] to=[sip:XMPP_client*xmpp.uniza.sk at sip.uniza.sk]
body=[ahoj]
Apr 5 09:12:36 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:68]: xode_send [<message id='8c7117b7' from='SIP_client*
sip.uniza.sk at xmpp-sip.uniza.sk' to='XMPP_client at xmpp.uniza.sk'
type='chat'><body>ahoj</body></message>]
...
"Message SIP -> XMPP does not work properly:"
...
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:235]: server read#012[<message xmlns='jabber:client'
type='chat' to='SIP_client*sip.uniza.sk at xmpp-sip.uniza.sk' id='mir_45'
from='XMPP_client at xmpp.uniza.sk/Miranda'><body>DOBRY DEN</body></message>]
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:85]: stream callback: 1: message
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: xmpp
[xmpp_component.c:102]: XMPP IM received
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: tm [uac.c:240]:
DEBUG:tm:t_uac: next_hop=<sip:SIP_client at sip.uniza.sk>
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[dns_cache.c:567]: dns_hash_find(_sip._udp.sip.uniza.sk(26), 33), h=524
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[resolve.c:924]: get_record: skipping 1 NS (p=0x816f57, end=0x816f90)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[resolve.c:940]: get_record: parsing 2 ARs (p=0x816f70, end=0x816f90)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[dns_cache.c:1777]: dns_get_related(0x7ffb6f526770 (_sip._udp.sip.uniza.sk,
33), 33, *0x960ce8) (0)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[dns_cache.c:870]: dns_cache_add: adding _sip._udp.sip.uniza.sk(26) 33
(flags=0) at 524
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[dns_cache.c:870]: dns_cache_add: adding server.sip.uniza.sk(23) 1 (flags=0)
at 476
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[dns_cache.c:567]: dns_hash_find(server.sip.uniza.sk(23), 1), h=476
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: tm [uac.c:181]:
DEBUG: dlg2hash: 40039
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:630]: SIP Request:
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:632]: method: <MESSAGE>
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:634]: uri: <sip:SIP_client at sip.uniza.sk>
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:636]: version: <SIP/2.0>
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK76c9.3ad70364.0>; state=16
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/parse_via.c:2300]: end of header reached, state=5
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers: Via found, flags=2
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:517]: parse_headers: this is the first via
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[receive.c:145]: After parse_msg...
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[receive.c:186]: preparing to run routing scripts...
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/parse_to.c:803]: end of header reached, state=9
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [28]; uri=[
sip:katka at p2b.sip.uniza.sk]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:189]: DEBUG: to body [
sip:katka at p2b.sip.uniza.sk#015#012]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <10> <MESSAGE>
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:201]: DEBUG: get_hdr_body : content_length=9
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/msg_parser.c:103]: found end of header
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: maxfwd
[mf_funcs.c:66]: max_forwards header not found!
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/parse_to.c:174]: DEBUG: add_param:
tag=533cb9e91f4b999cf76861cbb9ed54ed-07b4
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[parser/parse_to.c:803]: end of header reached, state=29
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: siputils
[checks.c:73]: no totag
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: tm
[t_lookup.c:1081]: DEBUG: t_check_msg: msg id=2 global id=1 T
start=0xffffffffffffffff
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: tm
[t_lookup.c:528]: t_lookup_request: start searching: hash=40039, isACK=0
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: tm
[t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: tm
[t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: tm
[t_lookup.c:1150]: DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:501]: grep_sock_info - checking if host==us: 16==9 && [
p2b.sip.uniza.sk] == [127.0.0.1]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:501]: grep_sock_info - checking if host==us: 16==14 && [
p2b.sip.uniza.sk] == [158.193.139.65]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:501]: grep_sock_info - checking if host==us: 16==9 && [
p2b.sip.uniza.sk] == [127.0.0.1]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:501]: grep_sock_info - checking if host==us: 16==14 && [
p2b.sip.uniza.sk] == [158.193.139.65]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[socket_info.c:504]: grep_sock_info - checking if port 5060 matches port
5060
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: auth_db
[authorize.c:239]: realm value [p2b.sip.uniza.sk]
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: auth [api.c:85]:
auth:pre_auth: Credentials with realm 'p2b.sip.uniza.sk' not found
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: auth_db
[authorize.c:257]: not authenticated
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: auth
[challenge.c:102]: build_challenge_hf: realm='p2b.sip.uniza.sk'
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: auth
[challenge.c:236]: auth: 'Proxy-Authenticate: Digest realm="p2b.sip.uniza.sk",
nonce="TZrCGE2awOxSpM6/mMSW
aCcpGpCCn2al"#015#012'
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: sl [sl.c:278]:
reply in stateless mode (sl)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[msg_translator.c:204]: check_via_address(158.193.139.65, 158.193.139.65, 0)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:640]: SIP Reply (status):
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:642]: version: <SIP/2.0>
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:644]: status: <407>
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:646]: reason: <Proxy Authentication Required>
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK76c9.3ad70364.0>; state=16
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/parse_via.c:2300]: end of header reached, state=5
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:515]: parse_headers: Via found, flags=2
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:517]: parse_headers: this is the first via
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[receive.c:145]: After parse_msg...
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_lookup.c:1081]: DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/parse_to.c:174]: DEBUG: add_param:
tag=b27e1a1d33761e85846fc98f5f3a7e58.1808
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/parse_to.c:803]: end of header reached, state=29
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [70]; uri=[
sip:katka at p2b.sip.uniza.sk]
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:189]: DEBUG: to body [sip:katka at p2b.sip.uniza.sk]
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <10> <MESSAGE>
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:201]: DEBUG: get_hdr_body : content_length=0
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[parser/msg_parser.c:103]: found end of header
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_lookup.c:967]: DEBUG: t_reply_matching: hash 40039 label 1177583011
branch 0
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched
(T=0x7ffb6f526990)!
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_lookup.c:1150]: DEBUG: t_check_msg: msg id=2 global id=2 T
end=0x7ffb6f526990
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_reply.c:2014]: DEBUG: reply_received: org. status uas=0, uac[0]=0 local=2
is_invite=0)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_reply.c:1129]: ->>>>>>>>> T_code=0, new_code=407
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_reply.c:1892]: DEBUG: local_reply: branch=0, save=0, winner=0
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_reply.c:1929]: DEBUG: local transaction completed
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: tm
[t_reply.c:1470]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21197]: DEBUG: <core>
[receive.c:289]: receive_msg: cleaning up
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Apr 5 09:12:45 server /usr/sbin/kamailio[21200]: DEBUG: <core>
[receive.c:289]: receive_msg: cleaning up
Apr 5 09:12:45 server /usr/sbin/kamailio[21210]: DEBUG: tm [timer.h:145]:
_set_fr_timer: too late, timer already marked for deletion
...
Why is Kamailio doing a DNS SRV query for himself after he has recieved a
message from XMPP and translated it to SIP ??
2011/4/4 Daniel-Constantin Mierla <daniel at kamailio.org>
> Hello,
>
> if you run kamailio with debug=3, what log messages are printed when the
> xmpp message arrives to kamailio?
>
> Cheers,
> Daniel
>
>
> On 4/4/11 7:19 PM, Martin Pohančeník wrote:
>
> Hello everyone.
> I am a student at University of Žilina (Faculty of Management Science and
> Informatics), which has been recently awarded Kamailio 2010 Awards for
> various articles about SIP and KAMAILIO on portal nil.uniza.sk.
> I am doing a bachelor thesis on topic SIP/SIMPLE - XMPP traversal, but I am
> experiencing some problems.
> I have a working Kamailio server serving domain sip.uniza.sk and a working
> Jabberd2 server serving domain xmpp.uniza.sk.
> I am running Kamailio 3.1 with XMPP module with following configuration:
>
> fork=yes
> children=4
> log_stderror=yes
> alias="sip.uniza.sk"
> ...
> loadmodule "XMPP.so"
> ...
> modparam("xmpp", "backend", "component")
> modparam("xmpp", "domain_separator", "*")
> modparam("xmpp", "gateway_domain", "sip.uniza.sk")
> modparam("xmpp", "xmpp_domain", "xmpp-sip.uniza.sk")
> modparam("xmpp", "xmpp_host", "server.xmpp.uniza.sk")
> modparam("xmpp", "xmpp_password", "secret")
> ...
> #main routing logic
> route {
> ...
> if( uri=~"sip:.+[*].+ at sip.uniza.sk")
> {
> # absorb retransmissions ###
> if (!t_newtran())
> {
> sl_reply_error();
> return;
> }
> if (method == "MESSAGE")
> {
> log("*** xmpp-handled MESSAGE message.\n");
> if (xmpp_send_message())
> {
> t_reply("200", "Accepted");
> } else
> {
> t_reply("404", "Not found");
> }
> return;
> } else
> {
> t_reply("403","not supported");
> exit;
> }
> }
> ...
> }
>
> To my knowledge there is no configuration required on the Jabberd2 server
> (except the password, that the XMPP component authenticates with).
> I am trying to enable SIP clients to chat with the XMPP clients and vice
> versa.
> SIP clients can send messages to XMPP clients. XMPP modules translates SIP
> to XMPP and forwards the massage to Jabberd2 server.
> URIs look like:
> XMPP client from SIP view: xmpp_client*xmpp.uniza.sk at sip.uniza.sk
> SIP client from XMPP view: sip_client*sip.uniza.sk at xmpp-sip.uniza.sk
> The message arrives to XMPP client, but he can not reply.
> I have sniffed the traffic on the Kamailio server. The XMPP message arrives
> to kamailio XMPP module (correct port and everything), but the module
> somehow ignores it, doesn't translate XMPP to SIP and doesn't send it to the
> SIP recipient.
> The sniffed message looks like:
>
> <message xmlns='jabber:client' type='chat' to='SIP_client*sip.uniza.sk@
> xmpp-sip.uniza.sk' id='mir_47' from='XMPP_client at xmpp.uniza.sk/Miranda
> '><body>hello</body></message>
>
> Any suggestions on where can the problem be ??
> Do I have to add some lines to routing logic for XMPP module to process the
> XMPP message (from Jabberd2) for SIP_client ??
>
> Thanks
> Martin
>
>
> _______________________________________________
> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing listsr-users at lists.sip-router.orghttp://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20110405/711d275e/attachment-0001.htm>
More information about the sr-users
mailing list