From klaus.feichtinger@gmx.net Mon Jun 14 15:01:52 2010
From: Klaus Feichtinger <klaus.feichtinger@gmx.net>
To: sr-dev@lists.kamailio.org
Subject: Re: [sr-dev] Dialog module: "CRITICAL bogus event 6 in state 2
Date: Mon, 14 Jun 2010 15:01:45 +0200
Message-ID: <20100614130145.51840@gmx.net>
In-Reply-To: <4C114A14.8060904@gmx.net>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="===============0939814068=="

--===============0939814068==
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: quoted-printable

Hello Ovidiu,

I've been testing reproducablility of the described error and found that it i=
s reproducable in "standard" mode onyl. This should mean: forked application =
with child processes. As soon as I start the application even as non-forked o=
r with only one child (children=3D1), the error was not reproducable until no=
w. I've fastened reproduction with SIPp the call generating tool and in stand=
ard mode this error messages are visible after about 1-2 minutes (the call ra=
te is one call per second with a pause of 1500ms between ACK and the followin=
g BYE).

Under these test circumstances no subscription for presence or dialog state w=
as active; it was tested on a "isolated" server where no other UAs were activ=
e; only SIPp and one other UA were active.

I found that this problem is UserAgent-independent, too. Do you have an idea =
how to find out any more details about this problem?

regards,

Klaus Feichtinger

> Datum: Thu, 10 Jun 2010 22:24:52 +0200
> Von: Klaus Feichtinger <klaus.feichtinger(a)gmx.net>
> An: Ovidiu Sas <osas(a)voipembedded.com>
> CC: sr-dev(a)lists.sip-router.org
> Betreff: Re: [sr-dev] Dialog module: "CRITICAL bogus event 6 in state 2

> Hello,
>=20
> according tcpdump-traces on the linux machine and log entries in syslog
> (see below) the 200 OK passed the SIP Router (this means - the call was
> accounted and afterwards the bogus event was noted):
>=20
> Jun 10 18:29:09 debian /usr/sbin/kamailio[20026]: INFO: <script>:
> ---xlog: a call with sip:116202(a)10.16.10.99 is coming in
> Jun 10 18:29:12 debian /usr/sbin/kamailio[20027]: NOTICE: acc
> [acc.c:275]: ACC: transaction answered:
> timestamp=3D1276208952;method=3DINVITE;from_tag=3D3120233282-36939680-12761=
87634579;to_tag=3D3338003860-56654088-1276187447718;call_id=3D741466613-36939=
680-1276187634579(a)10.16.10.152;code=3D200;reason=3DOK;src_user=3D116201;src=
_domain=3D10.16.10.99;dst_user=3D116202;dst_domain=3D10.16.10.90;src_ip=3D10.=
16.10.152
> Jun 10 18:29:12 debian /usr/sbin/kamailio[20025]: CRITICAL: dialog
> [dlg_hash.c:591]: bogus event 6 in state 2 for dlg 0xa7eb3ea8
> [2285:1225504260] with clid
> '741466613-36939680-1276187634579(a)10.16.10.152' and tags
> '3120233282-36939680-1276187634579' ''
>=20
>=20
> However, this is not the one and only event / state combination I found
> in syslog. There is also an entry with event 6 in state 1 present:
>=20
> Jun 10 19:35:49 debian /usr/sbin/kamailio[20026]: INFO: <script>:
> ---xlog: a call with sip:116002(a)10.16.10.99 is coming in
> Jun 10 19:35:50 debian /usr/sbin/kamailio[20027]: NOTICE: acc
> [acc.c:275]: ACC: transaction answered:
> timestamp=3D1276212950;method=3DINVITE;from_tag=3D3805046041-37017968-12761=
91635112;to_tag=3Dbefc3f7326747dei0;call_id=3D789390150-37017968-127619163511=
2(a)10.16.10.152;code=3D200;reason=3DOK;src_user=3D116201;src_domain=3D10.16.=
10.99;dst_user=3D116002;dst_domain=3D10.16.10.205;src_ip=3D10.16.10.152
> Jun 10 19:35:50 debian /usr/sbin/kamailio[20026]: CRITICAL: dialog
> [dlg_hash.c:591]: bogus event 6 in state 1 for dlg 0xa7e979b8
> [1648:1273002173] with clid
> '789390150-37017968-1276191635112(a)10.16.10.152' and tags
> '3805046041-37017968-1276191635112' ''
>=20
> But tomorrow I will test the setting - as recommended by you - to reduce
> kamailio to a single worker and check if the problem will keep
> repreduceable.
>=20
> Regards,
>=20
> Klaus Feichtinger
>=20
> > Bogus event 6 in state 2 means ACK received in early state.
> > This is a little bit bizarre, because it seems that the dialog did not
> > see the 200ok passing by.
> > Try to use a single worker (children=3D1) and see if you can reproduce
> > the problem.
> > Also, check that the 200ok is really going through the proxy.
> >
> > Regards,
> > Ovidiu Sas
> >
> > On Thu, Jun 10, 2010 at 6:44 AM, Klaus Feichtinger
> > <klaus.feichtinger(a)gmx.net> wrote:
> >  =20
> >> Hello list,
> >>
> >> under special circumstances I have a problem with the DIALOG module of
> SIP-Router/Kamailio version 3.0.2. The dialog module is used in combination
> with presence, presence_xml, pua, pua_usrloc and pua_dialoginfo modules +
> db_mysql modules. The db_mode is set to "write_through", because of
> redundancy requirements.
> >>
> >> From my point of view this problem has something to do with timing in
> general. E.g. a so called "data call" has a duration of about 50 ms only;
> INVITE....BYE). That problem occurs on this short calls only. Because of the
> problems in the dialog state machine, NOTIFY messages are incorrect. Even
> when the call is already finished, the NOTIFY message includes the state
> "confirmed" and causes a wrong status indication....
> >>
> >> The detailed error message can be seen here:
> >> "Jun  9 16:00:39 debian /usr/sbin/kamailio[14992]: CRITICAL: dialog
> [dlg_hash.c:591]: bogus event 6 in state 2 for dlg [dialog-ID] with clid
> [Call-ID] and tags '1299370188-28358304-1276092068837' ''"
> >>
> >>
> >> I found in old mails of the developer list another error that looked
> nearly the same, but it differed in the event and state of the dialog state
> machine (the thread can be found under the link
> http://www.mail-archive.com/devel(a)lists.kamailio.org/msg03234.html). That=
 bug should - according the
> information that I've found in the list - be solved. Therefore I will ask
> you: is the error as displayed above another well known error / bug, which
> (maybe) should already be solved? Is it a new bug?
> >>
> >> Thanks for any information.
> >>
> >> regards,
> >>
> >> Klaus Feichtinger
> >>
> >> _______________________________________________
> >> sr-dev mailing list
> >> sr-dev(a)lists.sip-router.org
> >> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
> >>
> >>    =20
> >  =20
>=20
>=20
> _______________________________________________
> sr-dev mailing list
> sr-dev(a)lists.sip-router.org
> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev

--=20
GMX DSL: Internet-, Telefon- und Handy-Flat ab 19,99 EUR/mtl. =20
Bis zu 150 EUR Startguthaben inklusive! http://portal.gmx.net/de/go/dsl


--===============0939814068==--