[Users] CANCEL problem

[Michael Ulitskiy]

Hello,

I found something that I believe is problem with CANCEL processing in tm
module. I'm using openser 0.10.x today's cvs.
If openser forwards an INVITE and then it receives CANCEL before
it receives a provisional reply from INVITE recipient, it never forwards CANCEL
to its destination.
CANCEL is handled the same way as INVITE and I'm sure it hits t_relay().
Here's relevant part of the config:

xlog("L_INFO","$rm: cseq=$cs: ruri=$ru received from $si:$sp\n");
if (allow_trusted()) {
           if (!lookup("location")) {
                   xlog("L_INFO","$rm: cseq=$cs: $ru: not found\n");
                   sl_send_reply("404","Not found");
                   exit;
           }
           xlog("L_INFO","$rm: cseq=$cs: lookup: $ru flags: $mF\n");;
           route(1);
           exit;
}
if (uri==myself) {
           rewritehost("192.168.80.26");
           route(1);
}

route[1]
{
 xlog("L_INFO","$rm: cseq=$cs: $ru: RELAYING to $du (flags: $mF)...\n");
        if (!t_relay()) {
                xlog("L_NOTICE","$rm: cseq=$cs: ERROR: t_relay failed\n");;
                if (!is_method("ACK")) {
                   sl_reply_error();
                }
        };
}


Here's ser log:
 0(1015) INVITE: cseq=102: ruri=sip:xyz_100_1_st2 at 192.168.83.61 received from 192.168.80.26:5060
 0(1015) INVITE: cseq=102: lookup: sip:xyz_100_1_st2 at 192.168.0.249:5060 flags: 00000040
 0(1015) INVITE: cseq=102: sip:xyz_100_1_st2 at 192.168.0.249:5060: RELAYING to sip:192.168.76.250:1058 (flags: 00000040)
 0(1015) CANCEL: cseq=102: ruri=sip:xyz_100_1_st2 at 192.168.83.61 received from 192.168.80.26:5060
 0(1015) CANCEL: cseq=102: lookup: sip:xyz_100_1_st2 at 192.168.0.249:5060 flags: 00000040
 0(1015) CANCEL: cseq=102: sip:xyz_100_1_st2 at 192.168.0.249:5060: RELAYING to sip:192.168.76.250:1058 (flags: 00000040)
 0(1015) ACK: cseq=102: ruri=sip:xyz_100_1_st2 at 192.168.83.61 received from 192.168.80.26:5060
 0(1015) <null>: cseq=102: onreply_route_log: received: 100 Trying from 192.168.76.250:1058
 0(1015) <null>: cseq=102: onreply_route_log: received: 180 Ringing from 192.168.76.250:1058

I've replaced ip addresses with 192.168.x.x, but recipient is behind NAT. 
As you can see according to this log CANCEL is getting relayed, but ngrep actually shows that it's not sent and
invited client sends "Trying", then "Ringing".
It happens only if INVITE is already forwarded and CANCEL is received before any provisional reply.
If CANCEL happens after openser received "100 Trying", everything works fine and call is cancelled.
It looks to me as a bug or some kind of race.
Any clues?

Thanks,
Michael