Tek-Tips is the largest IT community on the Internet today!

Members share and learn making Tek-Tips Forums the best source of peer-reviewed technical information on the Internet!

Register Log in
  • Congratulations Chriss Miller on being selected by the Tek-Tips community for having the most helpful posts in the forums last week. Way to Go!

Calls not ringing the dialed extension

Status
Not open for further replies.
chaunymony

chaunymony

Programmer
Feb 25, 2010
227
US
Hey guys, I have a problem that's been a pain to reproduce but I am getting a lot of calls saying it's happening. I have a 500v2 at 7.0 with matching Voicemail Pro and 1408 and 1416 series handsets. The issue is callers are saying they are calling an extension and it's ringing to the wrong place. Ex: 104 calls 107 and it rings at 128 instead. I have been running monitor but have yet to be able to catch it in the act. I do see this "No user activity" that keeps popping up on the trace and I'm not sure what that means. Just seeing if any of you had come across this before or not. Below is a small chunk of monitor trace.

231412413mS PRN: +++ START OF ALARM LOG DUMP +++
231412413mS PRN: ALARM: 15/04/2011 18:03:25 IP 500 V2 7.0(5) <WATCHDOG> CRIT RAISED addr=00000000 d=0 pc=f00b8a94 f00065d8 f02929e0 f02929ac 00000000 00000000
231412413mS PRN: +++ END OF ALARM LOG DUMP +++
231413613mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
231413613mS PRN: + loader: 1.32
231413613mS PRN: + cpu: id 12 board 3 pld 24 type c10 options a002
231413613mS PRN: + cpu: sn 11WZ03000601
231413613mS PRN: + fpga: id 1 issue 0 build 827
231413613mS PRN: +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
231413614mS PRN: ++++++++++++++++++++ LIST OF MODULES ++++++++++++++++++++
231413614mS PRN: +------------------------------------------------------------
231413614mS PRN: + Slot 1: Base PHONE8 Board=0x05 PLD=0x03
231413614mS PRN: + Mezzanine PRIS U Board=0x03 PLD=0x0a
231413614mS PRN: +------------------------------------------------------------
231413614mS PRN: + Slot 2: Base COMBO6210 Board=0x02 PLD=0x04
231413615mS PRN: + Mezzanine ATM4 Board=0x03 PLD=0x07
231413615mS PRN: +------------------------------------------------------------
231413615mS PRN: + Slot 3: Base DIGSTA8 Board=0x13 PLD=0x06
231413615mS PRN: + Mezzanine NONE
231413615mS PRN: +------------------------------------------------------------
231413615mS PRN: + Slot 4: Base DIGSTA8 Board=0x13 PLD=0x06
231413615mS PRN: + Mezzanine NONE
231413616mS PRN: +------------------------------------------------------------
231413616mS PRN: +++++++++++++++++ END OF LIST OF MODULES +++++++++++++++
231413616mS PRN: +++++++++++++++++ LIST OF MEMORY CARDS ++++++++++++++++++
231413616mS PRN: +------------------------------------------------------------
231413616mS PRN: + System SD Card: MNTD
231413616mS PRN: + CID Register: 0x02544d534430344761b1c64e2b00aa61
231413617mS PRN: + CSD Register: 0x400e00325b5900001d877f800a400051
231413617mS PRN: + SCR Register: 0x02b5800026028302
231413617mS PRN: + OCR Register: 0xc0ff8000
231413618mS PRN: + Status Register: 0x000000000200000002029004005a
231413618mS PRN: +------------------------------------------------------------
231413619mS PRN: + Optional SD Card: UMNT
231413619mS PRN: +------------------------------------------------------------
231413619mS PRN: ++++++++++++++ END OF LIST OF MEMORY CARDS +++++++++++++
231413619mS PRN: ++++++++++++++++++++ MEMORY CAPTURE +++++++++++++++++++++
231413619mS PRN: +------------------------------------------------------------
231413619mS PRN: + 0x00000003, 0x00000000, 0x00000000, 0x00000015, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000015, 0x00000000, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000015, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
231413620mS PRN: + 0x00000000, 0x00000000, 0x00000000, 0x00000000, 0x00000000
231413621mS PRN: + 0x00000000, 0x4dabd46a, 0x2047cb91, 0x3ad37ce9, 0xe7055cc7
231413621mS PRN: +------------------------------------------------------------
231413621mS PRN: +++++++++++++++++ END OF MEMORY CAPTURE ++++++++++++++++
231420024mS CMTARGET: ISDN BChannel 2: in-service check = 1
231420024mS ISDNL3Evt: v=1 stacknum=1 State, new=Present, old=NullState id=11
231420025mS CMLineRx: v=1
CMSetup
Line: type=Q931Line 1 Call: lid=1 id=11 in=1
Called[2187231112] Type=Unknown (0) Reason=CMDRdirect SndComp Calling[92184915049] Type=Unknown Plan=ISDN Pres=Allowed (0)
BC: CMTC=Speech CMTM=Circuit CMTR=64 CMST=Default CMU1=ULaw
BChan: slot=0 chan=2
231420025mS PRN: Q931Trunk: Found QBChannel to match 0.2 --> 1.3
231420026mS CMCallEvt: 0.3287.0 -1 BaseEP: NEW CMEndpoint f52562a4 TOTAL NOW=7 CALL_LIST=3
231420026mS CMCallEvt: CREATE CALL:642 (f52554a8)
231420026mS CMCallEvt: 0.3288.0 -1 BaseEP: NEW CMEndpoint f5221f9c TOTAL NOW=8 CALL_LIST=3
231420028mS CD: CALL: 1.11.1 BState=Idle Cut=1 Music=0.0 Aend="Line 1" (1.3) Bend="" [] (0.0) CalledNum=2187231112 () CallingNum=92184915049 () Internal=0 Time=2 AState=Idle
231420028mS CMCallEvt: 1.11.1 642 Q931 Trunk:1 CHAN=2: StateChange: END=A CMCSIdle->CMCSDialInitiated
231420029mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: LOOKUP CALL ROUTE: type=0 called_party=2187231112 sub= calling=92184915049 dir=in complete=1 ses=0
231420029mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: SET BESTMATCH: length 0 vs -1 match= dest=Main
231420029mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: SET BESTMATCH: length 10 vs 0 match=2187231112 dest=Main
231420030mS CMCallEvt: Priority hike: call 642 priority 0->1
231420030mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: LOOKUP ICR: DDI= CGPN=92184915049 (Destination Main ) => CDPN=Main
231420030mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: ADD TARGET (N): number=Main type=0 depth=1 nobar=1 setorig=1 ses=0
231420030mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: HG(Main,200,10.169.1.85) Requires Routing To Master(1). IsLocalExecutive(1)
231420031mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: HG call targeting occuring here
231420031mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: PrimeForHGTarget: Main setorig=1 recall=0 resetExtnVars 1
231420031mS CMCallEvt: Priority hike: call 642 priority 1->5
231420031mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: AddHGTarget Main (depth=2) allowq=1 type=CMNTypeUnknown
231420031mS CMCallEvt: 0.3289.0 -1 BaseEP: NEW CMEndpoint f5228f24 TOTAL NOW=9 CALL_LIST=4
231420032mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: AddHGTargetRingGroup Main starting at 1
231420032mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: ADD USER: Reception 2nd 2 depth=3 disallow_cw=0 dnd=0 real_call=1 group_call=1 type(CMNTypeUnknown) incl(0x0) excpt(0x3c), allow_redir(1) remote=00000000
231420032mS CMCallEvt: 0.3290.0 -1 BaseEP: NEW CMEndpoint f52137c0 TOTAL NOW=10 CALL_LIST=4
231420033mS CMCallEvt: 0.3290.0 -1 Reception 2nd 2.-1: NEW CMExtnEndpoint f52137c0, Name=Reception 2nd 2, Extn=104, Phys Extn=104
231420034mS CMTARGET: 0.3290.0 642 Reception 2nd 2.0: ADD PRIMARY
231420034mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: ADD USER: Reception 2nd depth=3 disallow_cw=0 dnd=0 real_call=1 group_call=1 type(CMNTypeUnknown) incl(0x0) excpt(0x3c), allow_redir(1) remote=00000000
231420034mS CMCallEvt: 0.3291.0 -1 BaseEP: NEW CMEndpoint f521ed60 TOTAL NOW=11 CALL_LIST=4
231420035mS CMCallEvt: 0.3291.0 -1 Reception 2nd.-1: NEW CMExtnEndpoint f521ed60, Name=Reception 2nd, Extn=100, Phys Extn=100
231420035mS CMTARGET: 0.3291.0 642 Reception 2nd.1: ADD PRIMARY
231420036mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: INITIAL TARGETING SUCCEEDED
231420036mS CMTARGET: 1.11.1 642 Q931 Trunk:1 CHAN=2: GetNoAnswerTimer:15
231420036mS CMCallEvt: 1.11.1 642 Q931 Trunk:1 CHAN=2: StateChange: END=A CMCSDialInitiated->CMCSDialled
231420037mS CMLineTx: v=1




