Re: [SR-Users] Failure route triggers a 500 internal server error - take 2

25 Mar 2011

      Hello,
Here goes the the tcpdump capturing the traffic on my kamailio server.
It is an incoming call to a internal user that sent a busy here.
Additionally I am also sending the capture of "the same" call without
arming the failure route.
I cannot quite understand why is the phone sending two busy here SIP
messages. Because the proxy already sent to it the ACK. Either way I
don't think that is the reason for the internal error. Hmmm ...
Curiously. sometimes the phone only sends one busy here .
*TCP Dump  - Call with failure route armed - internal error*
/14:29:44.809942 IP (tos 0x0, ttl 58, id 18259, offset 0, flags
    [none], proto UDP (17), length 865) 158.36.141.13.5060 >
    128.39.190.50.5060: SIP, length: 837
            INVITE sip:+4773411459@umb.no SIP/2.0
            Via: SIP/2.0/UDP 158.36.141.13:5060;branch=z9hG4bK29a6713c;rport
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            User-Agent: UNINETT PBX
            Max-Forwards: 70
            Date: Fri, 25 Mar 2011 13:30:16 GMT
            Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
    NOTIFY, INFO
            Supported: replaces
            Content-Type: application/sdp
            Content-Length: 266
v=0
            o=root 12328 12328 IN IP4 158.36.141.13
            s=session
            c=IN IP4 158.36.141.13
            t=0 0
            m=audio 20882 RTP/AVP 8 0 101
            a=rtpmap:8 PCMA/8000
            a=rtpmap:0 PCMU/8000
            a=rtpmap:101 telephone-event/8000
            a=fmtp:101 0-16
            a=silenceSupp:off - - - -
            a=ptime:20
            a=sendrecv
14:29:44.810897 IP (tos 0x10, ttl 64, id 8279, offset 0, flags
    [none], proto UDP (17), length 367) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 339
            SIP/2.0 100 trying
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Content-Length: 0
14:29:44.811020 IP (tos 0x10, ttl 64, id 53941, offset 0, flags
    [none], proto UDP (17), length 993) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 965
            INVITE sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Record-Route: sip:128.39.190.50;lr=on
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            User-Agent: UNINETT PBX
            Max-Forwards: 69
            Date: Fri, 25 Mar 2011 13:30:16 GMT
            Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
    NOTIFY, INFO
            Supported: replaces
            Content-Type: application/sdp
            Content-Length: 266
v=0
            o=root 12328 12328 IN IP4 158.36.141.13
            s=session
            c=IN IP4 158.36.141.13
            t=0 0
            m=audio 20882 RTP/AVP 8 0 101
            a=rtpmap:8 PCMA/8000
            a=rtpmap:0 PCMU/8000
            a=rtpmap:101 telephone-event/8000
            a=fmtp:101 0-16
            a=silenceSupp:off - - - -
            a=ptime:20
            a=sendrecv
14:29:45.127879 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 653) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 625
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:29:45.128427 IP (tos 0x10, ttl 64, id 8280, offset 0, flags
    [none], proto UDP (17), length 591) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 563
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:29:45.635458 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 653) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 625
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:29:45.636015 IP (tos 0x10, ttl 64, id 8281, offset 0, flags
    [none], proto UDP (17), length 591) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 563
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:29:46.113735 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 480) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 452
            SIP/2.0 486 Busy Here
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Content-Length: 0
14:29:46.113800 IP (tos 0x10, ttl 64, id 53942, offset 0, flags
    [none], proto UDP (17), length 392) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 364
            ACK sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            Max-Forwards: 69
            Content-Length: 0
14:29:46.114033 IP (tos 0x10, ttl 64, id 8282, offset 0, flags
    [none], proto UDP (17), length 419) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 391
            SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To:
    sip:+4773411459@umb.no;tag=b8aa993dfa373c22d82ad10d9797ba65-36b7
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Content-Length: 0
14:29:46.122671 IP (tos 0x0, ttl 58, id 18260, offset 0, flags
    [none], proto UDP (17), length 470) 158.36.141.13.5060 >
    128.39.190.50.5060: SIP, length: 442
            ACK sip:+4773411459@umb.no SIP/2.0
            Via: SIP/2.0/UDP 158.36.141.13:5060;branch=z9hG4bK29a6713c;rport
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To:
    sip:+4773411459@umb.no;tag=b8aa993dfa373c22d82ad10d9797ba65-36b7
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            User-Agent: UNINETT PBX
            Max-Forwards: 70
            Content-Length: 0
