cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1999
Views
0
Helpful
5
Replies

Presence Version 8.6.2.10000-44 with Exchange 2010 Calender integration not working.

Sarg .
Level 3
Level 3

Hello all,

I have configure my presence server and integrated it with Microsoft AD and its all working fine except the calender presence is not been displayed on the cupc clients. I have log into the calender integration account via outlook web access and i was able to access the account perfectly ok. on active directory, I have given  the integration account Enterprice admin premission and on Exchange, I have given the integration account full mailbox access to all mailboxes but still its not working. can anyone offear any advice on this? 

I have attached the logs below.

cups config.PNG

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG -->BackendGatewayObserver.notify<record>

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG <--BackendGatewayObserver.notify<record>

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG -->BackendGatewayObserver.notify<record>

18:13:50.438 |CCMEncryption::hexToPassword():enter

18:13:50.438 |CCMEncryption::hexToPassword():exit

18:13:50.438 |CCMEncryption::DecryptText:enter

18:13:50.438 |CCMEncryption::DecryptText (Exit) (Success))

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG Calendar.notify Exchange server ADD or UPDATE

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG HostName:    calendar.homelab.com

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG Server:      WIN-LHJ39MD2SSK:443

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG AccountName: homelab\cupc

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG SubjectCN: null

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG LocaleCalendarName: default

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG Domain:

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG Site:

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG -->ExchangeSession::certificateExist: /usr/local/sip/.security/proxy/trust-certs

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG <--ExchangeSession::certificateExist: 1

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG -->SessionManager::addHost win-lhj39md2ssk:443

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG <--SessionManager.ctor 196484960

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG <--SessionManager.clear 196484960

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG <--SessionManager.set 196484960 win-lhj39md2ssk:443 homelab\cupc

18:13:50.438 |system.pe.pa.owa.backend 1114382 INFO <--SessionManager::addHost succeeded: win-lhj39md2ssk:443 homelab\cupc

18:13:50.438 |system.pe.pa.owa.backend 1114382 INFO <--Sessionmanager host(s): win-lhj39md2ssk:443

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG <--BackendGatewayObserver.notify<record>

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG <--BackendGatewayObserver.notify<recordsholder>

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG attach to the cache

18:13:50.438 |system.pe.storage 1114382 DEBUG StorageSubject 196178344::attach

18:13:50.438 |system.pe.pa.ews.backend 1114382 DEBUG <--BackendGatewayObserver::init

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.438 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1896262

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1897290

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1898318

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1899346

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1900374

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1901402

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1902430

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1903458

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1904486

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1905514

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1906542

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1907570

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1908598

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1909626

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1910654

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1911682

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1912710

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1913738

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1914766

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.439 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1915794

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1916822

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1917850

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1918878

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1919906

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1920934

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1921962

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1922990

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1924018

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1925046

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1926074

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1927102

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1928130

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1929158

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1930186

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1931214

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1932242

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1933270

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1934298

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.440 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1935326

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1936354

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1937382

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1938410

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1939438

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1940466

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1941494

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1942522

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1943550

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1944578

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1945606

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1946634

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1947662

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1948690

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1949718

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1950746

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1951774

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1952802

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1953830

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.441 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1954858

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1955886

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1956914

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG -->threadStart()

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG stack size:  1048576

18:13:50.442 |system.pe.pa.owa.backend 1114382 DEBUG <--threadStart():  1957942

18:13:50.442 |system.pe.pa.owa.backend 1114382 INFO set thread count for EWS transactions 60

18:13:50.442 |system.pe.pa.owa.backend 1114382 INFO set queue depth for EWS transactions 2200

18:13:50.442 |system.pe.pa.ews.backend 1114382 DEBUG <--EwsCalendar::init

18:13:50.442 |system.pe.pa.ews.backend 1114382 DEBUG <--EwsBackendAdapter.init

18:13:50.442 |system.pe.pa.backend 1114382 DEBUG Checking status

18:13:50.442 |system.pe.pa.backend 1114382 DEBUG status success

18:13:50.442 |system.pe.pa.backend 1114382 DEBUG created policy