And this is the "no user activity" that I'm seeing pop up.

231944060mS CMExtnEvt: Nursing Stat 1: CMExtnHandler::SetCurrent( id: 3419->0 )
231944061mS CMCallEvt: 0.3419.0 -1 Nursing Stat 1.-1: StateChange: END=X CMCSCompleted->CMCSDelete
231944061mS CMCallEvt: 0.3419.0 -1 BaseEP: DELETE CMEndpoint f524b58c TOTAL NOW=7 CALL_LIST=3
231944061mS CMExtnEvt: Reception 1st: CALL LOST (CMCauseNormal)
231944061mS CMExtnEvt: Reception 1st: Extn(125) Calling Party Number(127) Type(CMNTypeInternal)
231944062mS CMExtnEvt: Reception 1st: CMExtnHandler::SetCurrent( id: 3421->0 )
231944062mS CMCallEvt: 0.3421.0 -1 Reception 1st.-1: StateChange: END=X CMCSCompleted->CMCSDelete
231944062mS CMCallEvt: END CALL:682 (f522f7b8)
231944063mS CMCallEvt: 0.3421.0 -1 BaseEP: DELETE CMEndpoint f521d618 TOTAL NOW=6 CALL_LIST=3
231944065mS CMMap: PCG::UnmapBChan pcp[113]b1r0 cp_b f5391de0 other_cp_b f536e748
231944065mS CMMap: a=20.9 b=20.11 M0
231944065mS CMMap: PCG::UnmapBChan pcp[153]b1r0 cp_b f536e748 other_cp_b 0
231944884mS CMExtnEvt: Nr Station 1: No user activity
231946061mS CMExtnEvt: Nursing Stat 1: Recover Timer reason=CMTRWrapUp
231946061mS CMExtnEvt: v=3 State, new=Idle old=PortRecoverDelay,0,0,Nursing Stat 1
231946062mS CMExtnTx: v=127, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 5 Call: lid=0 id=-1 in=0
Called[Nursing Stat 1 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Nursing Stat 1 Msgs=0]
Timed: 18/04/11 10:29
231946063mS CMExtnEvt: Reception 1st: Recover Timer reason=CMTRWrapUp
231946063mS CMExtnEvt: v=1 State, new=Idle old=PortRecoverDelay,0,0,Reception 1st
231946064mS CMExtnTx: v=125, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 5 Call: lid=0 id=-1 in=0
Called[Reception 1st Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Reception 1st Msgs=0]
Timed: 18/04/11 10:29
231959548mS CMExtnRx: v=100, p1=0
CMReleaseComp
Line: type=DigitalExtn 4 Call: lid=0 id=3424 in=0
231959548mS CMCallEvt: 0.3424.0 683 Reception 2nd.0: StateChange: END=B CMCSConnected->CMCSCompleted
231959549mS CMExtnEvt: v=5 State, new=PortRecoverDelay old=Connected,0,0,Reception 2nd
231959550mS CMLOGGING: CALL:2011/04/1810:29,00:00:19,001,184,O,100,100,NursingStat4,,,1,,""n/a,0
231959550mS CD: CALL: 0.3422.0 BState=Disconnecting Cut=1 Music=0.0 Aend="Nursing Stat 4(184)" (9.24) Bend="Reception 2nd(100)" [Reception 2nd(100)] (20.5) CalledNum=100 (Reception 2nd) CallingNum=184 (Nursing Stat 4) Internal=1 Time=22497 AState=Connecte 231959550mS CD: CALL: 0.3422.0 Deleted
231959550mS CD: CALL: 0.3422.0 Deleted
231959551mS CMExtnEvt: Nursing Stat 4: CALL LOST (CMCauseNormal)
231959551mS CMExtnEvt: Nursing Stat 4: Extn(184) Calling Party Number(184) Type(CMNTypeInternal)
231959551mS CMCallEvt: 0.3422.0 -1 Nursing Stat 4.0: StateChange: END=X CMCSConnected->CMCSCompleted
231959552mS CMExtnEvt: v=22 State, new=PortRecoverDelay old=Connected,0,0,Nursing Stat 4
231959552mS CMExtnTx: v=184, p1=0
CMReleaseComp
Line: type=DigitalExtn 7 Call: lid=0 id=3422 in=0
Called[100] Type=Default (100) Reason=CMDRdirect Calling[184] Type=Internal Plan=Default
Cause=16, Normal call clearing
Timed: 18/04/11 10:29
231959553mS CMExtnEvt: Nursing Stat 4: CMExtnHandler::SetCurrent( id: 3422->0 )
231959553mS CMCallEvt: 0.3422.0 -1 Nursing Stat 4.-1: StateChange: END=X CMCSCompleted->CMCSDelete
231959553mS CMCallEvt: 0.3422.0 -1 BaseEP: DELETE CMEndpoint f5241224 TOTAL NOW=5 CALL_LIST=2
231959554mS CMExtnEvt: Reception 2nd: CALL LOST (CMCauseNormal)
231959554mS CMExtnEvt: Reception 2nd: Extn(100) Calling Party Number(184) Type(CMNTypeInternal)
231959554mS CMExtnEvt: Reception 2nd: CMExtnHandler::SetCurrent( id: 3424->0 )
231959555mS CMCallEvt: 0.3424.0 -1 Reception 2nd.-1: StateChange: END=X CMCSCompleted->CMCSDelete
231959555mS CMCallEvt: END CALL:683 (f52005c0)
231959556mS CMCallEvt: 0.3424.0 -1 BaseEP: DELETE CMEndpoint f5238f68 TOTAL NOW=4 CALL_LIST=2
231959557mS CMMap: PCG::UnmapBChan pcp[141]b1r0 cp_b f5378798 other_cp_b f536f4a4
231959557mS CMMap: a=20.5 b=9.24 M0
231959557mS CMMap: PCG::UnmapBChan pcp[152]b1r0 cp_b f536f4a4 other_cp_b 0
231959862mS RES: Mon 18/4/2011 10:29:55 FreeMem=64808968(1) CMMsg=7 (8) Buff=200 948 1000 7396 5 Links=18555
231959862mS RES2: IP 500 V2 7.0(5) Tasks=41 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=63 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
231961553mS CMExtnEvt: Nursing Stat 4: Recover Timer reason=CMTRWrapUp
231961553mS CMExtnEvt: v=22 State, new=Idle old=PortRecoverDelay,0,0,Nursing Stat 4
231961553mS CMExtnTx: v=184, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 7 Call: lid=0 id=-1 in=0
Called[Nursing Stat 4 Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Nursing Stat 4 Msgs=0]
Timed: 18/04/11 10:29
231961555mS CMExtnEvt: Reception 2nd: Recover Timer reason=CMTRWrapUp
231961555mS CMExtnEvt: v=5 State, new=Idle old=PortRecoverDelay,0,0,Reception 2nd
231961556mS CMExtnTx: v=100, p1=0
CMVoiceMailStatus
Line: type=DigitalExtn 4 Call: lid=0 id=-1 in=0
Called[Reception 2nd Msgs=0 Old=0 Sav=0] Type=Default (100) Reason=CMDRdirect Calling[00000000] Type=Default Plan=Default
Display [Reception 2nd Msgs=0]
Timed: 18/04/11 10:29
231963324mS CMExtnEvt: Donna: No user activity
231964376mS CMExtnEvt: Nr Station 4: No user activity
231964458mS CMExtnEvt: Lab 2: No user activity
231975522mS CMExtnEvt: v=(null) State, new=Idle old=Idle,0,0,Amy: DSS Emulation DefinityHGEna Key Pressed 5
231975523mS CMExtnEvt: Amy: ProcessShortCode feature=HuntGroupEnable id=133
231975525mS PRN: Config Write Wake Up
231975862mS RES: Mon 18/4/2011 10:30:11 FreeMem=64808996(1) CMMsg=7 (8) Buff=200 948 1000 7396 5 Links=18553
231975862mS RES2: IP 500 V2 7.0(5) Tasks=41 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=59 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
231976025mS PRN: Updates IO list size 1 updated list size 2
231976026mS PRN: Sending Updates out to f525bbc8 started
231976027mS PRN: Sending Updates out to f525bbc8 finished
231976027mS PRN: Config Write Completed
231990360mS CMExtnEvt: Kate: No user activity
231990664mS CMExtnEvt: Tammy: No user activity
231992369mS CMExtnEvt: Reception 2nd 2: No user activity
231992862mS RES: Mon 18/4/2011 10:30:28 FreeMem=64808528(1) CMMsg=7 (8) Buff=200 948 999 7396 5 Links=18555
231992862mS RES2: IP 500 V2 7.0(5) Tasks=41 RTEngine=0 CMRTEngine=0 ExRTEngine=0 Timer=56 Poll=0 Ready=0 CMReady=0 CMQueue=0 VPNNQueue=0 Monitor=1 SSA=0 ASC=1 SYS=MNTD OPT=UMNT SDSPD=2034
 
Sort by date Sort by votes
I should also note I have looked into forwarding, internal twinning and such and all is turned off.
 
Upvote 0 Downvote
capture your monitor traces, and save them to a log file that you can look at after it has been reported. at least then you can run an autopsy on the issue.

i would also say that if it is happening on a regular basis, open the call status, and start dialing away. dial every extension and see if you can duplicate the problem yourself. it may annoy users, but if you can get to the bottom of it, so be it.

Beets? Yes! Ask me how I feel about Beets! I like Beets!
 
Upvote 0 Downvote
Thanks! I do have the traces writing to file now so I can go back through them. They take a lot of calls so by the time I heard of it happening I couldn't go back far enough on monitor. I think doing the call every extension and try to make it happen is about my last option for this short of wiping the box and starting over.
 
Upvote 0 Downvote
SSA continous log wil be better, set that away and when they say it happened you can watch it back like it was real-time in SSA :)

ACSS (SME)
APSS (SME)


"I'm just off to Hartlepool to buy some exploding trousers
 
Upvote 0 Downvote
I completely forgot about SSA continuous log. Thanks that will be much easier to sift through!
 
Upvote 0 Downvote
Status
Not open for further replies.

Similar threads

bbrown3730
  • Locked
  • Question
All of a sudden in IP Office outside calls show the main BTN and not the actual extension of the user making the phone call. How can I fix this?
Replies
4
Views
642
Ivan_Cohen
Ivan_Cohen
phoneguy427
  • Locked
  • Question
Networked IP office ringing over amplifier 3
Replies
4
Views
454
phoneguy427
phoneguy427
smartedge1
  • Locked
  • Question
Disable extension to extension calls 9
2
Replies
27
Views
1K
hibroth
hibroth
NetEngBB
  • Locked
  • Question
Forward unconditional not working with external calls through VMPro
Replies
11
Views
948
NetEngBB
NetEngBB
Nikos Koulioumbis
  • Locked
  • Question
VM PRO on IPO500 9.0.12 does not route calls to menu selection 1
Replies
6
Views
522
TouchToneTommy
TouchToneTommy

Part and Inventory Search

Sponsor

Back
Top