[SR-Users] Msilo not delivering message (status 408)

Daniel-Constantin Mierla miconda at gmail.com
Fri Jul 18 00:01:41 CEST 2014


You should not call m_store() if src_ip==myself -- in this way you avoid 
to store notification messages that cannot be delivered.

Why notifications are not delivered has to be troubleshooted there. Have 
you tried also with UDP?

Cheers,
Daniel

On 17/07/14 23:46, Peter Villeneuve wrote:
> Well I've been experimenting with this for hours and still no joy
>  :(  Hair pulling continues
>
> Here's what I did to help debug. I updated to 4.2 and I started using 
> the default TCP listener on 5060 and have turned off the TLS listener 
> to make debugging easier.
> I have also tried using the routing config from here 
> <http://telephonynetworks.blogspot.pt/2012/08/configuracion-de-kamailio-33-con-nat.html> but 
> I get the exact same results as with the routing posted above, which 
> tends to rule out any config issues (I think).
>
> Here's what I found so far.
>
> If I don't set the msilo outbound proxy like Daniel suggested, I get 
> the dreaded "no socket found" error I mentioned earlier.
>
> If I do set the proxy, the offline message does get delivered as 
> expected. The problem is that once I send a new message to an offline 
> user, the caller doesn't receive the "user whatever is offline" 
> message, but simply a 202.
> Then I look in msilo DB and suddenly I have 7k messages and growing 
> and have to shut down kamailio and clean the db.
>
> Example to make understanding this weird behavior easier. Msilo 
> outbound proxy set:
>
> 1010 sends msg "testing 123" to 1000 (offline). Msilo stores the msg 
> correctly, although 1010 never does receive the "***User 1000 is 
> offline!" message, only a 202 I see in ngrep.
> I then look in the msilo db and confirm the "testing 123" msg is 
> there. But right after there is another message stored in msilo, which 
> is what should have been sent to 1000 instead of being stored in the silo.
>
> sip:registrar at my.domain.com 	sip:1010 at my.domain.com 
> <mailto:sip%3A1010 at my.domain.com> 	1010 	my.domain.com 
> <http://my.domain.com> 	2014-07-17 14:11:00 	*** User 1000 is offline!
>
>
> And then registrar storing a message for registrar saying 1010 is 
> offline (which is obviously wrong since 1010 just sent the msg)
>
> sip:registrar at my.domain.com 	sip:registrar at my.domain.com 	registrar 
> my.domain.com
> 	2014-07-17 14:11:00 	*** User 1010 is offline!
>
>
> And then it gets simply crazy with over 7K repeating messages in the 
> silo saying the user registrar is offline.
>
> sip:registrar at my.domain.com 	sip:registrar at my.domain.com 	registrar 
> my.domain.com
> 	2014-07-17 14:11:00 	*** User registrar is offline!
>
>
>
> To top it all off I see this in the sip trace
>
> What's puzzling me is this: 79.my.server.IP1:58487 -> 
> 79.my.server.IP1:5060
>
> Why does kamailio send to itself from port 58487 to 5060 and not from 
> 5060 to the UAC's public IP?
>
>
> Sorry to dump so much info here but I'm hoping to resolve this before 
> I go nuts.
>
> Daniel, when you have the time can you take a look please?
>
> Thanks,
> Peter
>
> T 2014/07/17 21:10:30.383043 85.xx.xx.xx:50235 -> 
> 79.my.server.IP1:5060 [AP]
> MESSAGE sip:1000 at my.domain.com <mailto:sip%3A1000 at my.domain.com> SIP/2.0.
> v: SIP/2.0/TCP 
> 192.168.1.4:50235;rport;branch=z9hG4bKPjCYikazjsY44q1jqMtDzapRCfqofgZ.3O;alias.
> Max-Forwards: 70.
> f: <sip:1010 at my.domain.com 
> <mailto:sip%3A1010 at my.domain.com>>;tag=s.HDD1ArN1dDgnwxgeWWK7meY98dkvrS.
> t: <sip:1000 at my.domain.com <mailto:sip%3A1000 at my.domain.com>>.
> i: p8PAwoJ6ZLCy7ClSqe8sXD8FWMTU3LQ9.
> CSeq: 64674 MESSAGE.
> Accept: text/plain, application/im-iscomposing+xml.
> User-Agent: PJSIP_m3-19/r2423.
> Route: <sip:my.domain.com <http://my.domain.com>;transport=tcp;lr>.
> c: text/plain.
> l:    25.
> .
> msg from 1010 to 1000
>
> T 2014/07/17 21:10:30.390095 *79.my.server.IP1:58487 -> 
> 79.my.server.IP1:5060* [AP]
> MESSAGE sip:1010 at my.domain.com <mailto:sip%3A1010 at my.domain.com> SIP/2.0.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK17.50c7d2e1000000000000000000000000.0.
> To: <sip:1010 at my.domain.com <mailto:sip%3A1010 at my.domain.com>>.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-ecd9.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f619-29814 at 79.my.server.IP1.
> Max-Forwards: 70.
> Content-Length: 25.
> User-Agent: kamailio (4.2.0-dev7 (x86_64/linux)).
> Contact: registrar at my.domain.com 
> <mailto:registrar at my.domain.com>;msilo=yes.
> Content-Type: text/plain.
> .
> *** User 1000 is offline!
>
> T 2014/07/17 21:10:30.390156 79.my.server.IP1:5060 -> 
> 85.xx.xx.xx:50235 [AP]
> SIP/2.0 202 ACCEPTED.
> v: SIP/2.0/TCP 
> 192.168.1.4:50235;rport=50235;branch=z9hG4bKPjCYikazjsY44q1jqMtDzapRCfqofgZ.3O;alias;received=85.xx.xx.xx.
> f: <sip:1010 at my.domain.com 
> <mailto:sip%3A1010 at my.domain.com>>;tag=s.HDD1ArN1dDgnwxgeWWK7meY98dkvrS.
> t: <sip:1000 at my.domain.com 
> <mailto:sip%3A1000 at my.domain.com>>;tag=83a51ef5beb3f269619e74eb008b8b4e.7652.
> i: p8PAwoJ6ZLCy7ClSqe8sXD8FWMTU3LQ9.
> CSeq: 64674 MESSAGE.
> Server: kamailio (4.2.0-dev7 (x86_64/linux)).
> Content-Length: 0.
> .
>
>
> T 2014/07/17 21:10:30.390441 79.my.server.IP1:5060 -> 
> 85.xx.xx.xx:50235 [AP]
> MESSAGE sip:1010 at 85.xx.xx.xx:50235;transport=TCP SIP/2.0.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK17.f09631e651d35b19e10d44b11fe53d81.0;i=3.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;rport=58487;branch=z9hG4bK17.50c7d2e1000000000000000000000000.0.
> To: <sip:1010 at my.domain.com <mailto:sip%3A1010 at my.domain.com>>.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-ecd9.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f619-29814 at 79.my.server.IP1.
> Max-Forwards: 69.
> Content-Length: 25.
> User-Agent: kamailio (4.2.0-dev7 (x86_64/linux)).
> Contact: registrar at my.domain.com 
> <mailto:registrar at my.domain.com>;msilo=yes.
> Content-Type: text/plain.
> .
> *** User 1000 is offline!
>
> T 2014/07/17 21:11:00.357394 79.my.server.IP1:58487 -> 
> 79.my.server.IP1:5060 [AP]
> MESSAGE sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com> SIP/2.0.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK24f7.237c32d3000000000000000000000000.0.
> To: <sip:registrar at my.domain.com <mailto:sip%3Aregistrar at my.domain.com>>.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-a22d.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f618-29809 at 79.my.server.IP1.
> Max-Forwards: 70.
> Content-Length: 25.
> User-Agent: kamailio (4.2.0-dev7 (x86_64/linux)).
> Contact: registrar at my.domain.com 
> <mailto:registrar at my.domain.com>;msilo=yes.
> Content-Type: text/plain.
> .
> *** User 1010 is offline!
>
> T 2014/07/17 21:11:00.358375 79.my.server.IP1:5060 -> 
> 79.my.server.IP1:58487 [AP]
> SIP/2.0 202 ACCEPTED.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK17.50c7d2e1000000000000000000000000.0;rport=58487.
> To: <sip:1010 at my.domain.com 
> <mailto:sip%3A1010 at my.domain.com>>;tag=9916224dd8b1ec9235e0f958cedf67cc-fe6b.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-ecd9.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f619-29814 at 79.my.server.IP1.
> Server: kamailio (4.2.0-dev7 (x86_64/linux)).
> Content-Length: 0.
> .
>
>
> T 2014/07/17 21:11:00.359438 79.my.server.IP1:58487 -> 
> 79.my.server.IP1:5060 [AP]
> MESSAGE sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com> SIP/2.0.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK810c.0eb84110000000000000000000000000.0.
> To: <sip:registrar at my.domain.com <mailto:sip%3Aregistrar at my.domain.com>>.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-2a02.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f618-29816 at 79.my.server.IP1.
> Max-Forwards: 70.
> Content-Length: 30.
> User-Agent: kamailio (4.2.0-dev7 (x86_64/linux)).
> Contact: registrar at my.domain.com 
> <mailto:registrar at my.domain.com>;msilo=yes.
> Content-Type: text/plain.
> .
> *** User registrar is offline!
>
> T 2014/07/17 21:11:00.359495 79.my.server.IP1:5060 -> 
> 79.my.server.IP1:58487 [AP]
> SIP/2.0 202 ACCEPTED.
> Via: SIP/2.0/TCP 
> 79.my.server.IP1;branch=z9hG4bK24f7.237c32d3000000000000000000000000.0;rport=58487.
> To: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=83a51ef5beb3f269619e74eb008b8b4e.a9f2.
> From: <sip:registrar at my.domain.com 
> <mailto:sip%3Aregistrar at my.domain.com>>;tag=416b6f80e891b334140ffeafcc1fa032-a22d.
> CSeq: 10 MESSAGE.
> Call-ID: 6807412f0f15f618-29809 at 79.my.server.IP1.
> Server: kamailio (4.2.0-dev7 (x86_64/linux)).
> Content-Length: 0.
> .
>
>
>
>
>
>
> On Thu, Jul 17, 2014 at 3:35 PM, Peter Villeneuve <petervnv1 at gmail.com 
> <mailto:petervnv1 at gmail.com>> wrote:
>
>     Thanks for helping out Hugh (and obviously Daniel)
>
>     I have made some progress by adding the modparam ("msilo",
>     "outbound_proxy", "sip:my.domain.com:5061;transport=tls").
>     Now indeed the stored message gets delivered when a UAC registers.
>
>     But I just noticed that it was also filling up msilo db with "user
>     xxx is offline!" messages, instead of sending that msg to the
>     initial UAC sending the msg.
>     This likely means I'm doing something wrong with the routing, as
>     it feels like it's in an endless loop. I think Daniel earlier
>     suggested adding if(src_ip != myself) t_on_failure("FAIL_MESSAGE")
>     to another poster that was having trouble with the exact same
>     routing config, but I'm not sure exactly where to insert it.
>
>     Can someone experienced with the routing syntax point out my -
>     likely obvious - mistake?
>
>     Cheers,
>     Peter
>
>
>     On Thu, Jul 17, 2014 at 3:11 PM, Waite, Hugh
>     <hugh.waite at acision.com <mailto:hugh.waite at acision.com>> wrote:
>
>         Hi,
>
>         We did have a working msilo implementation a while back, but
>         we don’t use it any more, so I can only look back at the
>         config files (which are a lot more complicated than yours).
>
>         We added the a modparam *modparam("msilo", "outbound_proxy",
>         "sip:MY_REAL_IP:MY_SIP_PORT;transport=tcp")*
>
>         which will make it arrive on the local machine on the given
>         socket (instead of localhost) to be processed, but that
>         probably isn’t your problem.
>
>         Is it possible that Kamailio is trying to establish a new
>         connection, instead of reusing the existing connection to the
>         client? That would be visible as TCP SYNs in a trace and would
>         cause a 408 after the timeout. We are using a separate
>         outbound enabled edge proxy so this isn’t a problem for us.
>
>         Regards,
>
>         Hugh
>
>         *From:*sr-users-bounces at lists.sip-router.org
>         <mailto:sr-users-bounces at lists.sip-router.org>
>         [mailto:sr-users-bounces at lists.sip-router.org
>         <mailto:sr-users-bounces at lists.sip-router.org>] *On Behalf Of
>         *Peter Villeneuve
>         *Sent:* 17 July 2014 13:10
>         *To:* Daniel-Constantin Mierla; Kamailio (SER) - Users Mailing
>         List
>         *Subject:* Re: [SR-Users] Msilo not delivering message (status
>         408)
>
>         I guess no one really knows why it isn't working either.
>
>         The only option I have left seems to be to try and update to
>         the 4.2 nightly and hope that whatever's wrong is a bug with
>         4.1.4 and not a simple mistake in my routing syntax or logic.
>
>         Daniel, is 4.2 nightly debian package stable enough for a
>         production system? Would you recommend I upgrade?
>
>         Thanks
>
>         On Wed, Jul 16, 2014 at 9:37 PM, Peter Villeneuve
>         <petervnv1 at gmail.com <mailto:petervnv1 at gmail.com>> wrote:
>
>         Can anyone help please? I was supposed to have this server up
>         and running hours ago and I can't think of anything to do next
>         to help debug this.
>
>         Thanks
>
>         On Wed, Jul 16, 2014 at 7:01 PM, Peter Villeneuve
>         <petervnv1 at gmail.com <mailto:petervnv1 at gmail.com>> wrote:
>
>         I removed the localhost listeners on TCP and UDP, and, as I
>         suspected, Kamailio doesn't seem to like that.
>
>         Why isn't kamailio sending the message back through the TLS
>         socket?
>
>         NOTICE: <script>: -------------------------MESSAGE PROCESSING: dumping offline messages
>
>         ERROR: tm [ut.h:343]: uri2dst2(): no corresponding socket for af 2
>
>         ERROR: tm [uac.c:266]: t_uac_prepare(): t_uac: no socket found
>
>         On Wed, Jul 16, 2014 at 4:44 PM, Peter Villeneuve
>         <petervnv1 at gmail.com <mailto:petervnv1 at gmail.com>> wrote:
>
>         And here's the full routing block. I copied it from someone
>         else on the list that was troubleshooting msilo a while back.
>
>         Also, I can confirm the message never gets delivered because
>         it remains in msilo DB and kamailio logs shows it trying and
>         trying.
>
>         ####### Routing Logic ########
>
>>
>         On Wed, Jul 16, 2014 at 4:38 PM, Peter Villeneuve
>         <petervnv1 at gmail.com <mailto:petervnv1 at gmail.com>> wrote:
>
>         Thanks for your help Daniel.
>
>         OK I ngrepped port 5060 and indeed the message tries to get
>         delivered. However it never arrives at the client (1010 in
>         this case).
>
>         I have added localhost listeners for UDP and TCP, even though
>         all clients register through TLS only (could this be the root
>         of the problem?). I added localhost listeners because I was
>         getting the no socket found error message.
>
>         Listening on
>
>          udp: 127.0.0.1:5080 <http://127.0.0.1:5080>
>
>          tcp: 127.0.0.1:5060 <http://127.0.0.1:5060>
>
>          tls: 79.my.server.IP1:5061
>
>         Aliases:
>
>          tcp: localhost:5060
>
>          udp: localhost:5080
>
>                    *: my.domain.com:*
>
>         U 2014/07/16 15:29:14.904285 127.0.0.1:5080
>         <http://127.0.0.1:5080> -> 79.my.server.IP1:5060
>
>         MESSAGE sip:1010 at my.domain.com
>         <mailto:sip%3A1010 at my.domain.com> SIP/2.0.
>
>         Via: SIP/2.0/UDP
>         127.0.0.1:5080;branch=z9hG4bKcde3.542219f4000000000000000000000000.0.
>
>         To: <sip:1010 at my.domain.com <mailto:sip%3A1010 at my.domain.com>>.
>
>         From: <sip:1000 at my.domain.com
>         <mailto:sip%3A1000 at my.domain.com>>;tag=def4124455da8a0b8e97eafabd028e26-2c30.
>
>         CSeq: 10 MESSAGE.
>
>         Call-ID: 16b126996f51d89c-12460 at 127.0.0.1
>         <mailto:16b126996f51d89c-12460 at 127.0.0.1>.
>
>         Max-Forwards: 70.
>
>         Content-Length: 58.
>
>         User-Agent: kamailio (4.1.4 (x86_64/linux)).
>
>         Date: Wed, 16 Jul 2014 15:22:31 GMT.
>
>         Content-Type: text/plain.
>
>         .
>
>         [Offline message - Wed Jul 16 15:22:31 2014] Test 1,2,3
>
>         On Wed, Jul 16, 2014 at 8:58 AM, Daniel-Constantin Mierla
>         <miconda at gmail.com <mailto:miconda at gmail.com>> wrote:
>
>         Hello,
>
>         can you watch the sip traffic on the network to see if the sip
>         messages is sent out? You can use ngrep, like:
>
>         ngrep -d any -qt -W byline "sip" port 5060
>
>         Cheers,
>         Daniel
>
>         On 14/07/14 19:56, Peter Villeneuve wrote:
>
>             Hi,
>
>             This is most likely a stupid mistake on my route config,
>             but msilo correctly stores messages for offline users, but
>             when they come back online, the message never arrives.
>
>             Looking through the debug logs indeed there is an error,
>             with status 408, which suggests kamaiio can't find a route
>             to the user that just logged. Before I spend hours looking
>             through all the routing blocks, perhaps someone more
>             exprienced in kamailio can see the problem right away and
>             offer a solution?
>
>             Thanks
>
>             DEBUG: msilo [msilo.c:1148]: m_dump(): msg [1-12] for:
>             sip:1010 at my.domain.com <mailto:sip%3A1010 at my.domain.com>
>
>             DEBUG: <core> [io_wait.h:617]: io_watch_del(): DBG:
>             io_watch_del (0x8e3040, 9, -1, 0x10) fd_no=2 called
>
>             DEBUG: <core> [tcp_read.c:1437]: release_tcpconn():
>             releasing con 0x7f61ced1b1b0, state 1, fd=9, id=1
>
>              DEBUG: <core> [tcp_read.c:1438]: release_tcpconn():
>              extra_data 0x7f61ced1c4f8
>
>             DEBUG: <core> [tcp_main.c:3385]: handle_tcp_child():
>             handle_tcp_child: reader response= 7f61ced1b1b0, 1 from 0
>
>             DEBUG: <core> [io_wait.h:390]: io_watch_add(): DBG:
>             io_watch_add(0x89ec40, 26, 2, 0x7f61ced1b1b0), fd_no=21
>
>             DEBUG: <core> [tcp_main.c:3515]: handle_tcp_child():
>             handle_tcp_child: CONN_RELEASE  0x7f61ced1b1b0 refcnt= 1
>
>             DEBUG: tm [t_reply.c:1304]: t_should_relay_response():
>             ->>>>>>>>> T_code=0, new_code=408
>
>             DEBUG: tm [t_reply.c:2086]: local_reply(): DEBUG:
>             local_reply: branch=0, save=0, winner=0
>
>             DEBUG: tm [t_reply.c:2123]: local_reply(): DEBUG: local
>             transaction completed
>
>             DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal():
>             DBG: trans=0x7f61ced1d868, callback type 1024, id 0 entered
>
>             DEBUG: msilo [msilo.c:1317]: m_tm_callback(): *completed
>             with status 408* [mid: 140058058335472/13]
>
>             DEBUG: msilo [msilo.c:1325]: m_tm_callback(): message <13>
>             was not sent successfully
>
>             DEBUG: msilo [ms_msg_list.c:236]: msg_list_set_flag():
>             mid:13 fl:8
>
>             DEBUG: tm [t_reply.c:1304]: t_should_relay_response():
>             ->>>>>>>>> T_code=0, new_code=408
>
>             DEBUG: tm [t_reply.c:2086]: local_reply(): DEBUG:
>             local_reply: branch=0, save=0, winner=0
>
>             DEBUG: tm [t_reply.c:2123]: local_reply(): DEBUG: local
>             transaction completed
>
>             DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal():
>             DBG: trans=0x7f61ced5f098, callback type 1024, id 0 entered
>
>             DEBUG: msilo [msilo.c:1317]: m_tm_callback(): completed
>             with status 408 [mid: 140058058329184/12]
>
>             DEBUG: msilo [msilo.c:1325]: m_tm_callback(): message <12>
>             was not sent successfully
>
>             DEBUG: msilo [ms_msg_list.c:236]: msg_list_set_flag():
>             mid:12 fl:8
>
>             _______________________________________________
>
>             SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>
>             sr-users at lists.sip-router.org  <mailto:sr-users at lists.sip-router.org>
>
>             http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
>
>
>         -- 
>
>         Daniel-Constantin Mierla -http://www.asipto.com
>
>         http://twitter.com/#!/miconda  <http://twitter.com/#%21/miconda>  -http://www.linkedin.com/in/miconda
>
>
>         _______________________________________________
>         SIP Express Router (SER) and Kamailio (OpenSER) - sr-users
>         mailing list
>         sr-users at lists.sip-router.org
>         <mailto:sr-users at lists.sip-router.org>
>         http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
>         ------------------------------------------------------------------------
>
>         This e-mail and any attachment is for authorised use by the
>         intended recipient(s) only. It may contain proprietary
>         material, confidential information and/or be subject to legal
>         privilege. It should not be copied, disclosed to, retained or
>         used by, any other party. If you are not an intended recipient
>         then please promptly delete this e-mail and any attachment and
>         all copies and inform the sender. Thank you for understanding.
>
>
>         _______________________________________________
>         SIP Express Router (SER) and Kamailio (OpenSER) - sr-users
>         mailing list
>         sr-users at lists.sip-router.org
>         <mailto:sr-users at lists.sip-router.org>
>         http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
>
>
>
>
> _______________________________________________
> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
> sr-users at lists.sip-router.org
> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-- 
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20140718/28e73ca5/attachment.html>


More information about the sr-users mailing list