18:13:50.442 |system.pe.pa.backend 1114382 DEBUG assigned policy

18:13:50.442 |system.pe.pa.sip.backend 1114382 DEBUG Entering SIPBackendAdapter::SIPBackendAdapter

18:13:50.442 |system.pe.pa.sip.backend 1114382 DEBUG Leaving SIPBackendAdapter::SIPBackendAdapter

18:13:50.442 |system.pe.pa.backend 1114382 DEBUG Leaving ForeignStateAccessManager::init

18:13:50.442 |system.pe.mvc 1114382 DEBUG PackageMgr::fetchPackageIPIDs: Entering

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: no data

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.442 |system.pe.mvc 1114382 WARNING package table entry missing for: calendar.winfo

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.442 |system.pe.mvc 1114382 DEBUG Setting presence package ipid = 1

18:13:50.442 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.443 |system.pe.mvc 1114382 DEBUG Setting presence.winfo package ipid = 3

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: no data

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.443 |system.pe.mvc 1114382 WARNING package table entry missing for: profileconfig.winfo

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: no data

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.443 |system.pe.mvc 1114382 WARNING package table entry missing for: reg

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Entering

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: no data

18:13:50.443 |system.pe.storage 1114382 DEBUG PackageCacheConn::getRecord: Leaving

18:13:50.443 |system.pe.mvc 1114382 WARNING package table entry missing for: reg.winfo

18:13:50.443 |system.pe.mvc 1114382 DEBUG PackageMgr::fetchPackageIPIDs: Leaving

18:13:50.443 |system.pe.mvc 1114382 DEBUG --> DefaultDocMRUCache::init

18:13:50.443 |system.pe.storage 1114382 DEBUG DefaultDocCacheConn::getAllRecords: Entering

18:13:50.443 |system.pe.pdr 1114382 DEBUG DefaultDocRecord::setDefaultDocument

18:13:50.443 |system.pe.storage 1114382 DEBUG added a row in default document record

18:13:50.443 |system.pe.pdr 1114382 DEBUG DefaultDocRecord::setDefaultDocument

18:13:50.443 |system.pe.storage 1114382 DEBUG added a row in default document record

18:13:50.443 |system.pe.storage 1114382 DEBUG DefaultDocCacheConn::getAllRecords: Leaving

18:13:50.443 |system.pe.pdr 1114382 DEBUG DefaultDocRecord::setDefaultDocument

18:13:50.443 |system.pe.pdr 1114382 DEBUG DefaultDocRecord::setDefaultDocument

18:13:50.443 |system.pe.storage.non-event 1114382 DEBUG --> DefaultDocCache::attach

18:13:50.443 |system.pe.storage 1114382 DEBUG StorageSubject 221258488::attach

18:13:50.443 |system.pe.storage.non-event 1114382 DEBUG <-- DefaultDocCache::attach

18:13:50.444 |system.pe.mvc 1114382 DEBUG -->FilterManager::init

18:13:50.444 |system.pe.utils 1114382 DEBUG -->ObjectPool

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 WARNING Entity Expansion Limit is 1000

18:13:50.444 |system.pe.utils 1114382 DEBUG ObjectPool-->

18:13:50.444 |system.pe.utils 1114382 DEBUG -->ObjectPool

18:13:50.444 |system.pe.utils 1114382 DEBUG ObjectPool-->

18:13:50.444 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference 0

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference - New filter, adding to the map

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference 1

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference - New filter, adding to the map

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference 11

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference - New filter, adding to the map

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference 12

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference - New filter, adding to the map

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference 13

18:13:50.445 |system.pe.mvc 1114382 DEBUG FilterManager::addFilterReference - New filter, adding to the map

18:13:50.445 |system.pe.mvc 1114382 DEBUG <--FilterManager::init

18:13:50.445 |system.pe.mvc 1114382 DEBUG UAToCapability ctor

18:13:50.445 |system.pe.mvc 1114382 DEBUG Entering UAToCapability::init

18:13:50.445 |system.pe.storage 1114382 DEBUG StorageSubject 207392600::attach

