From klaus.feichtinger@gmx.net Thu Jun 10 22:24:59 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: Thu, 10 Jun 2010 22:24:52 +0200
Message-ID: <4C114A14.8060904@gmx.net>
In-Reply-To: <AANLkTimmnqIvVb4DqpX-2Ll87j0-Ngwv2cIyPN8WqQl5@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="===============1760587319=="

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

Hello,

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):

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-1276187=
634579;to_tag=3D3338003860-56654088-1276187447718;call_id=3D741466613-3693968=
0-1276187634579(a)10.16.10.152;code=3D200;reason=3DOK;src_user=3D116201;src_d=
omain=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' ''


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:

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-1276191=
635112;to_tag=3Dbefc3f7326747dei0;call_id=3D789390150-37017968-1276191635112(=
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' ''

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.

Regards,

Klaus Feichtinger

> 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_mysq=
l modules. The db_mode is set to "write_through", because of redundancy requi=
rements.
>>
>> From my point of view this problem has something to do with timing in gene=
ral. 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 problem=
s in the dialog state machine, NOTIFY messages are incorrect. Even when the c=
all is already finished, the NOTIFY message includes the state "confirmed" an=
d 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_h=
ash.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 nearl=
y the same, but it differed in the event and state of the dialog state machin=
e (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 informati=
on 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



--===============1760587319==--