14:29:46.600448 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 480) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 452
            SIP/2.0 486 Busy Here
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK29a6713c;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Content-Length: 0
14:29:46.600832 IP (tos 0x10, ttl 64, id 53943, offset 0, flags
    [none], proto UDP (17), length 392) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 364
            ACK sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK9801.552576e3.0
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as0d1cd500
            To: sip:+4773411459@umb.no;tag=4tyj0j0ipp
            Call-ID:
    59863ad774b1df04381caf3700afb14f@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            Max-Forwards: 69
            Content-Length: 0
/
*TCP Dump  - Call WITHOUT failure route armed - NO internal error*
_
_
/14:27:30.623782 IP (tos 0x0, ttl 58, id 18257, offset 0, flags
    [none], proto UDP (17), length 865) 158.36.141.13.5060 >
    128.39.190.50.5060: SIP, length: 837
            INVITE sip:+4773411459@umb.no SIP/2.0
            Via: SIP/2.0/UDP 158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            User-Agent: UNINETT PBX
            Max-Forwards: 70
            Date: Fri, 25 Mar 2011 13:28:02 GMT
            Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
    NOTIFY, INFO
            Supported: replaces
            Content-Type: application/sdp
            Content-Length: 266
v=0
            o=root 12328 12328 IN IP4 158.36.141.13
            s=session
            c=IN IP4 158.36.141.13
            t=0 0
            m=audio 24026 RTP/AVP 8 0 101
            a=rtpmap:8 PCMA/8000
            a=rtpmap:0 PCMU/8000
            a=rtpmap:101 telephone-event/8000
            a=fmtp:101 0-16
            a=silenceSupp:off - - - -
            a=ptime:20
            a=sendrecv
14:27:30.623974 IP (tos 0x10, ttl 64, id 8275, offset 0, flags
    [none], proto UDP (17), length 367) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 339
            SIP/2.0 100 trying
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Content-Length: 0
14:27:30.624000 IP (tos 0x10, ttl 64, id 53938, offset 0, flags
    [none], proto UDP (17), length 993) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 965
            INVITE sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Record-Route: sip:128.39.190.50;lr=on
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            User-Agent: UNINETT PBX
            Max-Forwards: 69
            Date: Fri, 25 Mar 2011 13:28:02 GMT
            Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE,
    NOTIFY, INFO
            Supported: replaces
            Content-Type: application/sdp
            Content-Length: 266
v=0
            o=root 12328 12328 IN IP4 158.36.141.13
            s=session
            c=IN IP4 158.36.141.13
            t=0 0
            m=audio 24026 RTP/AVP 8 0 101
            a=rtpmap:8 PCMA/8000
            a=rtpmap:0 PCMU/8000
            a=rtpmap:101 telephone-event/8000
            a=fmtp:101 0-16
            a=silenceSupp:off - - - -
            a=ptime:20
            a=sendrecv
14:27:30.940271 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 653) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 625
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:27:30.940778 IP (tos 0x10, ttl 64, id 8276, offset 0, flags
    [none], proto UDP (17), length 591) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 563
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:27:31.445703 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 653) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 625
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:27:31.445745 IP (tos 0x10, ttl 64, id 8277, offset 0, flags
    [none], proto UDP (17), length 591) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 563
            SIP/2.0 180 Ringing
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            Record-Route: sip:128.39.190.50;lr=on
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY,
    SUBSCRIBE, PRACK, MESSAGE, INFO
            Allow-Events: talk, hold, refer, call-info
            Content-Length: 0
14:27:31.694001 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 480) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 452
            SIP/2.0 486 Busy Here
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Content-Length: 0
14:27:31.694049 IP (tos 0x10, ttl 64, id 53939, offset 0, flags
    [none], proto UDP (17), length 392) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 364
            ACK sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            Max-Forwards: 69
            Content-Length: 0