18:13:50.445 |system.pe.storage 1114382 DEBUG -->UAToCapabilityCacheConn::getAll: Entering

18:13:50.445 |system.pe.storage 1114382 DEBUG record 1

18:13:50.445 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.445 |system.pe.storage 1114382 DEBUG record 2

18:13:50.445 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 1, value = -1.

18:13:50.445 |system.pe.storage 1114382 DEBUG record 3

18:13:50.445 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 2, value = -1.

18:13:50.445 |system.pe.storage 1114382 DEBUG record 4

18:13:50.445 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 3, value = -1.

18:13:50.445 |system.pe.storage 1114382 DEBUG record 5

18:13:50.445 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 4, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 6

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 5, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 7

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 6, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 8

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 7, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 9

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 8, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 10

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 9, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 11

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 10, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 12

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 11, value = -1.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 13

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 12, value = 2.

18:13:50.446 |system.pe.storage 1114382 DEBUG record 14

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 13, value = 2.

18:13:50.446 |system.pe.storage 1114382 DEBUG <--UAToCapabilityCacheConn::getAll: Leaving

18:13:50.446 |system.pe.mvc 1114382 DEBUG number of uatocapability records 14

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 0, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 0, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-CCM/5.0 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 1, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 1, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-CCM/5.1 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 2, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 2, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-CCM5.1 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 3, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 3, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.1 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 4, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 4, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.2 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 5, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 5, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.3 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 6, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 6, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.4 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 7, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 7, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.5 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 8, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 8, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.6 with reachability version 1, filterId -1

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 9, filterId = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.446 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 9, filterId = -1.

18:13:50.446 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.7 with reachability version 1, filterId -1

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 10, filterId = -1.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 10, filterId = -1.

18:13:50.447 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.8 with reachability version 1, filterId -1

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 11, filterId = -1.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = -1.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 11, filterId = -1.

18:13:50.447 |system.pe.mvc 1114382 DEBUG user agent Cisco-UCModel01/1.1.9 with reachability version 1, filterId -1

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 12, filterId = 2.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = 2.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 12, filterId = 2.

18:13:50.447 |system.pe.mvc 1114382 DEBUG user agent LCC/1.3 with reachability version 1, filterId 2

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 13, filterId = 2.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::setFilterId: row = 0, value = 2.

18:13:50.447 |system.pe.pdr 1114382 DEBUG UAToCapability::getFilterId: row = 13, filterId = 2.

18:13:50.447 |system.pe.mvc 1114382 DEBUG user agent UCCP/2.0.6090.0 OC/2.0.6090.0 (Microsoft Office Communicator) with reachability version 1, filterId 2

18:13:50.447 |system.pe.mvc 1114382 DEBUG Leaving UAToCapability::init

18:13:50.447 |system.pe.mvc 1114382 DEBUG FederatedDomain ctor

18:13:50.447 |system.pe.mvc 1114382 DEBUG Entering FederatedDomain::init

18:13:50.447 |system.pe.storage.non-event 1114382 DEBUG --> FederatedDomainCache::attach(obs)

18:13:50.447 |system.pe.storage 1114382 DEBUG StorageSubject 218917240::attach

18:13:50.447 |system.pe.storage.non-event 1114382 DEBUG <--

FederatedDomainCache::attach(obs)

18:13:50.447 |system.pe.storage 1114382 DEBUG FederatedDomainCacheConn::get -> Entering

18:13:50.447 |system.pe.storage 1114382 DEBUG -->FederatedDomainCacheConn::getAll: Entering

18:13:50.447 |system.pe.storage 1114382 DEBUG <--FederatedDomainCacheConn::getAll: Leaving

18:13:50.447 |system.pe.mvc 1114382 DEBUG No records in FederatedDomain table

18:13:50.447 |system.pe.codec 1114382 DEBUG ipid: 1

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG PresPidfCodec: error from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG PresPidfCodec: error from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG error from mimecodecmgr_t registerCodec ENCODER for MULTISLOT_PRESENCE_IPID 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG error from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG status from mimecodecmgr_t registerCodec DECODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG status from mimecodecmgr_t registerCodec DECODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG  --> RegReginfoCodec::RegReginfoCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG ipid: -1

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG result from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG result from mimecodecmgr_t registerCodec DECODER 0

