#657 ACC not writing some BYE's to DB

[Daniel Zanutti]

Hi

Im having a strange issue on ACC module. ACC is configured with MySQL database, on START/STOP billing model.

After sending around 100 calls, i could find 1 call that BYE wasn't stored on DB. When i look at opensips log(at syslog), the INVITE was sucessfuly stored and reported by ACC, BYE was received but not written to DB.

Doing stress call test, this problem happens on 1-2% of all answered calls.

See log below:

May 13 10:50:38 /sbin/opensips[23017]: Calling: sip:22229999@fs02.test.com:5060 - (gw=11) - Tent: 1 - Prio: 1 - Route: 55389 - User: 1000@s05.test.com (46.182.109.28) - 11-1819@46.182.109.28
May 13 10:50:38 /sbin/opensips[23035]: incoming reply OK - 200 - ru=sip:22229999@s05.test.com:5060 - 11-1819@46.182.109.28 - ip:199.233.233.36
May 13 10:50:38 /sbin/opensips[23035]: ACC: transaction answered: timestamp=1368453038;method=INVITE;from_tag=1819SIPpTag0011;to_tag=3KSyHgHyXa8cK;call_id=11-1819@46.182.109.28;code=200;reason=OK
May 13 10:50:38 /sbin/opensips[23021]: ACK - sip:22229999@199.233.233.36:5060;transport=udp - 1000@s05.test.com (46.182.109.28) - 11-1819@46.182.109.28
May 13 10:50:57 /sbin/opensips[23024]: BYE - ACC - Gravando Log - sip:46.182.109.24;lr;ftag=1819SIPpTag0011;did=91d.a6e3ea66 - 11-1819@46.182.109.28
May 13 10:50:57 /sbin/opensips[23024]: BYE - sip:46.182.109.24;lr;ftag=1819SIPpTag0011;did=91d.a6e3ea66 - 22229999@s05.test.com (199.233.233.36) - 11-1819@46.182.109.28
May 13 10:50:57 /sbin/opensips[23017]: BYE - ACC - Gravando Log - sip:22229999@199.233.233.36:5060;transport=udp - 11-1819@46.182.109.28
May 13 10:50:57 /sbin/opensips[23017]: BYE - sip:22229999@199.233.233.36:5060;transport=udp - 1000@s05.test.com (46.182.109.28) - 11-1819@46.182.109.28

I'm not sure if this is related to server load, but I think that opensips should at least generate an error and I don't see any. The problem can be reproduced on any environment.

My temporary solution was to force an INSERT into DB, when BYE is received =(

Thanks

[Bogdan-Andrei Iancu]

Hi Daniel,

So you do accounting in parallel to DB and to SYSLOG (via different acc flags) and you can see the STOP record in SYSLOG, but not in DB ?

Regards,
Bogdan

[Daniel Zanutti]

Yes and no.

On my Loose route i have this(only relevant part):
if (is_method("BYE"))
{
xlog("L_NOTICE", "BYE - ACC - Gravando Log - $ru - $ci");
setflag(ACC_LOG_FLAG); # do accounting
setflag(ACC_DB_FLAG);
}

So on 99% of calls, i can see my syslog message "BYE - ACC - Gravando Log - ..." and also log from ACC module "ACC: transaction answered: timestamp=1369140333;method=INVITE...". Checking the database, BYE was written sucessfuly there too... On this case, everything works fine.

On other 1% calls, i just see my syslog(xlog) message "BYE - ACC - Gravando Log - ..." but I don't see a syslog message from ACC neither BYE was written to DB.

I believe that BYE message sucesfully was related to the dialog because it entered loose route and the call was hangup on both sides... There is no dialog timeout log so this is why I believe that this is bug.

I can reproduce the problem and give access to a system with the problem.

What should i do?

Thanks

[Bogdan-Andrei Iancu]

Hi Daniel,

Maybe the BYE is not logged because it does not have a 2xx reply, but a negative reply (the acc flags logs only successful transactions).

To test that, for BYE also set the failed_transaction_flag (see http://www.opensips.org/html/docs/modules/1.9.x/acc.html#id292830).

Regards,
Bogdan

[Daniel Zanutti]

Hi Bogdan

Actually the 2xx reply was received, check log below:

incoming reply OK - 200 - ru=sip:22229999@s05.test.com:5060 - 11-1819@46.182.109.28 - ip:199.233.233.36

ACC: transaction answered: timestamp=1368453038;method=INVITE;from_tag=1819SIPpTag0011;to_tag=3KSyHgHyXa8cK;call_id=11-1819@46.182.109.28;code=200;reason=OK

I really believe that this is a bug... But I can test with this parameter "failed_transaction_flag" but takes some time to find the call with the problem...
Should I do the test?

Thanks

[Bogdan-Andrei Iancu]

That's the 200 OK for the INVITE req. I was talking about the 200 OK for the BYE request.

Please configure the failed_transaction_flag and re-test.

Regards,
Bogdan

[Daniel Zanutti]

Ok, got it!

Will teste and report asap.

Thanks

[Daniel Zanutti]

I sent 10k calls, all were billed succesfully... Seems that this missing config "failed_transaction_flag" was the problem.

So without this config, accounting is done only after transaction is confirmed (REQUEST+200 OK+ACK)?

Thanks for all help.

[Bogdan-Andrei Iancu]

Probably one of the BYE gets a timeout or some negative reply and it was not accounted with that flag.

I will close this ticket.

Regards,
Bogdan