Show Posts
1
Mitel Software Applications / UCX - the phone rejected the connection.
« on: March 28, 2012, 09:07:04 AM »
Dear All
I am really struggling with getting UCX working.
current setup is Mitel 3300 running version 10.2.0.26_2 and the phone i am testing with is 5330 with PC connectivity enabled on the phone. Computers are on vlan 1 and mitel is on vlan 2. they are on different ip ranges but i can ping from the pc both the phone and the ICP and from the ICP the pc so i am happy i can communicate with the phones.
I have checked firewalls and added the port 5060 and 80 to incoming rules for the pc and have followed the UCX instructions but i still cannot get the software to connect i keep getting a message saying the phone rejected the connection.
I would be very greatful if someone could look at the log files below and let me know what they think is stopping it from working.
Many thanks
Oliver
DEBUG 2012-03-21 15:31:09.185 T(01): Scope End <<< mitel_test_btn__Click() (309396ms)
DEBUG 2012-03-21 15:31:10.208 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:31:10.208 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:02.401 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:32:02.402 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:32:02.402 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:32:02.402 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:32:04.579 T(01): Scope Start >>> InitializeGeneralPanel()
DEBUG 2012-03-21 15:32:04.580 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:04.580 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:04.580 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:04.580 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:04.583 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
DEBUG 2012-03-21 15:32:04.586 T(01): Scope End <<< InitializeGeneralPanel() (0ms)
DEBUG 2012-03-21 15:32:04.589 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:04.590 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:04.590 T(01): Scope End <<< get_taskBarLocation (15ms)
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:32:04.609 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:04.609 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:04.609 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:04.609 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:11.540 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:11.540 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:16.253 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:32:16.253 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:32:16.254 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:32:16.254 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:32:18.821 T(01): Scope Start >>> InitializeGeneralPanel()
DEBUG 2012-03-21 15:32:18.822 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:18.822 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:18.822 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:18.823 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
WARNING 2012-03-21 15:32:18.824 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
DEBUG 2012-03-21 15:32:18.827 T(01): Scope End <<< InitializeGeneralPanel() (0ms)
DEBUG 2012-03-21 15:32:18.830 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:18.831 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:18.831 T(01): Scope End <<< get_taskBarLocation (0ms)
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:32:18.849 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:18.850 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:18.850 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:18.850 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:23.163 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:23.163 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:23.163 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:33:12.846 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:33:12.847 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:33:12.847 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:33:12.847 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:16.557 T(01): Scope Start >>> mitel_test_btn__Click()
INFO 2012-03-21 15:33:16.570 T(01): status_tb_.Handle == 13308026
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:33:16.571 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.571 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.572 T(01): Scope Start >>> PCAAPI
DEBUG 2012-03-21 15:33:16.634 T(01): Scope Start >>> connect_events
DEBUG 2012-03-21 15:33:16.639 T(01): Scope End <<< connect_events (15ms)
DEBUG 2012-03-21 15:33:16.639 T(01): Scope End <<< PCAAPI (78ms)
DEBUG 2012-03-21 15:33:16.640 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.640 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.640 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.640 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.640 T(21): Scope Start >>> initiate(PhoneProfile)
DEBUG 2012-03-21 15:33:16.640 T(21): <Profile name="Work" model="" type="mitel_desktop_phone"><Entry name="phone_ipordn">2627</Entry><Entry name="phone_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAB0pqsZx/2/6uSVSTBwbhJ4AAAAAASAAACgAAAAEAAAAP77c9luKGcTtaSnylftUSUIAAAAiJD+VZHOJesUAAAAEbXg2A2SA856pqHC3ve0vkCPuvw=</Entry><Entry name="icp_url">10.10.27.1</Entry><Entry name="vms_number">2627</Entry><Entry name="icp_user">DN2IP</Entry><Entry name="icp_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAA4UtUYMhGRgmIx0lqJ6MA+AAAAAASAAACgAAAAEAAAAPHjXfeAM8RoAhIC0/u1LUUIAAAARRHd0/wAqsAUAAAAA/MXQzbvevBMBJKlHEIFKWzsEOw=</Entry><Entry name="direct_line">False</Entry><Entry name="networkInfo"></Entry><Entry name="use_dhcp_values">True</Entry><Entry name="DHCP_sip_server"></Entry><Entry name="DHCP_sip_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_user_domain">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_url">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_vms_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_voicemail_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_tftp_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="last_IP"></Entry></Profile>
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> DoDNToIP
INFO 2012-03-21 15:33:16.649 T(21): <Profile name="Work" model="" type="mitel_desktop_phone"><Entry name="phone_ipordn">2627</Entry><Entry name="phone_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAB0pqsZx/2/6uSVSTBwbhJ4AAAAAASAAACgAAAAEAAAAP77c9luKGcTtaSnylftUSUIAAAAiJD+VZHOJesUAAAAEbXg2A2SA856pqHC3ve0vkCPuvw=</Entry><Entry name="icp_url">10.10.27.1</Entry><Entry name="vms_number">2627</Entry><Entry name="icp_user">DN2IP</Entry><Entry name="icp_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAA4UtUYMhGRgmIx0lqJ6MA+AAAAAASAAACgAAAAEAAAAPHjXfeAM8RoAhIC0/u1LUUIAAAARRHd0/wAqsAUAAAAA/MXQzbvevBMBJKlHEIFKWzsEOw=</Entry><Entry name="direct_line">False</Entry><Entry name="networkInfo"></Entry><Entry name="use_dhcp_values">True</Entry><Entry name="DHCP_sip_server"></Entry><Entry name="DHCP_sip_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_user_domain">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_url">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_vms_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_voicemail_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_tftp_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="last_IP"></Entry></Profile>
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> GetIPFromDN( 2627, Unprogrammed)
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.649 T(21): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.650 T(21): Scope Start >>> DN2IP.Lookup()
DEBUG 2012-03-21 15:33:19.646 T(21): Scope End <<< DN2IP.Lookup() (2995ms)
INFO 2012-03-21 15:33:19.646 T(21): DN2IP.Lookup returned: OK - InService
INFO 2012-03-21 15:33:19.647 T(21): GetIPFromDN() is returning: OK - InService
DEBUG 2012-03-21 15:33:19.647 T(21): Scope End <<< GetIPFromDN( 2627, Unprogrammed) (3011ms)
INFO 2012-03-21 15:33:19.647 T(21): Phone IP = 10.10.27.59
DEBUG 2012-03-21 15:33:19.648 T(21): Scope End <<< DoDNToIP (3011ms)
DEBUG 2012-03-21 15:33:19.648 T(21): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:19.648 T(21): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:19.648 T(21): Scope Start >>> initiate
DEBUG 2012-03-21 15:33:19.652 T(21): Scope End <<< initiate (0ms)
DEBUG 2012-03-21 15:33:19.652 T(21): Scope End <<< initiate(PhoneProfile) (3011ms)
INFO 2012-03-21 15:33:19.656 T(10): OnCSTASent:
<RequestSystemStatus xmlns="http://www.ecma-international.org/standards/ecma-323/csta/ed3" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
<extensions>
<privateData>
<private>
<mitel:Param1 xmlns:mitel="http://schemas.mitel.com/cstaExtension">9bf017355da1d8ddd016fe5366396a3c</mitel:Param1>
<mitel:Param2 xmlns:mitel="http://schemas.mitel.com/cstaExtension">8228824e055c357b4983c75eb9cc2368</mitel:Param2>
</private>
</privateData>
</extensions>
</RequestSystemStatus>
DEBUG 2012-03-21 15:33:19.657 T(10): Scope Start >>> OnError( 0 )
DEBUG 2012-03-21 15:33:19.657 T(10): Scope End <<< OnError( 0 ) (0ms)
DEBUG 2012-03-21 15:33:51.666 T(10): Scope Start >>> OnError( 1 )
DEBUG 2012-03-21 15:33:51.666 T(10): Scope Start >>> pca_DisconnectedEvent( connection_closed, )
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> closeConnection()
DEBUG 2012-03-21 15:33:51.668 T(10): Scope End <<< closeConnection() (0ms)
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> Mitel.PCAAPI.Dispose(True)
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> clear_events
DEBUG 2012-03-21 15:33:51.671 T(10): Scope End <<< clear_events (0ms)
DEBUG 2012-03-21 15:33:51.671 T(10): Scope Start >>> closeConnection()
DEBUG 2012-03-21 15:33:51.672 T(10): Scope End <<< closeConnection() (0ms)
DEBUG 2012-03-21 15:33:51.672 T(10): Calling ReleaseComObject on ntb2_: 0
DEBUG 2012-03-21 15:33:51.674 T(10): Calling ReleaseComObject on tel_: 0
DEBUG 2012-03-21 15:33:51.674 T(10): Calling FinalReleaseComObject on ntb_: 0
DEBUG 2012-03-21 15:33:51.677 T(10): Trying to kill PC App on exit
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< Mitel.PCAAPI.Dispose(True) (0ms)
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< pca_DisconnectedEvent( connection_closed, ) (0ms)
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< OnError( 1 ) (0ms)
DEBUG 2012-03-21 15:34:58.749 T(01): Scope End <<< mitel_test_btn__Click() (102180ms)
DEBUG 2012-03-21 15:37:44.111 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:37:44.112 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:37:44.112 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:37:59.260 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:37:59.261 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:38:01.518 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:38:01.518 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:38:01.518 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:38:01.518 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:38:07.451 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:38:07.451 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:38:07.451 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:38:07.465 T(01): Scope Start >>> OnLoad
DEBUG 2012-03-21 15:38:07.470 T(01): Scope End <<< OnLoad (0ms)
I am really struggling with getting UCX working.
current setup is Mitel 3300 running version 10.2.0.26_2 and the phone i am testing with is 5330 with PC connectivity enabled on the phone. Computers are on vlan 1 and mitel is on vlan 2. they are on different ip ranges but i can ping from the pc both the phone and the ICP and from the ICP the pc so i am happy i can communicate with the phones.
I have checked firewalls and added the port 5060 and 80 to incoming rules for the pc and have followed the UCX instructions but i still cannot get the software to connect i keep getting a message saying the phone rejected the connection.
I would be very greatful if someone could look at the log files below and let me know what they think is stopping it from working.
Many thanks
Oliver
DEBUG 2012-03-21 15:31:09.185 T(01): Scope End <<< mitel_test_btn__Click() (309396ms)
DEBUG 2012-03-21 15:31:10.208 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:31:10.208 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:02.401 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:32:02.402 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:32:02.402 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:32:02.402 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:32:04.579 T(01): Scope Start >>> InitializeGeneralPanel()
DEBUG 2012-03-21 15:32:04.580 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:04.580 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:04.580 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:04.580 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
WARNING 2012-03-21 15:32:04.582 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:04.583 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
DEBUG 2012-03-21 15:32:04.586 T(01): Scope End <<< InitializeGeneralPanel() (0ms)
DEBUG 2012-03-21 15:32:04.589 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:04.590 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:04.590 T(01): Scope End <<< get_taskBarLocation (15ms)
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:32:04.608 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:32:04.609 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:04.609 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:04.609 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:04.609 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:11.540 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:11.540 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:16.253 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:32:16.253 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:32:16.254 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:32:16.254 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:32:18.821 T(01): Scope Start >>> InitializeGeneralPanel()
DEBUG 2012-03-21 15:32:18.822 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:18.822 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:32:18.822 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:32:18.823 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
WARNING 2012-03-21 15:32:18.824 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyStatus()
at ov.a()
WARNING 2012-03-21 15:32:18.825 T(01): System.Runtime.InteropServices.COMException (0x800706BA): The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
at MSNMessengerAPI.MessengerClass.get_MyContacts()
at ov.a()
DEBUG 2012-03-21 15:32:18.827 T(01): Scope End <<< InitializeGeneralPanel() (0ms)
DEBUG 2012-03-21 15:32:18.830 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:18.831 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:18.831 T(01): Scope End <<< get_taskBarLocation (0ms)
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:32:18.849 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:32:18.849 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:18.850 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:18.850 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:32:18.850 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:32:23.163 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:32:23.163 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:32:23.163 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:33:12.846 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:33:12.847 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:33:12.847 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:33:12.847 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:13.749 T(01):
DEBUG 2012-03-21 15:33:16.557 T(01): Scope Start >>> mitel_test_btn__Click()
INFO 2012-03-21 15:33:16.570 T(01): status_tb_.Handle == 13308026
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting InGenius 124/125 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid InGenius 124/125 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting InGenius 60/43 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid InGenius 60/43 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting Mitel 124/125 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid Mitel 124/125 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting Mitel 60/43 options
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid Mitel 60/43 options found.
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: requesting option 140
INFO 2012-03-21 15:33:16.570 T(01): DhcpManager: no valid option 140 found.
DEBUG 2012-03-21 15:33:16.571 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.571 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.572 T(01): Scope Start >>> PCAAPI
DEBUG 2012-03-21 15:33:16.634 T(01): Scope Start >>> connect_events
DEBUG 2012-03-21 15:33:16.639 T(01): Scope End <<< connect_events (15ms)
DEBUG 2012-03-21 15:33:16.639 T(01): Scope End <<< PCAAPI (78ms)
DEBUG 2012-03-21 15:33:16.640 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.640 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.640 T(01): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.640 T(01): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.640 T(21): Scope Start >>> initiate(PhoneProfile)
DEBUG 2012-03-21 15:33:16.640 T(21): <Profile name="Work" model="" type="mitel_desktop_phone"><Entry name="phone_ipordn">2627</Entry><Entry name="phone_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAB0pqsZx/2/6uSVSTBwbhJ4AAAAAASAAACgAAAAEAAAAP77c9luKGcTtaSnylftUSUIAAAAiJD+VZHOJesUAAAAEbXg2A2SA856pqHC3ve0vkCPuvw=</Entry><Entry name="icp_url">10.10.27.1</Entry><Entry name="vms_number">2627</Entry><Entry name="icp_user">DN2IP</Entry><Entry name="icp_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAA4UtUYMhGRgmIx0lqJ6MA+AAAAAASAAACgAAAAEAAAAPHjXfeAM8RoAhIC0/u1LUUIAAAARRHd0/wAqsAUAAAAA/MXQzbvevBMBJKlHEIFKWzsEOw=</Entry><Entry name="direct_line">False</Entry><Entry name="networkInfo"></Entry><Entry name="use_dhcp_values">True</Entry><Entry name="DHCP_sip_server"></Entry><Entry name="DHCP_sip_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_user_domain">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_url">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_vms_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_voicemail_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_tftp_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="last_IP"></Entry></Profile>
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> DoDNToIP
INFO 2012-03-21 15:33:16.649 T(21): <Profile name="Work" model="" type="mitel_desktop_phone"><Entry name="phone_ipordn">2627</Entry><Entry name="phone_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAB0pqsZx/2/6uSVSTBwbhJ4AAAAAASAAACgAAAAEAAAAP77c9luKGcTtaSnylftUSUIAAAAiJD+VZHOJesUAAAAEbXg2A2SA856pqHC3ve0vkCPuvw=</Entry><Entry name="icp_url">10.10.27.1</Entry><Entry name="vms_number">2627</Entry><Entry name="icp_user">DN2IP</Entry><Entry name="icp_password">AQAAANCMnd8BFdERjHoAwE/Cl+sBAAAA1e1yN+DjR0+FkmObnGMYAwQAAAACAAAAAAADZgAAwAAAABAAAAA4UtUYMhGRgmIx0lqJ6MA+AAAAAASAAACgAAAAEAAAAPHjXfeAM8RoAhIC0/u1LUUIAAAARRHd0/wAqsAUAAAAA/MXQzbvevBMBJKlHEIFKWzsEOw=</Entry><Entry name="direct_line">False</Entry><Entry name="networkInfo"></Entry><Entry name="use_dhcp_values">True</Entry><Entry name="DHCP_sip_server"></Entry><Entry name="DHCP_sip_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_registrar_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_user_domain">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_stun_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_outbound_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_url">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_icp_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_user">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_asterisk_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_password">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_it5k_server_port">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_vms_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_sip_voicemail_number">UNDEFINED_DHCP_VALUE</Entry><Entry name="DHCP_tftp_server">UNDEFINED_DHCP_VALUE</Entry><Entry name="last_IP"></Entry></Profile>
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> GetIPFromDN( 2627, Unprogrammed)
DEBUG 2012-03-21 15:33:16.649 T(21): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:16.649 T(21): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:16.650 T(21): Scope Start >>> DN2IP.Lookup()
DEBUG 2012-03-21 15:33:19.646 T(21): Scope End <<< DN2IP.Lookup() (2995ms)
INFO 2012-03-21 15:33:19.646 T(21): DN2IP.Lookup returned: OK - InService
INFO 2012-03-21 15:33:19.647 T(21): GetIPFromDN() is returning: OK - InService
DEBUG 2012-03-21 15:33:19.647 T(21): Scope End <<< GetIPFromDN( 2627, Unprogrammed) (3011ms)
INFO 2012-03-21 15:33:19.647 T(21): Phone IP = 10.10.27.59
DEBUG 2012-03-21 15:33:19.648 T(21): Scope End <<< DoDNToIP (3011ms)
DEBUG 2012-03-21 15:33:19.648 T(21): Scope Start >>> Decrypt
DEBUG 2012-03-21 15:33:19.648 T(21): Scope End <<< Decrypt (0ms)
DEBUG 2012-03-21 15:33:19.648 T(21): Scope Start >>> initiate
DEBUG 2012-03-21 15:33:19.652 T(21): Scope End <<< initiate (0ms)
DEBUG 2012-03-21 15:33:19.652 T(21): Scope End <<< initiate(PhoneProfile) (3011ms)
INFO 2012-03-21 15:33:19.656 T(10): OnCSTASent:
<RequestSystemStatus xmlns="http://www.ecma-international.org/standards/ecma-323/csta/ed3" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
<extensions>
<privateData>
<private>
<mitel:Param1 xmlns:mitel="http://schemas.mitel.com/cstaExtension">9bf017355da1d8ddd016fe5366396a3c</mitel:Param1>
<mitel:Param2 xmlns:mitel="http://schemas.mitel.com/cstaExtension">8228824e055c357b4983c75eb9cc2368</mitel:Param2>
</private>
</privateData>
</extensions>
</RequestSystemStatus>
DEBUG 2012-03-21 15:33:19.657 T(10): Scope Start >>> OnError( 0 )
DEBUG 2012-03-21 15:33:19.657 T(10): Scope End <<< OnError( 0 ) (0ms)
DEBUG 2012-03-21 15:33:51.666 T(10): Scope Start >>> OnError( 1 )
DEBUG 2012-03-21 15:33:51.666 T(10): Scope Start >>> pca_DisconnectedEvent( connection_closed, )
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> closeConnection()
DEBUG 2012-03-21 15:33:51.668 T(10): Scope End <<< closeConnection() (0ms)
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> Mitel.PCAAPI.Dispose(True)
DEBUG 2012-03-21 15:33:51.668 T(10): Scope Start >>> clear_events
DEBUG 2012-03-21 15:33:51.671 T(10): Scope End <<< clear_events (0ms)
DEBUG 2012-03-21 15:33:51.671 T(10): Scope Start >>> closeConnection()
DEBUG 2012-03-21 15:33:51.672 T(10): Scope End <<< closeConnection() (0ms)
DEBUG 2012-03-21 15:33:51.672 T(10): Calling ReleaseComObject on ntb2_: 0
DEBUG 2012-03-21 15:33:51.674 T(10): Calling ReleaseComObject on tel_: 0
DEBUG 2012-03-21 15:33:51.674 T(10): Calling FinalReleaseComObject on ntb_: 0
DEBUG 2012-03-21 15:33:51.677 T(10): Trying to kill PC App on exit
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< Mitel.PCAAPI.Dispose(True) (0ms)
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< pca_DisconnectedEvent( connection_closed, ) (0ms)
DEBUG 2012-03-21 15:33:51.677 T(10): Scope End <<< OnError( 1 ) (0ms)
DEBUG 2012-03-21 15:34:58.749 T(01): Scope End <<< mitel_test_btn__Click() (102180ms)
DEBUG 2012-03-21 15:37:44.111 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:37:44.112 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:37:44.112 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:37:59.260 T(01): Scope Start >>> SetDialCurrentAreaCode( {0} )
DEBUG 2012-03-21 15:37:59.261 T(01): Scope End <<< SetDialCurrentAreaCode( {0} ) (0ms)
DEBUG 2012-03-21 15:38:01.518 T(01): Scope Start >>> OnTrayIconOpening
DEBUG 2012-03-21 15:38:01.518 T(01): Scope Start >>> FillPhones
DEBUG 2012-03-21 15:38:01.518 T(01): Scope End <<< FillPhones (0ms)
DEBUG 2012-03-21 15:38:01.518 T(01): Scope End <<< OnTrayIconOpening (0ms)
DEBUG 2012-03-21 15:38:07.451 T(01): Scope Start >>> get_taskBarLocation
DEBUG 2012-03-21 15:38:07.451 T(01): taskBarLocation == c
DEBUG 2012-03-21 15:38:07.451 T(01): Scope End <<< get_taskBarLocation (0ms)
DEBUG 2012-03-21 15:38:07.465 T(01): Scope Start >>> OnLoad
DEBUG 2012-03-21 15:38:07.470 T(01): Scope End <<< OnLoad (0ms)