Thanks for the answer. I had already upgraded the phones to 7.5.6 just before I saw your reply and it did not solve the problem. In addition I did see the anonymous call problem but due to how our system implements dynamic call park they can be parked and then when the call is picked up again the xfer button is back and it works so we can work around that for now.
Due to some things we have found out I'm thinking now it is a network problem. This customer has a point to point fiber link and the provider of that link says they are having problems with their pon equipment and are in the process of replacing many of them. Just as a note, I have verified that the device that is doing nat for this customer does not have sip alg turned on (a cisco 2800 with the no service sip udp 5060 command - I think that is the exact syntax from memory but I would have to login to check the exact syntax).
I still see something I don't understand at all. I turned the debug on for 3 phones - debug level 3 as well as full sip debugging. I did that late last night and then made a test call. Now the description I originally gave was for a call that exhibited the problem I described but it looked like a trace for a normal call. We have found out that on many of the problem calls though there are multiple invites sent due to not receiving a response from the phone. So, for example, a call comes in, the server sends an invite, waits for a timeout period with no response and then sends another invite. Eventually responses are received from the phones. My test call at 02:42 this morning exhibited that behaviour, 3 invites were sent before a response.
Now here is the weird part, when I looked at the logs I see no invites for the call. There are a lot of NOTIFY messages which are used for registration to our server normally but I even see them associated with the call ID of my test call. I'm attaching the log with my cell number sanitized (and the command I ran to filter this out was
cat syslog.1 | grep 20140906074250023017-fcdd719c346870e86975fdd57713f6b > ~/tsb.log
so the log should only show entries related to that phone call since that is the term call-id):
Sep 6 02:42:50 NOTIFY sip: 118@10.110.0.146 SIP/2.0#015#012Via: SIP/2.0/UDP 74.112.209.130:5060;branch=z9hG4bKUVWWVs4t2q4Wq73993B53D#015#012To: "Greg Elsner" <sip:118@tsb>;tag=89e554bf95c65b7f#015#012From: <sip:104@tsb>;tag=bmH0iT0QrJl9zEpz930F3B#015#012Call-ID: cd52bdbf-4290067f@10.110.0.146#015#012CSeq: 110 NOTIFY#015#012Contact: <sip:74.112.209.130:5060;transport=udp>#015#012Server: NetSapiens SiPBx 1-1224#015#012Event: dialog#015#012Subscription-State: active#015#012Content-Type: application/dialog-info+xml#015#012Content-Length: 506#015#012#015#012<?xml version="1.0"?>#012<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="9" state="full" entity="sip:104@tsb"#012>#012<dialog id="20140906074250023017-fcdd719c346870e86975fdd57713f6b5" direction="recipient">#012<state>early</state>#012<local>#012<identity display="Tri State Bearing">"sip:104@tsb"#012</identity>#012<target uri="sip:104@tsb"/>#012</local>#012<remote>#012<identity display="SITCO LLC">"sip:+xxxxxxxxxxx@4.55.39.95"#012</identity>#012<target uri="sip:+xxxxxxxxxxx@4.55.39.95"/>#012</remote>#012</dialog>#012</dialog-info>
That looks like all other registration attempts I see in the logs but I don't understand why the call id of this call is associated with it - and that is a question to be answered by the phone switch vendor. Here is an example of other registration attempts:
Sep 6 02:28:57 NOTIFY sip: 101@10.110.0.129 SIP/2.0#015#012Via: SIP/2.0/UDP 74.112.209.130:5060;branch=z9hG4bKE8IDms6ZgzZIEw7k934A51#015#012To: "Ron Eli" <sip:101@tsb>;tag=25f3b6f160bf0b0a#015#012From: <sip:110@tsb>;tag=S2HbkUT5gWBJ05Hx93057B#015#012Call-ID: 731b063d-a899242e@10.110.0.129#015#012CSeq: 104 NOTIFY#015#012Contact: <sip:74.112.209.130:5060;transport=udp>#015#012Server: NetSapiens SiPBx 1-1224#015#012Event: dialog#015#012Subscription-State: active#015#012Content-Type: application/dialog-info+xml#015#012Content-Length: 354#015#012#015#012<?xml version="1.0"?>#012<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="3" state="full" entity="sip:110@tsb"#012>#012<dialog id="20140905215139056156-fcdd719c346870e86975fdd57713f6b5">#012<state>terminated</state>#012<local>#012<identity display="Tri State Bearing">"sip:110@tsb"#012</identity>#012<target uri="sip:110@tsb"/>#012</local>#012</dialog>#012</dialog-info>
Now one thing to note in the log is the phone does respond with a 180 ringing. Here is the response the server received from one phone:
@2014-09-06_02:42:51
Received Packet from 74.112.209.59:1167
SIP/2.0 180 Ringing
To: <sip:118@tsb>;tag=e509be5a6f2c02edi0
From: "SITCO LLC" <sip:+xxxxxxxxxxx@4.55.39.95>;tag=5xCRHR4oc34m3aR893B545
Call-ID: 20140906074250023017-fcdd719c346870e86975fdd57713f6b5
CSeq: 201 INVITE
Via: SIP/2.0/UDP 74.112.209.130:5060;branch=z9hG4bK5xCRHR4oc34m3aR893B545
Contact: "Greg Elsner" <sip:118@10.110.0.146:5060>
Server: Cisco/SPA508G-7.5.6
Content-Length: 0
and there is a matching packet from the phone log that is exactly like that received by the server.
What I don't understand is if the phone log reports that the phone didn't receive an invite then why does it respond with the 180? That just makes no sense to me. I did a test call from a phone in my office this morning and the log for that looks like one would expect with the phone logging the invite and then responding to it. Any ideas on what might be making the phone ring without it receiving an invite - or at least showing that in the logs? I am going to be getting some packet captures from one of the phones in question on Monday but if there is any insight you may have it would be greatly appreciated.
Thanks!
P.S. I'm adding this note because I figured out one thing about the logs. All of the phones this customer has have the attendant consoles and they have 23 (I think that is correct) phones ring at once. So I now know those NOTIFY packets are for those consoles. It still doesn't explain why the phones don't report seeing an INVITE yet they still respond with a 180 Ringing. I don't thing the NOTIFY packets would be causing a problem but that is one thing I'm going to test. I'll disable the consoles and make some test calls and see if I can replicate the no INVITE and then see what the phones do.
I'll keep everyone updated on this in case anyone else ever runs into a problem like this. I must admit that I am becoming very curious about what exactly is going on but it is also very exasperating as well! :-)