18:13:50.447 |system.pe.codec 1114382 DEBUG  RegReginfoCodec::RegReginfoCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG  --> GenericCodec::GenericCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG ipid: 104

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG Duplicate found, not inserted into map

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG Registering mime type: application/pidf+xml

18:13:50.447 |system.pe.codec 1114382 DEBUG result from mimecodecmgr_t registerCodec ENCODER 7

18:13:50.447 |system.pe.codec 1114382 DEBUG ipid: 101

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG Duplicate found, not inserted into map

18:13:50.447 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.447 |system.pe.codec 1114382 DEBUG Registering mime type: application/x-upcdbnotify+xml

18:13:50.447 |system.pe.codec 1114382 DEBUG result from mimecodecmgr_t registerCodec ENCODER 7

18:13:50.447 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.447 |system.pe.codec 1114382 DEBUG Duplicate found, not inserted into map

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG Registering mime type: application/x-upcloginnotify+xml

18:13:50.448 |system.pe.codec 1114382 DEBUG result from mimecodecmgr_t registerCodec ENCODER 7

18:13:50.448 |system.pe.codec 1114382 DEBUG  GenericCodec::GenericCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG -->SIPGenericPDRBuilder::SIPGenericPDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG ipid: 104

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG Duplicate PDRBuilder found

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG ipid: 101

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG Duplicate PDRBuilder found

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPGenericPDRBuilder::SIPGenericPDRBuilder-->

18:13:50.448 |system.pe.codec 1114382 DEBUG --> SIPPresencePDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG ipid found 1

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG error code from pdrbuildermgr 0

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPPresencePDRBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG --> SIPRegPDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG ipid found -1

18:13:50.448 |system.pe.codec 1114382 DEBUG error code from pdrbuildermgr for reg: 0

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPRegPDRBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPRlmiPDRBuilder::SIPRlmiPDRBuilder ctr

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG MultipartParser::MultipartParser ctr

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPMultipartRelatedPDRBuilder::SIPMultipartRelatedPDRBuilder ctr

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG --> CalendarPresencePDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG <-- CalendarPresencePDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG --> SIPAclInfoPDRBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG --> PDRBuilderMgr::registerSIPBuilder

18:13:50.448 |system.pe.codec 1114382 DEBUG PDRBuilderMgr::registerSIPBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG error code from pdrbuildermgr 0

18:13:50.448 |system.pe.codec 1114382 DEBUG SIPAclInfoPDRBuilder -->

18:13:50.448 |system.pe.codec 1114382 DEBUG WinfoPDRBuilder::WinfoPDRBuilder: Entering

18:13:50.448 |system.pe.codec 1114382 DEBUG WinfoPDRBuilder::WinfoPDRBuilder: Leaving

18:13:50.448 |system.pe.codec 1114382 DEBUG XmppPDRBuilder::XmppPDRBuilder: Entering

18:13:50.448 |system.pe.codec 1114382 DEBUG WinfoWatcherInfoCodec::WinfoWatcherInfoCodec(): Entering

18:13:50.448 |system.pe.codec 1114382 DEBUG WinfoWatcherInfoCodec::WinfoWatcherInfoCodec(): -- WINFO IPID = 3

18:13:50.448 |system.pe.codec 1114382 DEBUG mimetype used: application/watcherinfo+xml

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG return Code from mimecodecmgr_t registerCodec ENCODER: 0

18:13:50.448 |system.pe.codec 1114382 DEBUG WinfoWatcherInfoCodec::WinfoWatcherInfoCodec(): Leaving

18:13:50.448 |system.pe.codec 1114382 DEBUG  Entering RlmiCodec::RlmiCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG status from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.448 |system.pe.codec 1114382 DEBUG  Leaving RlmiCodec::RlmiCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG  Entering MultipartCodec::MultipartCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG status from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.448 |system.pe.codec 1114382 DEBUG  Leaving MultipartCodec::MultipartCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG  Entering MultipartMixedCodec::MultipartMixedCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG status from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.448 |system.pe.codec 1114382 DEBUG  Leaving MultipartMixedCodec::MultipartMixedCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG  --> AclInfoCodec::AclInfoCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG error from mimecodecmgr_t registerCodec ENCODER 0