14:27:31.694071 IP (tos 0x10, ttl 64, id 8278, offset 0, flags
    [none], proto UDP (17), length 418) 128.39.190.50.5060 >
    158.36.141.13.5060: SIP, length: 390
            SIP/2.0 486 Busy Here
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Content-Length: 0
14:27:31.702736 IP (tos 0x0, ttl 58, id 18258, offset 0, flags
    [none], proto UDP (17), length 443) 158.36.141.13.5060 >
    128.39.190.50.5060: SIP, length: 415
            ACK sip:+4773411459@umb.no SIP/2.0
            Via: SIP/2.0/UDP 158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Contact: sip:+4794511652@158.36.141.13
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            User-Agent: UNINETT PBX
            Max-Forwards: 70
            Content-Length: 0
14:27:32.179966 IP (tos 0x0, ttl 57, id 0, offset 0, flags [DF],
    proto UDP (17), length 480) 158.38.58.37.5060 > 128.39.190.50.5060:
    SIP, length: 452
            SIP/2.0 486 Busy Here
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            Via: SIP/2.0/UDP
    158.36.141.13:5060;branch=z9hG4bK57f4bd24;rport=5060
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 INVITE
            Contact: sip:geirtu@158.38.58.37:5060;line=6281o655;flow-id=1
            Content-Length: 0
14:27:32.180001 IP (tos 0x10, ttl 64, id 53940, offset 0, flags
    [none], proto UDP (17), length 392) 128.39.190.50.5060 >
    158.38.58.37.5060: SIP, length: 364
            ACK sip:geirtu@158.38.58.37:5060;line=6281o655 SIP/2.0
            Via: SIP/2.0/UDP 128.39.190.50;branch=z9hG4bK570a.b69d7015.0
            From: "+4794511652"
    sip:+4794511652@test-tgw1.tlf.uninett.no;tag=as4e06afa7
            To: sip:+4773411459@umb.no;tag=mbfd224815
            Call-ID:
    48930218141f7d9463d82a747f3be037@test-tgw1.tlf.uninett.no
            CSeq: 102 ACK
            Max-Forwards: 69
            Content-Length: 0/
