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