18:13:50.448 |system.pe.codec 1114382 DEBUG --> MIMECodecMgr::registerCodec

18:13:50.448 |system.pe.codec 1114382 DEBUG MIMECodecMgr::registerCodec-->

18:13:50.448 |system.pe.codec 1114382 DEBUG  AclInfoCodec::AclInfoCodec-->

18:13:50.449 |CCMEncryption::hexToPassword():enter

18:13:50.449 |CCMEncryption::hexToPassword():exit

18:13:50.449 |CCMEncryption::DecryptText:enter

18:13:50.449 |CCMEncryption::DecryptText (Exit) (Success))

18:13:50.449 |system.pe.eventpkg.presence 1114382 DEBUG Axl connection to cucmpublisher, with user ccmadmin, and password agbakaagbaka1

18:13:50.450 |system.pe.eventpkg.presence 1114382 DEBUG Loading certificates from: /usr/local/platform/.security/tomcat/trust-certs/

18:13:50.450 |system.pe.eventpkg.presence 1114382 DEBUG AxlSession: loading certificate: cups-pub-sitea.homelab.com.pem

18:13:50.450 |system.pe 1114382 DEBUG -->threadStart()

18:13:50.450 |system.pe 1114382 DEBUG stack size is 262144

18:13:50.450 |system.pe 1114382 DEBUG <--threadStart(): 1840556960

18:13:50.450 |system.pe.mvc 1114382 DEBUG SubscriptionInfo::SubscriptionInfo

18:13:50.450 |system.pe.mvc 1114382 DEBUG Expires in constructor is 3600

18:13:50.450 |system.pe 1114382 DEBUG -->threadStart()

18:13:50.450 |system.pe 1114382 DEBUG stack size is 262144

18:13:50.450 |system.pe 1114382 DEBUG <--threadStart(): 1843219360

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent version:  1.0.137

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerPresenceEventListener() called

18:13:50.451 |pe.mvc.cupcm 1114382 DEBUG Presence watcher started

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerSessionEventListener() called

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerENCEventListener() called

18:13:50.451 |system.pe.jabber 1114382 DEBUG ::registerENCEventListener() - size =  1

18:13:50.451 |pe.mvc.cupcm 1114382 DEBUG PEXCPMessageWatcher()

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerMessageEventListener() called

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerRosterEventListener() called

18:13:50.451 |system.pe.jabber 1114382 INFO ClientEmComponent::registerPepEventListener() called

5 Replies 5

Paul Reck
Level 1
Level 1

Have you enabled calendar integration on the cup user page? Calendaring must be enable individually by the users now after you've configured the connections.

Sent from Cisco Technical Support iPhone App

yes I have enabled it. I just disabled form based authentication on ' outlook web access'  and extracted some logs again and i am  seeing  internal errors as can be seen below.

09:50:28.079 |system.pe.jabber 1962734 INFO ClientEmComponent::processIqResult() called

09:50:28.079 |pe.mvc.cupcm 1962734 DEBUG PEXCPPrivacyListener::privacyListSetResult() for 201212@homelab.com/composed

09:50:28.103 |system.pe.pa.owa.backend 1895926 ERROR subscribe parser status -  ResponseClass:  ResponseCode:  Subscription ID:  Watermark:  body:

09:50:28.103 |system.pe.pa.owa.backend 1895926 INFO received SUBSCRIBE response for 201211: 500 Internal Server Error

HTTP/1.1 500 Internal Server Error

x-powered-by: ASP.NET

transfer-encoding: chunked

persistent-auth: true

date: Sun, 28 Oct 2012 09:51:16 GMT

set-cookie: exchangecookie=c98a451f58454f8f9b9d3ce562cedba2; expires=Mon, 28-Oct-2013 09:51:16 GMT; path=/; HttpOnly