Cheers,
Miguel Baptista
On 25.03.2011 07:55, Daniel-Constantin Mierla wrote:
...
Hello,
can you send a ngrep trace of such case, from the initial invite to
the end of transaction? The debug messages you sent are only for the
received reply, but it seems that 500 is sent already and then is just
retransmitted, the SIP trace will help to clarify that.
Cheers,
Daniel
On 3/24/11 4:50 PM, Miguel Baptista wrote:
...
Hi all,
A couple of days ago I sent an identical email but because I wasn't a
member of this list I don't know if you got it or not. Additionally,
I would like to say that I have the same problem with kamailio 3.1.1.
This is very weird problem ..
I am using kamailio 3.1.2 (like I say the same is happening with
3.1.1) and I have an issue with failure route. Every-time kamailio
enters the failure route an internal error is triggered and kamailio
sends a  500 SIP error message:  /SIP/2.0 500 I'm terribly sorry,
server error occurred (1/TM)/.
Just for testing purpose I "downgraded" my failure route
configuration to a very simple one. But even so I am always getting
the same error and it doesn't matter if it is a busy, a cancel, a
moved temporarily...
If I don't arm the failure route I don't get any error.
Any idea what might be wrong? Is this a bug?
This is the relevant part of my configuration :
*/route[RELAY] {/*
/        if (is_method("INVITE")) {/
/                t_on_failure("FAILTWO");/
/        }/
/        if (!t_relay()) {/
/                sl_reply_error();/
/        }/
/        exit;/
/}/

/*failure_route[FAILTWO] {*
        xlog("L_INFO", "FAILUREFROMEXTERNAL: Entered\n");

        if (t_check_status("302")) {
                xlog("L_INFO", "FAILUREFROMEXTERNAL: 302
detected\n");
        } else {
                xlog("L_INFO", "FAILUREFROMEXTERNAL: other
detected\n");
        }

 xlog("L_INFO", "FAILUREFROMEXTERNAL: Exiting\n");/
}

Here is the Debug output from a busy message got by kamailio and the
internal error generated:
/Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 860) called from <core>:
receive.c: receive_msg(120)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 860) returns address
0x837e300 frag. 0x837e2e8 (size=860) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:640]: SIP Reply  (status):
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:642]:  version: <SIP/2.0>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:644]:  status:  <486>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:646]:  reason:  <Busy Here>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f29c frag. 0x837f284 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 116) called from <core>:
parser/msg_parser.c: get_hdr_field(130)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 116) returns address
0x837e68c frag. 0x837e674 (size=116) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f2ec frag. 0x837f2d4 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK54f1.2f69b061.0>; state=16
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_via.c:2300]: end of header reached, state=5
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:515]: parse_headers: Via found, flags=2
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:517]: parse_headers: this is the first via
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [receive.c:145]: After parse_msg...
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:1081]: DEBUG: t_check_msg: msg id=19 global id=18 T
start=0xffffffff
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f33c frag. 0x837f324 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 116) called from <core>:
parser/msg_parser.c: get_hdr_field(130)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 116) returns address
0x837e820 frag. 0x837e808 (size=224) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f38c frag. 0x837f374 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK1f04fb19>; state=6
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f6e0 frag. 0x837f6c8 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_via.c:1287]: Found param type 235, <rport> =
<5060>; state=16
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_via.c:2300]: end of header reached, state=5
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:515]: parse_headers: Via found, flags=22
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:528]: parse_headers: this is the second via
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f730 frag. 0x837f718 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f820 frag. 0x837f808 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 224) called from <core>:
parser/msg_parser.c: get_hdr_field(170)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 224) returns address
0x837e9c8 frag. 0x837e9b0 (size=224) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 24) called from <core>:
parser/parse_to.c: parse_to_param(283)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 24) returns address
0x837e930 frag. 0x837e918 (size=24) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_to.c:174]: DEBUG: add_param: tag=i76l2xu48i
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/parse_to.c:803]: end of header reached, state=29
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:187]: DEBUG: get_hdr_field: <To> [41];
uri=[sip:+4773411459@umb.no] 
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:189]: DEBUG: to body
[sip:+4773411459@umb.no]
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f780 frag. 0x837f768 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837f7d0 frag. 0x837f7b8 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 24) called from <core>:
parser/msg_parser.c: get_hdr_field(149)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 24) returns address
0x837eb78 frag. 0x837eb60 (size=24) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [parser/msg_parser.c:167]: get_hdr_field: cseq <CSeq>: <102>
<INVITE>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 8005 label
369858290 branch 0
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched
(T=0xb59ec41c)!
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:1150]: DEBUG: t_check_msg: msg id=19 global id=19 T
end=0xb59ec41c
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:2014]: DEBUG: reply_received: org. status uas=180,
uac[0]=180 local=0 is_invite=1)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0xb5881000, 1010) called from tm:
t_msgbuilder.c: build_local_reparse(368)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0xb5881000, 1012) returns address
0xb59ed5a0 frag. 0xb59ed588 (size=1012) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0xb5881000, 0xb59ed5a0), called from
tm: t_reply.c: reply_received(2064)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0xb59ed588 alloc'ed from
tm: t_msgbuilder.c: build_local_reparse(368)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:1129]: ->>>>>>>>> T_code=180, new_code=486
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 43) called from tm:
t_reply.c: fake_req(854)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 44) returns address
0x837f8c0 frag. 0x837f8a8 (size=44) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: INFO:
<script>: FAILUREFROMEXTERNAL: Entered
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:1081]: DEBUG: t_check_msg: msg id=16 global id=16 T
start=0xb59ec41c
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_lookup.c:1153]: DEBUG: t_check_msg: T already found!
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [tm.c:967]: DEBUG:t_check_status: checked status is <486>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: INFO:
<script>: FAILUREFROMEXTERNAL: other detected
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: INFO:
<script>: FAILUREFROMEXTERNAL: Exiting
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f8c0), called from tm:
t_reply.c: free_faked_req(885)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837f8a8 alloc'ed from
tm: t_reply.c: fake_req(854)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [msg_translator.c:204]: check_via_address(158.36.141.13,
158.36.141.13, 0)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 12) called from <core>:
msg_translator.c: rport_builder(390)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 12) returns address
0x837f008 frag. 0x837eff0 (size=12) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 392) called from <core>:
msg_translator.c: build_res_buf_from_sip_req(2032)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 392) returns address
0x838007c frag. 0x8380064 (size=564) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f008), called from
<core>: msg_translator.c: build_res_buf_from_sip_req(2192)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837eff0 alloc'ed from
<core>: msg_translator.c: rport_builder(390)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0xb5881000, 0xb59ed29c), called from
<core>: mem/shm_mem.c: sh_realloc(82)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0xb59ed284 alloc'ed from
<core>: mem/shm_mem.c: sh_realloc(83)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:366]: qm_malloc(0xb5881000, 391) called from <core>:
mem/shm_mem.c: sh_realloc(83)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:406]: qm_malloc(0xb5881000, 392) returns address
0xb59ea720 frag. 0xb59ea708 (size=500) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:1470]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:659]: DEBUG: reply sent out. buf=0x838007c: SIP/2.0 500
I'm terr..., shmem=0xb59ea720: SIP/2.0 500 I'm terr
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x838007c), called from tm:
t_reply.c: _reply_light(668)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 860) called from <core>:
receive.c: receive_msg(120)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x8380064 alloc'ed from
<core>: msg_translator.c: build_res_buf_from_sip_req(2032)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 860) returns address
0x837e300 frag. 0x837e2e8 (size=860) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:669]: DEBUG: _reply_light: finished
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:630]: SIP Request:
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:1631]: DEBUG: relay_reply: branch=0, save=0, relay=-1
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:632]:  method:  <ACK>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
tm [t_reply.c:1470]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:634]:  uri:     <sip:+4773411459@umb.no>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:636]:  version: <SIP/2.0>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837ed00 frag. 0x837ece8 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 116) called from <core>:
parser/msg_parser.c: get_hdr_field(130)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 116) returns address
0x837e68c frag. 0x837e674 (size=116) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [usr_avp.c:646]: DEBUG:destroy_avp_list: destroying list (nil)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: DEBUG:
<core> [receive.c:289]: receive_msg: cleaning up
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837ecb0 frag. 0x837ec98 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f2ec), called from
<core>: parser/parse_via.c: free_via_param_list(2387)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/parse_via.c:1287]: Found param type 232, <branch> =
<z9hG4bK1f04fb19>; state=6
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837f2d4 alloc'ed from
<core>: parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 32) called from <core>:
parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837e68c), called from
<core>: parser/parse_via.c: free_via_list(2399)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 32) returns address
0x837ec60 frag. 0x837ec48 (size=32) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837e674 alloc'ed from
<core>: parser/msg_parser.c: get_hdr_field(130)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/parse_via.c:1287]: Found param type 235, <rport> =
<n/a>; state=17
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f29c), called from
<core>: parser/hf.c: free_hdr_field_lst(251)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: <core>
[mem/q_malloc.c:366]: qm_malloc(0x82bcfe0, 860) called from <core>:
receive.c: receive_msg(120)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/parse_via.c:2300]: end of header reached, state=5
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837f284 alloc'ed from
<core>: parser/msg_parser.c: parse_headers(341)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: <core>
[mem/q_malloc.c:406]: qm_malloc(0x82bcfe0, 860) returns address
0x8380078 frag. 0x8380060 (size=860) on 1 -th hit
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:515]: parse_headers: Via found, flags=2
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f38c), called from
<core>: parser/parse_via.c: free_via_param_list(2387)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: DEBUG:
<core> [parser/msg_parser.c:640]: SIP Reply  (status):
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [parser/msg_parser.c:517]: parse_headers: this is the first via
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837f374 alloc'ed from
<core>: parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: DEBUG:
<core> [parser/msg_parser.c:642]:  version: <SIP/2.0>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [receive.c:145]: After parse_msg...
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:428]: qm_free(0x82bcfe0, 0x837f6e0), called from
<core>: parser/parse_via.c: free_via_param_list(2387)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: DEBUG:
<core> [parser/msg_parser.c:644]:  status:  <486>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
<core> [receive.c:186]: preparing to run routing scripts...
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15016]: <core>
[mem/q_malloc.c:450]: qm_free: freeing frag. 0x837f6c8 alloc'ed from
<core>: parser/parse_via.c: parse_via(2168)
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15014]: DEBUG:
<core> [parser/msg_parser.c:646]:  reason:  <Busy Here>
Mar 22 13:48:57 sip /usr/ipbx/kamailio/sbin/kamailio[15015]: DEBUG:
sl [sl_funcs.c:307]: DEBUG : sl_filter_ACK: to late to be a local ACK! /
Regards,
Miguel Baptista

SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- 
Daniel-Constantin Mierla
http://www.asipto.com

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

Re: [SR-Users] Failure route triggers a 500 internal server error - take 2