C SCRIPTS: Internal Error (Interface busy) and "always busy" on phone

[preacherandrew]

Hi.

I have CUCME 10.5 and about 100 sip-phones CP-7821. (All phones and server in LAN)

Sometimes some phone (or may be number) "hangs" - it becomes always busy. If I call to problem number - it is busy. If I call FROM problem number - I get busy too. If I power off, wait (even several hours) and power on problem phone - this is doesn't helps. Phone still always busy.

In debug logs on CUCME, I can trace this problem to these lines

948104: Jul 15 15:22:41.731: //-1/xxxxxxxxxxxx/DPM/dpMatchPeersMoreArg:
   Result=SUCCESS(0)
   List of Matched Outgoing Dial-peer(s):
     1: Dial-peer Tag=40067
948105: Jul 15 15:22:41.731: //23869//AFW_:/SetupValidateSharedln: calledNum=7076, callingNum=7299, callID=23869,  callinf.peertag=40071, joinXtoID=-1
948106: Jul 15 15:22:41.731: //23869//AFW_:/SetupValidateSharedln: Incoming call to shared-line '7076, userCnt: 0'
948107: Jul 15 12:22:41.731: %VOICE_IEC-3-GW: C SCRIPTS: Internal Error (Interface busy): IEC=1.1.182.11.26.0 on callID 23869 GUID=A80890D649BD11E6BA35A4004C60D51F
948108: Jul 15 15:22:41.731: //23869//AFW_:/Session_Close: lastFailureCause 17
948109: Jul 15 15:22:41.731: //23869//AFW_:/AFW_Module_Terminate:  Terminating Module: Session_0x10047264_0_110173872
948110: Jul 15 15:22:41.731: //23869//AFW_:/AFW_M_Session_Terminate:  
948111: Jul 15 15:22:41.731: //23869//AFW_:/AFW_M_Session_Terminate: lastFailureCause 17
948112: Jul 15 15:22:41.731: //23869//AFW_:/Session_Cleaner:  
948113: Jul 15 15:22:41.731: //23869//AFW_:/Session_Cleaner: lastFailureCause 17
948114: Jul 15 15:22:41.731: //23869/A80890D6BA35/AFW_:/AFW_Leg_Disconnect: Disconnecting Leg: LEG_23869
948115: Jul 15 15:22:41.731: //23869/A80890D6BA35/AFW_:/AFW_Leg_Disconnect: Disconnecting Leg: LEG_23869, Cause 17

That is, when I call to "problem" phone, CUCME finds right outbound dialpeer, but ... then CUCME decides that "interface busy" and returns "busy here". And as far as I understanding CUCME really don't try to connect with problem phone.

It seems that decision about "interface busy" based on an internal info in CUCME.

(For example, if I power off a normal phone and try to call it immediately - I get the silence - this is understandable - outbound dialpeer (for powered off phone) still exists but IP-address doesn't respond.

If I power off the "problem" phone and try to call it immediately - I get busy anyway)

Meanwhile "problem" phone is registered - I see normal exchange by SIP-messages (REGISTER, REFER, OK) between this phone and CUCME.

In most cases to cure the "problem" phone enough

voice register pool N

restart

But sometimes it's not enough and I have to restart CUCME.

How to know what script returns "Internal Error (Interface busy): IEC=1.1.182.11.26.0" ?

How to fix this problem?

[Manish Gogna]

As per docwiki "The IEC feature is itself a troubleshooting tool. By enabling the voice iec syslog command you can display IECs logged in real time, which allows you to isolate a failure cause without turning on debugging. Then, based on the IEC reported, you can selectively enable the appropriate debug tool to gather additional information."

http://docwiki.cisco.com/wiki/Cisco_IOS_Voice_Troubleshooting_and_Monitoring_--_Cisco_VoIP_Internal_Error_Codes#Enabling_IEC_Syslog_Reporting

In this case it appears we need more details like "show log" and "show tech" apart from the debug for a failed call to see what exactly is causing this issue.

Manish

[preacherandrew]

Must I use "show log" and "show tech" in any time or when there is a problem phone  or while calling to problem phone?

(I just reboot CUCME - because two phones "hanged". And it will take some time before problems reappears)

[Manish Gogna]

You can take the latest outputs when the issue is reproduced.

HTH

Manish

[preacherandrew]

Here is output "show logging" and "show tech" immediately after call to failed phone - call from 7299 to 7076

(I've cut most dn and peer from show running-config. )

P.S: After many experiments during several last days I think that I know how to reproduce this issue:

1) power off the phone

2) call to powered off phone immediately (while outbound dial-peer still exists)

3) power on the phone

4) make several call before phone is registered

Maybe when I make call to existing dial-peer and phone doesn't ready, CME (under some conditions) remembers that phone unavailable?

I've make those steps twice for 7076 phone and get this issue.

(Of cause my colleges don't power off/power on phones intentionally)