cache-control: private

server: Microsoft-IIS/7.5

content-type: text/xml; charset=utf-8

x-aspnet-version: 2.0.50727

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <----QMS::SUBSCRIBE 201211

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG -->SessionManager::setConnected: win-lhj39md2ssk:443 1

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--SessionManager::setConnected 0

09:50:28.103 |system.pe.pa.owa.backend 1895926 ERROR -->EWSSubscription::initiateRecovery: 201211 POST 500 Internal Server Error

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--EWSSubscription::clearResubscribe

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--EWSSubscription::scheduleResubscribe - interval (secs): 720

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--EWSSubscription::initiateRecovery: POST

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--EWSSubscription::processSubscribeRequest

09:50:28.103 |system.pe.pa.owa.backend 1895926 DEBUG <--QMS::SUBSCRIBE

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG parser status -  parserfinditem: ResponseClass:  ResponseCode:  []

09:50:28.103 |system.pe.pa.owa.backend 1896954 INFO received FINDITEM response for 201212: 500 Internal Server Error

HTTP/1.1 500 Internal Server Error

x-powered-by: ASP.NET

transfer-encoding: chunked

persistent-auth: true

date: Sun, 28 Oct 2012 09:51:16 GMT

set-cookie: exchangecookie=421d9aada8da49c38e80c2fa73fd4648; expires=Mon, 28-Oct-2013 09:51:16 GMT; path=/; HttpOnly

cache-control: private

server: Microsoft-IIS/7.5

content-type: text/xml; charset=utf-8

x-aspnet-version: 2.0.50727

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <----QMS::FINDITEM 201212

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG -->EWSCalendarInfo::processCalendarRequest: POST

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG -->SessionManager::setConnected: win-lhj39md2ssk:443 1

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--SessionManager::setConnected 0

09:50:28.103 |system.pe.pa.owa.backend 1896954 ERROR -->EWSCalendarInfo::initiateRecovery: 201212 POST 500 Internal Server Error

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--EWSCalendarInfo::clearTransition

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--EWSCalendarInfo::clearRefresh

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--EWSCalendarInfo::scheduleRefresh - refresh interval: 720

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--EWSCalendarInfo::initiateRecovery: POST

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--EWSCalendarInfo::processCalendarRequest

09:50:28.103 |system.pe.pa.owa.backend 1896954 DEBUG <--QMS::FINDITEM

09:50:28.103 |system.pe.pa.owa.backend 1894898 DEBUG parser status -  parserfinditem: ResponseClass:  ResponseCode:  []

09:50:28.103 |system.pe.pa.owa.backend 1894898 INFO received FINDITEM response for 201211: 500 Internal Server Error

HTTP/1.1 500 Internal Server Error

x-powered-by: ASP.NET

transfer-encoding: chunked

persistent-auth: true

date: Sun, 28 Oct 2012 09:51:16 GMT

set-cookie: exchangecookie=c57fcb68354247009304b295a890bd87; expires=Mon, 28-Oct-2013 09:51:16 GMT; path=/; HttpOnly

cache-control: private

server: Microsoft-IIS/7.5

content-type: text/xml; charset=utf-8

x-aspnet-version: 2.0.50727

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <----QMS::FINDITEM 201211

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG -->EWSCalendarInfo::processCalendarRequest: POST

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG -->SessionManager::setConnected: win-lhj39md2ssk:443 1

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--SessionManager::setConnected 0

09:50:28.104 |system.pe.pa.owa.backend 1894898 ERROR -->EWSCalendarInfo::initiateRecovery: 201211 POST 500 Internal Server Error

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--EWSCalendarInfo::clearTransition

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--EWSCalendarInfo::clearRefresh

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--EWSCalendarInfo::scheduleRefresh - refresh interval: 720

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--EWSCalendarInfo::initiateRecovery: POST

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--EWSCalendarInfo::processCalendarRequest

09:50:28.104 |system.pe.pa.owa.backend 1894898 DEBUG <--QMS::FINDITEM

09:50:29.049 |system.tcp 1826014 INFO Construct(1) TCP socket object [0x11864a84] to 1862314176 : 46234

