10-27-2012 11:08 AM - edited 03-16-2019 01:54 PM
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.
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
10-28-2012 02:44 AM
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
10-28-2012 03:13 AM
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
10-28-2012 10:16 AM
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
11-15-2012 09:04 AM
Did you ever get this resolved? I am having the same issue.
Thanks,
Joe
11-17-2012 03:29 AM
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
note: you only need to use section 4 to section 9 of this doc
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
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
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: