Strange Problem after upgrade to 8.1(63) 1

[PhoneGuyNJ]

I have IP Office 500V2, with a Digital and a Combo Card. We have 1 POTS line on port 9 of the combo, and all was working fine until the upgrade. Now, almost every 30 minutes, the system thinks that line is ringing, when in fact it's not. It rings about 1 ring and stops, with no callerID. I have now set an incoming call route with a "?" to go to a phanthom extension that just is a busy, because it's annoying. Tried everything, reboots, some settings, etc. Strange because it's only since the upgrade. It seems as though it is detecting "something" but I dont know what that something is. I can say there is no voicemail on the POTS.

Here is a piece of the log when it happens if anyone has any ideas..

2013-01-10T13:58:48 4647038mS ATMChannel: [1] DTMF Message Rx: 0x0000 (Tone=0x0000)
2013-01-10T13:58:48 4647038mS ATMChannel: [1] CLI Message Rx:
2013-01-10T13:58:48 4647038mS ATMChannel: end of CLI Message
2013-01-10T13:58:48 4647038mS ATMChannel: [1] StateChange Idle->CLIAwaitData
2013-01-10T13:58:48 4647038mS ATMChannel: [1] CMLinkLayer Tx: 'Alert_PreIndication'
2013-01-10T13:58:48 4647038mS ATMIO: [1] CLI DETECTION OFF, EQUALISER OFF
2013-01-10T13:58:48 4647038mS ATMChannel: [1] StateChange CLIAwaitData->CLIDataSettle
2013-01-10T13:58:48 4647039mS ATMCMLine: [1] CMLinkLayer Rx: 'Alert_PreIndication' callid=(lid=1, id=2, in=1)
2013-01-10T13:58:48 4647039mS ATMCMLine: [1] StateChange Idle->IncomingGuard
2013-01-10T13:58:48 4647238mS ATMChannel: [1] Sloppy timeout(200ms)
2013-01-10T13:58:48 4647238mS ATMChannel: [1] StateChange CLIDataSettle->Incoming
2013-01-10T13:58:48 4647238mS ATMChannel: [1] CMLinkLayer Tx: 'Ringing'
2013-01-10T13:58:48 4647238mS ATMCMLine: [1] CMLinkLayer Rx: 'Ringing' callid=(lid=1, id=2, in=1)
2013-01-10T13:58:48 4647239mS ATMCMLine: [1] StateChange IncomingGuard->Present
2013-01-10T13:58:48 4647239mS ATMCMLine: [1] IncomingCall
2013-01-10T13:58:48 4647240mS CMCallEvt: 0.1113.0 -1 BaseEP: NEW CMEndpoint f5170318 TOTAL NOW=1 CALL_LIST=0
2013-01-10T13:58:48 4647240mS CMCallEvt: CREATE CALL:6 (f51889b4)
2013-01-10T13:58:48 4647240mS CMCallEvt: 0.1114.0 -1 BaseEP: NEW CMEndpoint f51874e8 TOTAL NOW=2 CALL_LIST=0
2013-01-10T13:58:48 4647242mS CMLineRx: v=1
CMSetup
Line: type=AnalogueLine 1 Call: lid=1 id=2 in=1
Called[] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[] Type=Unknown Plan=Unknown Pres=NAInterworking (2)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=1 chan=1
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=2 ipaddr=192.168.42.1 apps=0
2013-01-10T13:58:48 4647242mS CD: CALL: 1.2.1 BState=Idle Cut=1 Music=0.0 Aend="Line 1" (1.1) Bend="" [] (0.0) CalledNum= () CallingNum= () Internal=0 Time=2 AState=Idle
2013-01-10T13:58:48 4647243mS CMCallEvt: 1.2.1 6 Alog Trunk:1: StateChange: END=A CMCSIdle->CMCSDialInitiated
2013-01-10T13:58:48 4647243mS CMTARGET: 1.2.1 6 Alog Trunk:1: LOOKUP CALL ROUTE: type=0 called_party= sub= calling= dir=in complete=1 ses=0
2013-01-10T13:58:48 4647243mS CMTARGET: 1.2.1 6 Alog Trunk:1: SET BESTMATCH: length 0 vs -1 match= dest=Home Line
2013-01-10T13:58:48 4647243mS CMTARGET: 1.2.1 6 Alog Trunk:1: AMBIGUITY: match= dest=498
2013-01-10T13:58:48 4647243mS CMTARGET: 1.2.1 6 Alog Trunk:1: SET BESTMATCH: length 0 vs 0 match= dest=498
2013-01-10T13:58:48 4647243mS CMCallEvt: Priority hike: call 6 priority 0->1
2013-01-10T13:58:48 4647243mS CMTARGET: 1.2.1 6 Alog Trunk:1: LOOKUP ICR: DDI=856-854-2679 CGPN= (Destination 498 ) => CDPN=498
2013-01-10T13:58:48 4647244mS CMTARGET: 1.2.1 6 Alog Trunk:1: ADD TARGET (N): number=498 type=0 depth=1 nobar=1 setorig=1 ses=0
2013-01-10T13:58:48 4647244mS CMTARGET: 1.2.1 6 Alog Trunk:1: SET USER: BUSY orig=1
2013-01-10T13:58:48 4647244mS CMTARGET: 1.2.1 6 Alog Trunk:1: ADD USER: BUSY depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeUnknown) incl(0x0) excpt(0x0), allow_redir(1) remote=00000000 simult 0 (0)
2013-01-10T13:58:48 4647244mS CMTARGET: TryLoggedOutTargeting for user BUSY Failed
2013-01-10T13:58:48 4647244mS CMTARGET: 1.2.1 6 Alog Trunk:1: NO INITIAL TARGETS: BUSY
2013-01-10T13:58:48 4647244mS CMTARGET: 1.2.1 6 Alog Trunk:1: ADD USER: BUSY depth=1 disallow_cw=0 dnd=0 real_call=1 group_call=0 type(CMNTypeUnknown) incl(0x40) excpt(0x40), allow_redir(1) remote=00000000 simult 0 (0)
2013-01-10T13:58:48 4647245mS CMTARGET: TryLoggedOutTargeting for user BUSY Failed
2013-01-10T13:58:48 4647245mS CMTARGET: 1.2.1 6 Alog Trunk:1: SELECT: TRY VOICEMAIL orig_hg() orig_user(498)
2013-01-10T13:58:48 4647245mS CMTARGET: 1.2.1 6 Alog Trunk:1: Fallback() targeting failed
2013-01-10T13:58:48 4647246mS CMLOGGING: CALL:2013/01/1013:58,00:00:00,000,,I,498,,,,,0,,""n/a,0
2013-01-10T13:58:48 4647246mS CD: CALL: 1.2.1 BState=Idle Cut=0 Music=0.0 Aend="Line 1" (1.1) Bend="BUSY(498)" [] (0.0) CalledNum=498 (BUSY) CallingNum= () Internal=0 Time=6 AState=Dialling
2013-01-10T13:58:48 4647246mS CD: CALL: 1.2.1 Deleted
2013-01-10T13:58:48 4647246mS CMTARGET: 1.2.1 -1 Alog Trunk:1: ~CMTargetHandler f518a7e0 ep f5170318
2013-01-10T13:58:48 4647246mS CMCallEvt: 1.2.1 -1 Alog Trunk:1: StateChange: END=X CMCSDialInitiated->CMCSCompleted
2013-01-10T13:58:48 4647247mS CMCallEvt: 0.1114.0 -1 BaseEP: DELETE CMEndpoint f51874e8 TOTAL NOW=1 CALL_LIST=0
2013-01-10T13:58:48 4647247mS CMCallEvt: END CALL:6 (f51889b4)
2013-01-10T13:58:48 4647247mS ATMCMLine: [1] ControlEchoCancellation ON
2013-01-10T13:58:48 4647247mS ATMCMLine: [1] CMLinkLayer Tx: 'EchoControl'
2013-01-10T13:58:48 4647249mS ATMChannel: [1] CMLinkLayer Rx: 'EchoControl' (ls)
2013-01-10T13:58:48 4647249mS ATMIO: [1] ECHO CANCELLATION ON
2013-01-10T13:58:48 4647249mS PRN: Config Write Wake Up
2013-01-10T13:58:48 4647513mS RES: Thu 10/1/2013 13:58:49 FreeMem=60075060(1) CMMsg=5 (6) Buff=5200 956 999 12463 5 Links=7775 BTree=0 CPU=10/13/16495/34376/36055/2
2013-01-10T13:58:48 4647513mS RES2: IP 500 V2 8.1(63) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=58 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2013-01-10T13:58:48 4647513mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)
2013-01-10T13:58:48 4647554mS PRN: Updates IO list size 1 updated list size 1
2013-01-10T13:58:48 4647554mS PRN: Sending Updates out to f5b05870 started
2013-01-10T13:58:48 4647554mS PRN: Sending Updates out to f5b05870 finished
2013-01-10T13:58:48 4647555mS PRN: Config Write Completed
2013-01-10T13:58:53 4652238mS ATMChannel: [1] Sloppy timeout(5000ms)
2013-01-10T13:58:53 4652238mS ATMIO: [1] TRUNK RELEASE
2013-01-10T13:58:53 4652238mS ATMChannel: [1] StateChange Incoming->Idle
2013-01-10T13:58:53 4652238mS ATMIO: [1] ECHO CANCELLATION OFF
2013-01-10T13:58:53 4652238mS ATMIO: [1] BLOCK FORWARDING OFF
2013-01-10T13:58:53 4652238mS ATMIO: [1] CLI DETECTION ON, EQUALISER OFF
2013-01-10T13:58:53 4652238mS ATMChannel: [1] CMLinkLayer Tx: 'Disconnect'
2013-01-10T13:58:53 4652239mS ATMCMLine: [1] CMLinkLayer Rx: 'Disconnect' callid=(lid=1, id=0, in=1)
2013-01-10T13:58:53 4652239mS ATMCMLine: [1] StateChange Present->DiscInd
2013-01-10T13:58:53 4652239mS ATMCMLine: [1] CM Tx: 'CMReleaseComp' callid=(lid=1, id=2, in=1)
2013-01-10T13:58:53 4652239mS CMLineRx: v=1
CMReleaseComp
Line: type=AnalogueLine 1 Call: lid=1 id=2 in=1
BChan: slot=1 chan=1
IE CMIERespondingPartyNumber (230)(P:2 S:100 T:0 N:0 R:4) number=
IE CMIEDeviceDetail (231) LOCALE=enu HW=15 VER=8 class=CMDeviceAlogTrunk type=0 number=1 channel=0 rx_gain=32 tx_gain=32 ep_callid=2 ipaddr=192.168.42.1 apps=0
2013-01-10T13:58:53 4652239mS ATMCMLine: [1] StateChange DiscInd->Idle
2013-01-10T13:58:53 4652240mS ATMCMLine: [1] CMLinkLayer Tx: 'DisconnectAck'
2013-01-10T13:58:53 4652240mS CMCallEvt: 1.2.1 -1 Alog Trunk:1: StateChange: END=X CMCSCompleted->CMCSDelete
2013-01-10T13:58:53 4652240mS CMCallEvt: 1.2.1 -1 BaseEP: DELETE CMEndpoint f5170318 TOTAL NOW=0 CALL_LIST=0
2013-01-10T13:58:53 4652241mS ATMChannel: [1] CMLinkLayer Rx: 'DisconnectAck' (ls)
2013-01-10T13:58:53 4652513mS RES: Thu 10/1/2013 13:58:54 FreeMem=60081100(1) CMMsg=5 (6) Buff=5200 956 999 12463 5 Links=7778 BTree=0 CPU=3/4/16495/34711/36055/2
2013-01-10T13:58:53 4652513mS RES2: IP 500 V2 8.1(63) Tasks=48 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=57 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=2 SSA=1 TCP=21 TAPI=1 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
2013-01-10T13:58:53 4652513mS RES4: XML MemObjs=45 PoolMem=2097152(1) FreeMem=2082064(1)

 

[holdmusic34]

The line is out of use now because of the programming, can you parallel or even disconnect it from your system and monitor it from your butt handset?
I've seen a POT phantom ring fault that was caused by a dodgy patch panel socket on the tie cable from the MDF. I used a different pair on the tie and pp and hey presto.
Electrician had to replace their new patch panel.
8.1.63 upgrade could just be a coincidence- had a working NIC blow up yesterday around the same time i plugged a PoE handset in.

GL

 

[PhoneGuyNJ]

Well, I have plugged this directly into the DMARC (Verizon Fios) with nothing else in it, and still every 30 minutes or so, that comes into the office. There is nothing on the butt set ringing at all.. even checked with the phone company and no phanthom calls. Tried Analog port 3 as well, same result.

What I notice in this log event is that the following lines ALWAYS come in first:

2013-01-10T13:58:48 4647038mS ATMChannel: [1] DTMF Message Rx: 0x0000 (Tone=0x0000)
2013-01-10T13:58:48 4647038mS ATMChannel: [1] CLI Message Rx:
2013-01-10T13:58:48 4647038mS ATMChannel: end of CLI Message
2013-01-10T13:58:48 4647038mS ATMChannel: [1] StateChange Idle->CLIAwaitData
2013-01-10T13:58:48 4647038mS ATMChannel: [1] CMLinkLayer Tx: 'Alert_PreIndication'
2013-01-10T13:58:48 4647038mS ATMIO: [1] CLI DETECTION OFF, EQUALISER OFF

What it looks to me is that it's looking for DTMF CallerID? Even though I am not set for that and set for FSK.
Normal calls kick off like this:

2013-01-12T16:49:57 8334201mS ATMChannel: [1] External Rx: 'IncomingRing' (ls)
2013-01-12T16:49:57 8334201mS ATMChannel: [1] StateChange Idle->CLIPossibleIncoming
2013-01-12T16:49:57 8334251mS ATMChannel: [1] Sloppy timeout(50ms)
2013-01-12T16:49:57 8334281mS ATMChannel: [1] StateChange CLIPossibleIncoming->CLIAwaitData
2013-01-12T16:49:57 8334281mS ATMChannel: [1] CMLinkLayer Tx: 'Alert_PreIndication'
2013-01-12T16:49:57 8334281mS ATMCMLine: [1] CMLinkLayer Rx: 'Alert_PreIndication' callid=(lid=0, id=0, in=1)
2013-01-12T16:49:57 8334282mS ATMCMLine: [1] StateChange Idle->IncomingGuard
2013-01-12T16:50:00 8337281mS ATMChannel: [1] Sloppy timeout(3000ms)
2013-01-12T16:50:00 8337281mS ATMChannel: [1] StateChange CLIAwaitData->CLIAwaitSecondRing
2013-01-12T16:50:04 8341281mS ATMChannel: [1] Sloppy timeout(4000ms)

But these Phanthom calls come in as stated above. I have it set properly with ICLID and FSK.. so it's almost as if it's "listening" for some kind of DTMF tone?

 

[holdmusic34]

So we can say this:

If your butt isn't ringing it isn't a real call.

Also to confirm your findings, below is also a normal trace which matches yours:

24508275mS ATMChannel: [1] External Rx: 'IncomingRing' (ls)
24508275mS ATMChannel: [1] StateChange Idle->CLIPossibleIncoming
24508325mS ATMChannel: [1] Sloppy timeout(50ms)
24508355mS ATMChannel: [1] StateChange CLIPossibleIncoming->CLIAwaitData
24508355mS ATMChannel: [1] CMLinkLayer Tx: 'Alert_PreIndication'
24508355mS ATMCMLine: [1] CMLinkLayer Rx: 'Alert_PreIndication' callid=(lid=1, id=2, in=1)
24508356mS ATMCMLine: [1] StateChange Idle->IncomingGuard
24511355mS ATMChannel: [1] Sloppy timeout(3000ms)
24511355mS ATMChannel: [1] StateChange CLIAwaitData->CLIAwaitSecondRing


At the start of your buggy monitor:
2013-01-10T13:58:48 4647038mS ATMChannel: [1] DTMF Message Rx: 0x0000 (Tone=0x0000)

You are right, you are getting some voltage the IP Office is detecting somehow.


1) Are there any other devices or line cords on this line hanging up this line and/ or generating a 'tinkle' on the circuit? Sometimes tracing back to the frame is the only way to be sure!!
2) Have you got clear dial tone at your main frame and at your endpoints?
3) Can you use a different port on the IP Office?

I have seen a faulty node in the exchange that would drop a DSL/POT service every 10 -15 minutes, then come back online with a burst that made the phones ring. Carrier tech had to swap a card. Carrier checked and had normal dial tone every time.

Tlpeter or one of the other deep .bin file programmers would be able to tell you if there is any benefit in downgrading to 8.1.56. I shouldn't think so, but stand to be corrected.

 

[intrigrant]

I think you just have static on the line from a external source like a cooler starting every 30 minutes, you could try to find a line filter to suppress static.

A simple mind delivers great solutions

 

[PhoneGuyNJ]

For testing there are NO other devices on this line, I did think it could be the Alarm which is tied in, but we removed that and plugged directly into the POTS jack on the Verizon FIOS ONT at the DMARC with a brand new line cord. We also tried other ports on the combo card by placing this one out of service, and the same result - it follows the line.

Dial tone is completely clear, No static at all (at least that is audible).

Interesting point - as there IS a water cooler! - Unplugged that as well.. problem still exists.

My only thought would be why would the system even "listen" for a DTMF CallerID when it's not set that way - I would think it should be supressed. In fact, when I turn the line to a Loop Start instead of ICLID, I still get the same going on. It's almost like a line test.

We did also call Verizon whom tested the line and reported no trouble.

 

[intrigrant]

You don't have a oscilliscope around there I suppose? That would make static or other signals visible.

A simple mind delivers great solutions

 

[Westi]

change the line port and see if the problem follows (requires a reboot I know if you want to reprogram the line ID but you can also just make a new incoming call route with the line ID and outgoing you skip the line for an hour until you know)
Had it also happening that a DsL line filter took care of phantom ringing so if you have one then put it in and hope for the best.

Joe W.

FHandw, ACSS (SME), ACIS (SME)

http://convergednetworks.ca

Give a tech a solution and he will be back tomorrow to ask you the next question, teach a tech how to read the manual and he will be able to solve the problems for a life time.

 

[tkocomp]

I am experiencing the same "phantom ring" on my system. It is an IPO 500v2 just upgraded to 8.1(63). This is a test system I have in my shop and it is a fresh config. It was running fine without this issue for about a month but started with these false call detections almost immediately after upgrading.

I also have a single POTS line on FIOS digital voice service connected to a combo card. I have tried moving the line to all 4 ports, logging into my verizon portal to make sure that Light message light and/or change dial tone to stutter (where available) is turned off, to eliminate that as the problem. I increased the Ring Detection, Ring Persistency to 1200 (from default of 400) to try to eliminate the phantom calls, but they are still there. The line from the FIOS ONT is plugged directly into the IPO, bypassing all internal wiring.

I will dig up a DSL filter to see if it helps, but has anyone gotten any answers on this? As I stated, this is a test system, so if anyone has any suggestions, I'd be happy to test them out.

 

[smoknonions]

We also have 2 customers running 8.1(63) and analog trunks experiencing the same issue....

 

[bpitt]

I did an install last week for a business partner. The IP Office was loaded with 8.1.63, and we were told that 8.1.63 was acting 'buggy'. They didn't go into specifics, they just said they had just found out that 8.1.63 was 'buggy' by someone at tier 3/4 Avaya, for what it's worth.

 

[bpitt]

Oh, and we ended up downgrading the switch from 8.1.63 to 8.1.43 and had no problems.

 

[PhoneGuyNJ]

Well it looks like a new update to .65 came out - wonder if that included any other fixes. I am glad I am not the only one having this issue - I am also dealing with Fios, so we called and had VM removed completely. But as mentioned, this only started when moving to .63 build.

 

[intrigrant]

On Phone 16 & 30 modules the number presenation doesn't work on all stations. I use the 8.0 bins and then it works.

A simple mind delivers great solutions

 

[PhoneGuyNJ]

No this is an inbound issue.
I just upgraded to .65 and these phanthom ringing calls are still coming in every 30 minutes or so.
Just wondering what I will lose if I downgrade back to Q4 .57?

 

[Telecomboy]

What happens if you just unplug the line from port 9. Do you still get a ring? It could be a short on the card.

 

[sizbut]

You've already diagnosed what is happening yourself (the CLI MESSAGE events from Verizon) and also been given the answer in a previous reply, ask Verizon to turn off the message waiting indication that they are sending on that line. FSK can be used to send more things than just CLI, in this case its sending message indication and the IP Office is being triggered to expect a call that never actually occurs. The actual line is fine.

Stuck in a never ending cycle of file copying.

 

[PhoneGuyNJ]

What I am saying is:

1. I already did call Verizon - and had any message waiting cleared, as well as had voicemail completely removed.
2. If I unplug the line, the problem goes away

3. I have already plugged it directly into the ONT eliminating anything to do with any other phones, alarms, or anything else plugged in.

4. I have changed/tested all settings, including even turning off callerID on the line.

As mentioned above, others have the same issue. I never said it was a CLI message from Verizon - I just figured I would rule that out as well because others have mentioned it as an issue.

 

[amriddle01]

They all seem to have FIOS in common, what is this service? Some kind of emulated POTS line or is it a true trunk delivered on a copper cable?


Avaya Implementation Qualified Professional Specialist Technical Engineer (AIQPSTE)

 

[PhoneGuyNJ]

To answer your question - FIOS has been coming through Fiber for a few years now. About 6 months ago, they moved over to Digital Voice, which I assume it's coming VOIP into the ONT Fiber Unit - then to a regular jack. It DOES provide the same power specifications of a pots line, as well as disco supervision, etc.

I DOWNGRADED to .57 at this point - and the phantom ringing has now stopped.

What I observed through system monitoring is that we are still getting Incoming Abandoned calls every 30 minutes on Line 1 - which is the POTS... BUT, the IP Office is not seizing the line now. Before it was seizing the line, and then ringing the hunt group with about 1 ring, then releasing the line. It has stopped doing that and leaves the line idle, even though it's registering the incoming abandoned.

I can't tell you if it did that before, because since it wasn't ringing, we didnt look at that.

It's definately something with that line, because we have another POTS (Emumlated Line) on Line 2 which is actually a Skype Gateway that acts as a POTS, and this one works fine in and out.. none of that. If we flip flop the lines, it does follow the line, so it can't be a bad port.

(Not sure if I mentioned that for the fun of it, there is a DSL filter in place too as suggested).

Really bizarre if you ask me.