09:50:29.049 |system.tcp 1826014 DEBUG Accepted connection from 1862314176 : 46234

09:50:29.058 |system.tcp 1825498 DEBUG Inserted socket 63 to 1862314176:46234 into the socketmap

09:50:29.058 |system.tcp 1825498 DEBUG Attached 1 new sockets

09:50:29.058 |system.tcp 1825498 DEBUG fireReadySocket got socket 63 in state 0, revents=1

09:50:29.058 |system.tcp 1825498 DEBUG Firing TCP or TLS Event for socket to 1862314176 : 46234! new state 2

09:50:29.058 |traffic.sip.receive 1828078 DEBUG TCP/TLSEventhandler got socket 63 in state 2, readState 0

I have noticed that just before my internal error, I get a CERTIFICATE_AUTHORITY_SIGNATURE_NOT_TRUSTED  error but the presence server the carries out furhter checks and says that it 'passed'. I am finding this a little strange as i am finding documentations that say that if the 'CA' bit is not listed in a certificate, then presnece server will not trust it.I am not a Microsoft Exchange expert but It looks like i am going to have to try to create some new certificates.

16:29:58.457 |system.pe 1800538 DEBUG --> threadStop() : 1843751840

16:29:58.457 |system.pe 1800538 DEBUG --> threadStop() return : 0

16:29:58.462 |system.pe.pa.owa.backend 1897998 DEBUG ExchangeSession::trustPeerCert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

                checking cache cert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

Found a matching trust cert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

16:29:58.462 |system.pe.pa.owa.backend 1897998 INFO ExchangeSession::verifySSL: received peer leaf: Certificate:  Identity: WIN-LHJ39MD2SSK Issuer: WIN-LHJ39MD2SSK Subject: WIN-LHJ39MD2SSK self-signed

0x110de7d0 ssl problem(s): CERTIFICATE_AUTHORITY_SIGNATURE_NOT_TRUSTED

                Doing further CA checks...checking self-signed or broken signer-chain cert

*** passed ***

16:29:58.462 |system.tcp 1826542 DEBUG Inserted socket 70 to 1862314176:5060 into the socketmap

16:29:58.462 |system.tcp 1826542 DEBUG Attached 1 new sockets

16:29:58.462 |system.tcp 1826542 DEBUG fireReadySocket got socket 70 in state 1, revents=1

16:29:58.462 |system.tcp 1826542 DEBUG Non-blocking connect completed successfully

16:29:58.462 |system.tcp 1826542 DEBUG CommonSocket::postConnectSetup called

16:29:58.463 |system.pe.pa.owa.backend 1899026 DEBUG ExchangeSession::trustPeerCert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

                checking cache cert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

Found a matching trust cert: Subject=WIN-LHJ39MD2SSK, Issuer=WIN-LHJ39MD2SSK

16:29:58.463 |system.pe.pa.owa.backend 1899026 INFO ExchangeSession::verifySSL: received peer leaf: Certificate:  Identity: WIN-LHJ39MD2SSK Issuer: WIN-LHJ39MD2SSK Subject: WIN-LHJ39MD2SSK self-signed

0x1111a900 ssl problem(s): CERTIFICATE_AUTHORITY_SIGNATURE_NOT_TRUSTED

                Doing further CA checks...checking self-signed or broken signer-chain cert

*** passed ***

16:29:58.464 |system.pe.pa.owa.backend 1896970 ERROR subscribe parser status -  ResponseClass:  ResponseCode:  Subscription ID:  Watermark:  body:

16:29:58.465 |system.pe.pa.owa.backend 1896970 INFO received SUBSCRIBE response for 201211: 500 Internal Server Error

HTTP/1.1 500 Internal Server Error

x-powered-by: ASP.NET

transfer-encoding: chunked

persistent-auth: true

date: Sun, 28 Oct 2012 16:30:47 GMT

set-cookie: exchangecookie=7868fa043f4944b09086e6f76840d1be; expires=Mon, 28-Oct-2013 16:30:47 GMT; path=/; HttpOnly

cache-control: private

server: Microsoft-IIS/7.5

content-type: text/xml; charset=utf-8

x-aspnet-version: 2.0.50727

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <----QMS::SUBSCRIBE 201211

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG -->SessionManager::setConnected: win-lhj39md2ssk:443 1

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--SessionManager::setConnected 1

16:29:58.465 |system.pe.oam 1896970 DEBUG generateFault: PECalendarConnectionLossCleared

16:29:58.465 |system.pe.oam 1896970 DEBUG generateFault: value - win-lhj39md2ssk:443

16:29:58.465 |debug.oam.fault.faultservice 1896970 INFO faultnotification: constructing notification : PECalendarConnectionLossCleared

16:29:58.465 |system.oam.faults 1896970 DEBUG  CCMFaultModule::notify: Alarm name = PECalendarConnectionLossCleared

16:29:58.465 |system.oam.faults 1896970 DEBUG  CCMFaultModule::notify: param 1 = PEAlarmMessage : win-lhj39md2ssk:443

16:29:58.465 |system.oam.faults 1896970 DEBUG  CCMFaultModule::notify: retval= 0

16:29:58.465 |debug.oam.fault.faultservice 1896970 INFO faultnotification: destructing notification : PECalendarConnectionLossCleared

16:29:58.465 |system.pe.pa.owa.backend 1896970 ERROR -->EWSSubscription::initiateRecovery: 201211 POST 500 Internal Server Error

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--EWSSubscription::clearResubscribe

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--EWSSubscription::scheduleResubscribe - interval (secs): 720

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--EWSSubscription::initiateRecovery: POST

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--EWSSubscription::processSubscribeRequest

16:29:58.465 |system.pe.pa.owa.backend 1896970 DEBUG <--QMS::SUBSCRIBE

16:29:58.466 |system.tcp 1826542 DEBUG fireReadySocket got socket 70 in state 0, revents=1

16:29:58.466 |system.tcp 1826542 DEBUG Firing TCP or TLS Event for socket to 1862314176 : 5060! new state 2

16:29:58.466 |traffic.sip.receive 1828606 DEBUG TCP/TLSEventhandler got socket 70 in state 2, readState 0

Did you ever get this resolved?  I am having the same issue.

Thanks,

Joe

Hi,

This was actually in my home lab so I was more or less just playing with it whenever I felt like.  In the logs above there is a hint that my problem was due to the certificates that I was using.

Based on this, I looked at the various areas that can cause certificates to fail

  • •1)      In my lab, I was using a self-signed certificate that was generated automatically  whilst i was installing exchange 2010 on my server 2008. When I check the certificate, the ‘CA’ bit was not marked. Cups would refuse to trust such certificates. May ways are out there to resolve this issue like using ‘ Makecert’ or getting a proper certificate from a CA.  My plan is to use a  Microsoft Root CA to generate all my certs in the lab.  To achieve this will do the following. 
    • •i)                    Install certificate service as listed in the link below:

http://www.vircom.com/security/how-to-create-a-self-signed-ssl-certificate-for-exchange-200320072010-on-windows-server/

note:    you only need to use section 4 to section 9 of this doc

  • •2)      Now that you have your certificate sever installed, you need to generate a certificate request from your exchange.  

Note: my version of presence does not support certificates with the SAN  bit marked. i.e Subject Alternative Name.  So when creating the certificate request from Exchange Gui and I’m  prompted to add multiple names in the request, I will only ask for one name or common name. (i’m no Microsoft expert). You can use the link below to find out how to make the request.

http://www.youtube.com/watch?v=GD0Ro0etUPQ

so now you have installed a working cert on the outlook web app you should now browse to the website of you Microsoft certificate server and grab it’s  own CA certificate or root certificate and install it on your presence sever.

I also found this really good documentation on this topic by cisco

http://www.cisco.com/en/US/docs/voice_ip_comm/cups/8_0/english/integration_notes/exchange/guide/exch0710.html#wp1068907

Hope this helps. I will jump on my lab soon and actually ‘do as I say’ and let you know if it help me lol.

Cheers

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: