RajaneeshJM
Programmer
Hi,
I have installed the Content Server Directory Services module to configure Content Server 10 SP2 Update 11 for external authentication.
In our environment we are using Microsoft ADS. For synchronization LDAP Read option has been set, and we are able to synchronize few of the users successfully.
On entering the valid credentials for one of the user in Domain\username [NTWORLD2\00001023] format with a valid Password, authentication is not successful. The message "Invalid username/password specified" is displayed.
Request you to help us analyze the issue. Listed below is the extract from one of the Connect log identified when Debug has been set to 2 with WantLogs as TRUE in opentext.ini
09/19/2014 17:55:28 INFO ..
09/19/2014 17:55:28 INFO [2516147191] 0000000480: --start of log------------------------
09/19/2014 17:58:31 INFO ..
09/19/2014 17:58:31 INFO [2699505976] 0000012289: CAPI.Log: AUTH_TYPE = ''
09/19/2014 17:58:31 INFO [2699506142] 0000012290: CAPI.Log: CONTENT_LENGTH = '169'
09/19/2014 17:58:31 INFO [2699506298] 0000012291: CAPI.Log: CONTENT_TYPE = 'application/x-09/19/2014 17:58:31 INFO [2699506478] 0000012292: CAPI.Log: CurrentClientTime = 'D/2014/9/19:17:56:34'
09/19/2014 17:58:31 INFO [2699506630] 0000012293: CAPI.Log: func = 'll.login'
09/19/2014 17:58:31 INFO [2699506785] 0000012294: CAPI.Log: GATEWAY_INTERFACE = 'CGI/1.1'
09/19/2014 17:58:31 INFO [2699506936] 0000012295: CAPI.Log: HTTPS = 'off'
09/19/2014 17:58:31 INFO [2699507156] 0000012296: CAPI.Log: HTTPS_KEYSIZE = ''
09/19/2014 17:58:31 INFO [2699507300] 0000012297: CAPI.Log: HTTPS_SECRETKEYSIZE = ''
09/19/2014 17:58:31 INFO [2699507441] 0000012298: CAPI.Log: HTTPS_SERVER_ISSUER = ''
09/19/2014 17:58:31 INFO [2699507591] 0000012299: CAPI.Log: HTTPS_SERVER_SUBJECT = ''
09/19/2014 17:58:31 INFO [2699507737] 0000012300: CAPI.Log: HTTP_ACCEPT = 'application/x-ms-application, image/jpeg, application/xaml+xml, image/gif, image/pjpeg, application/x-ms-xbap, */*'
09/19/2014 17:58:31 INFO [2699507883] 0000012301: CAPI.Log: HTTP_ACCEPT_ENCODING = 'gzip, deflate'
09/19/2014 17:58:31 INFO [2699508025] 0000012302: CAPI.Log: HTTP_ACCEPT_LANGUAGE = 'en-US'
09/19/2014 17:58:31 INFO [2699508166] 0000012303: CAPI.Log: HTTP_CACHE_CONTROL = 'no-cache'
09/19/2014 17:58:31 INFO [2699508305] 0000012304: CAPI.Log: HTTP_CONNECTION = 'Keep-Alive'
09/19/2014 17:58:31 INFO [2699508461] 0000012305: CAPI.Log: HTTP_CONTENT_LENGTH = '169'
09/19/2014 17:58:31 INFO [2699508603] 0000012306: CAPI.Log: HTTP_CONTENT_TYPE = 'application/x-09/19/2014 17:58:31 INFO [2699508775] 0000012307: CAPI.Log: HTTP_COOKIE = 'LLCookie=lBdBugrUvjxlUL3hd6gDrBPtV7plsgtUBXgfVEc%2FHMLX7rRQcxmm5yNNfnfUOg8MJx9GGatveWtypQTCrZTo%2BA%3D%3D; LLTZCookie=0; BrowseSettings=e7rkWUcn9qASnLwoY6lumAiTa7hP8TbDaLCs%2BcnwD9o%3D; AdminPwd=dQCRTdaK6V2nxOLwEP7ImkYEJUk6qbxqUsWc1WtTy1BM8RIsilrYPJTgsClRDlms; adminStyle=all'
09/19/2014 17:58:31 INFO [2699508928] 0000012308: CAPI.Log: HTTP_DNT = '1'
09/19/2014 17:58:31 INFO [2699509071] 0000012309: CAPI.Log: HTTP_HOST = 'vmesx22s40'
09/19/2014 17:58:31 INFO [2699509214] 0000012310: CAPI.Log: HTTP_REFERER = '09/19/2014 17:58:31 INFO [2699509368] 0000012311: CAPI.Log: HTTP_USER_AGENT = 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64; Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; .NET4.0E)'
09/19/2014 17:58:31 INFO [2699509571] 0000012312: CAPI.Log: NextURL = '/OTCS/livelink.exe?func=Enterprise.Home'
09/19/2014 17:58:31 INFO [2699509751] 0000012313: CAPI.Log: Password = 'XXXXXXXXXX'
09/19/2014 17:58:31 INFO [2699509960] 0000012314: CAPI.Log: PATH_INFO = ''
09/19/2014 17:58:31 INFO [2699510174] 0000012315: CAPI.Log: PATH_TRANSLATED = 'C:\inetpub\09/19/2014 17:58:31 INFO [2699510399] 0000012316: CAPI.Log: QUERY_STRING = ''
09/19/2014 17:58:31 INFO [2699510613] 0000012317: CAPI.Log: REMOTE_ADDR = '192.168.105.101'
09/19/2014 17:58:31 INFO [2699510811] 0000012318: CAPI.Log: REMOTE_HOST = '192.168.105.101'
09/19/2014 17:58:31 INFO [2699511029] 0000012319: CAPI.Log: REMOTE_USER = ''
09/19/2014 17:58:31 INFO [2699511244] 0000012320: CAPI.Log: REQUEST_METHOD = 'POST'
09/19/2014 17:58:31 INFO [2699511478] 0000012321: CAPI.Log: REQUEST_PROCESSING_DURATION = '0'
09/19/2014 17:58:31 INFO [2699511679] 0000012322: CAPI.Log: SCRIPT_NAME = '/OTCS/livelink.exe'
09/19/2014 17:58:31 INFO [2699511823] 0000012323: CAPI.Log: SERVER_NAME = 'vmesx22s40'
09/19/2014 17:58:31 INFO [2699511960] 0000012324: CAPI.Log: SERVER_PORT = '80'
09/19/2014 17:58:31 INFO [2699512098] 0000012325: CAPI.Log: SERVER_PROTOCOL = 'HTTP/1.1'
09/19/2014 17:58:31 INFO [2699512277] 0000012326: CAPI.Log: SERVER_SOFTWARE = 'Microsoft-IIS/7.5'
09/19/2014 17:58:31 INFO [2699512423] 0000012327: CAPI.Log: Username = 'ntworld2\00001023'
09/19/2014 17:58:31 INFO [2699512586] 0000012328: CAPI.Log: _REQUEST = 'llweb'
09/19/2014 17:58:31 INFO [2699521079] 0000012329: ****** CAPIAllocConnect called ...
09/19/2014 17:58:31 INFO [2699523347] 0000012330: KSqlOCI10::SubclassConnect() before OCIServerAttach
09/19/2014 17:58:31 INFO [2699558822] 0000012331: KSqlOCI10::SubclassConnect() before OCISessionBegin
09/19/2014 17:58:31 INFO [2699574113] 0000012332: KSqlOCI10::SubclassConnect() connect success. Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
09/19/2014 17:58:31 INFO [2699574214] 0000012333: KSqlOCI10::SubclassConnect() statement cache size set to: 0
09/19/2014 17:58:31 INFO [2699574307] 0000012334: KSql::Connect('local_orcl','LLFrontier','ADMIN','*','APIEngine','API100') --> 'SUCCESS',[sec: 0 msec: 50]
09/19/2014 17:58:31 INFO [2699574375] 0000012335: KSql::Connect .. ConnectionType = ORACLE
09/19/2014 17:58:31 INFO [2699574431] 0000012336: KSql::Connect .. DatabaseType = ORACLE7
09/19/2014 17:58:31 INFO [2699574489] 0000012337: KSql::Connect .. MaxLength = 4000
09/19/2014 17:58:31 INFO [2699574545] 0000012338: KSql::Connect .. MaxLongLength = 32767
09/19/2014 17:58:31 INFO [2699574599] 0000012339: KSql::Connect .. SubQueryBlobs = FALSE
09/19/2014 17:58:31 INFO [2699574890] 0000012340: KConnect::Connect(...) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699574967] 0000012341: KConnect::AllocConnect() .. allocate new connection.
09/19/2014 17:58:31 INFO [2699575322] 0000012342: ****** CAPIExec called ...
09/19/2014 17:58:31 INFO [2699576021] 0000012343: KSqlCursor::Open(201f,'select * from KIni where IniSection = 'Livelink.VersionInfo' and IniKeyword = 'DatabaseVersion'') -->'SUCCESS'
09/19/2014 17:58:31 INFO [2699576117] 0000012344: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699576186] 0000012345: KSqlCursor::Bind(0,{}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699576657] 0000012346: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577214] 0000012347: KSqlCursor::Fetch({'Livelink.VersionInfo','DatabaseVersion','{6,1,3}'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577589] 0000012348: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577728] 0000012349: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:31 INFO [2699577912] 0000012350: ****** CAPIAllocLogin called ...
09/19/2014 17:58:31 INFO [2699579012] 0000012351: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:31 INFO [2699579097] 0000012352: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699579209] 0000012353: KSqlCursor::Bind(3,{0,0,'Admin'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580067] 0000012354: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580227] 0000012355: KSqlCursor::Fetch({1000,1000,0,0,'Admin',?,?,0,'xxxxxx',1001,16777215,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,1000,1,'DefaultGroup',?}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580615] 0000012356: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580805] 0000012357: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699580937] 0000012358: KUAFUser::Get(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699581621] 0000012359: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699581701] 0000012360: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699581782] 0000012361: KSqlCursor::Bind(1,{2}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582307] 0000012362: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582414] 0000012363: KSqlCursor::Fetch({2,304,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582502] 0000012364: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582600] 0000012365: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699583117] 0000012366: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699583196] 0000012367: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583276] 0000012368: KSqlCursor::Bind(1,{3}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583836] 0000012369: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583943] 0000012370: KSqlCursor::Fetch({3,35902,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584030] 0000012371: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584128] 0000012372: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699584765] 0000012373: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699584845] 0000012374: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584926] 0000012375: KSqlCursor::Bind(1,{4}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585527] 0000012376: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585634] 0000012377: KSqlCursor::Fetch({4,2,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585722] 0000012378: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585827] 0000012379: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699585906] 0000012380: ****** CAPIExec called ...
09/19/2014 17:58:32 INFO [2699586820] 0000012381: KSqlCursor::Open(201f,'select sl.LanguageCode, sl.LanguageName, sl.LanguageNameLocal, ml.Enabled from SystemLanguages sl, MetadataLanguages ml where sl.LanguageCode = ml.LanguageCode') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699586904] 0000012382: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699586971] 0000012383: KSqlCursor::Bind(0,{}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699587942] 0000012384: KSqlCursor::Execute({'LANGUAGECODE','LANGUAGENAME','LANGUAGENAMELOCAL','ENABLED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588056] 0000012385: KSqlCursor::Fetch({'en','English','English',1}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588445] 0000012386: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588572] 0000012387: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699589097] 0000012388: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699589176] 0000012389: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589257] 0000012390: KSqlCursor::Bind(1,{1}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589812] 0000012391: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589919] 0000012392: KSqlCursor::Fetch({1,5,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590006] 0000012393: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590106] 0000012394: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699590619] 0000012395: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699590717] 0000012396: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590833] 0000012397: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591396] 0000012398: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591517] 0000012399: KSqlCursor::Fetch({1000,0,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591610] 0000012400: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591709] 0000012401: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699592560] 0000012402: KSqlCursor::Open(20ff,'select a.ID,a.OwnerID,a.Type,a.SpaceID,a.Name,a.LeaderID,a.UserPrivileges from KUAF a where a.ID in (select distinct b.ID from KUAFChildren b start with b.ChildID=:A1 connect by nocycle prior b.ID=b.ChildID)') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699592676] 0000012403: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699592790] 0000012404: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699594496] 0000012405: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','LEADERID','USERPRIVILEGES'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699594615] 0000012406: KSqlCursor::Fetch({1001,1000,1,0,'DefaultGroup',?,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595162] 0000012407: KSqlOCI10Cursor: multi-fetched 3 rows
09/19/2014 17:58:32 INFO [2699595270] 0000012408: KSqlCursor::Fetch({5966,5964,5963,0,'Guests',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595365] 0000012409: KSqlCursor::Fetch({5964,5964,5963,0,'Coordinators',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595456] 0000012410: KSqlCursor::Fetch({5965,5964,5963,0,'Members',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595553] 0000012411: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595668] 0000012412: KSql::Execute(...) --> 'SUCCESS',4 records,[sec: 0 msec: 3]
09/19/2014 17:58:32 INFO [2699596307] 0000012413: KSqlCursor::Open(2000,'select ID,OwnerID,Type,SpaceID,Name,LeaderID,UserPrivileges from KUAF where ID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699596388] 0000012414: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699596559] 0000012415: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597113] 0000012416: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','LEADERID','USERPRIVILEGES'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597227] 0000012417: KSqlCursor::Fetch({1000,1000,0,0,'Admin',?,16777215}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597510] 0000012418: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597627] 0000012419: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699597709] 0000012420: KUAF::RightsListByID(1000) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699598394] 0000012421: KSqlCursor::Open(2000,'select distinct ProxyType from KUAFProxy where ProxyID=:A1 order by ProxyType') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699598477] 0000012422: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699598560] 0000012423: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599044] 0000012424: KSqlCursor::Execute({'PROXYTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599138] 0000012425: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599246] 0000012426: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699599317] 0000012427: KLogin::ReloadUserRightsList(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599379] 0000012428: KLogin::Login(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599441] 0000012429: KLogin::AllocLogin() .. allocate new login.
09/19/2014 17:58:32 INFO [2699600901] 0000012430: ****** CAPIIniList( Module.VersionInfo ) called ...
09/19/2014 17:58:32 INFO [2699601559] 0000012431: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699601695] 0000012432: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699601792] 0000012433: KSqlCursor::Bind(1,{'Module.VersionInfo'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699602478] 0000012434: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699603009] 0000012435: KSqlCursor::Fetch({'Module.VersionInfo','Classification','{1,0,10}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699603716] 0000012436: KSqlCursor::Fetch({'Module.VersionInfo','PhysicalObjects','{5,5,2}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699604440] 0000012437: KSqlCursor::Fetch({'Module.VersionInfo','RecMan','{5,5,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699605147] 0000012438: KSqlCursor::Fetch({'Module.VersionInfo','WebSystemObj','{8,0,46}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699605910] 0000012439: KSqlCursor::Fetch({'Module.VersionInfo','appearances','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699606604] 0000012440: KSqlCursor::Fetch({'Module.VersionInfo','bestbets','{1,1,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699607295] 0000012441: KSqlCursor::Fetch({'Module.VersionInfo','collections','{1,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699608220] 0000012442: KSqlCursor::Fetch({'Module.VersionInfo','dc','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699608963] 0000012443: KSqlCursor::Fetch({'Module.VersionInfo','directory','{1,0,2}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699609692] 0000012444: KSqlCursor::Fetch({'Module.VersionInfo','distributedagent','{1,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699610380] 0000012445: KSqlCursor::Fetch({'Module.VersionInfo','indexobject','{1,0,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699611112] 0000012446: KSqlCursor::Fetch({'Module.VersionInfo','itemtemplate','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699611861] 0000012447: KSqlCursor::Fetch({'Module.VersionInfo','multifile','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699612962] 0000012448: KSqlCursor::Fetch({'Module.VersionInfo','polling','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699613750] 0000012449: KSqlCursor::Fetch({'Module.VersionInfo','pstage','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699614486] 0000012450: KSqlCursor::Fetch({'Module.VersionInfo','recommender','{1,1,11}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699615275] 0000012451: KSqlCursor::Fetch({'Module.VersionInfo','report','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699615973] 0000012452: KSqlCursor::Fetch({'Module.VersionInfo','searchstats','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699616661] 0000012453: KSqlCursor::Fetch({'Module.VersionInfo','storageprovider','{1,1,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699617350] 0000012454: KSqlCursor::Fetch({'Module.VersionInfo','undelete','{1,0,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699618041] 0000012455: KSqlCursor::Fetch({'Module.VersionInfo','webprospector','{4,0,5}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699618729] 0000012456: KSqlCursor::Fetch({'Module.VersionInfo','websovmgmt','{8,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699619417] 0000012457: KSqlCursor::Fetch({'Module.VersionInfo','webwork','{8,0,9}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620125] 0000012458: KSqlCursor::Fetch({'Module.VersionInfo','xmlsearch','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620449] 0000012459: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620568] 0000012460: KSql::Execute(...) --> 'SUCCESS',24 records,[sec: 0 msec: 19]
09/19/2014 17:58:32 INFO [2699625586] 0000012461: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699625668] 0000012462: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699625758] 0000012463: KSqlCursor::Bind(2,{'StorageProviderConfigCache','ConfigCache.Version'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699626234] 0000012464: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699626730] 0000012465: KSqlCursor::Fetch({'6939215'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699627022] 0000012466: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699627137] 0000012467: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699627226] 0000012468: ****** CAPIIniGet( StorageProviderConfigCache, ConfigCache.Version ) returned 6939215
09/19/2014 17:58:32 INFO [2699627776] 0000012469: ****** CAPIIniList( Livelink.LogicalProviders ) called ...
09/19/2014 17:58:32 INFO [2699628274] 0000012470: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699628354] 0000012471: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699628439] 0000012472: KSqlCursor::Bind(1,{'Livelink.LogicalProviders'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699628964] 0000012473: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629471] 0000012474: KSqlCursor::Fetch({'Livelink.LogicalProviders','Default','{\'SQL\',\'\'}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629824] 0000012475: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629941] 0000012476: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699630683] 0000012477: ****** CAPIIniList( Livelink.LogicalProviderRules ) called ...
09/19/2014 17:58:32 INFO [2699631245] 0000012478: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699631325] 0000012479: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699631418] 0000012480: KSqlCursor::Bind(1,{'Livelink.LogicalProviderRules'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699631949] 0000012481: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632449] 0000012482: KSqlCursor::Fetch({'Livelink.LogicalProviderRules','9999','{\'Default\',6,?}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632773] 0000012483: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632890] 0000012484: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699635376] 0000012485: ****** CAPIUserInfo returned R<'ID'=1000,...>
09/19/2014 17:58:32 INFO [2699635493] 0000012486: ****** CAPIUserID returned 1000
09/19/2014 17:58:32 INFO [2699635591] 0000012487: ****** DAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699636143] 0000012488: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699636223] 0000012489: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699636309] 0000012490: KSqlCursor::Bind(1,{'DTREECORE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699637664] 0000012491: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699637766] 0000012492: KSqlCursor::Fetch({'OWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638073] 0000012493: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699638165] 0000012494: KSqlCursor::Fetch({'PARENTID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638247] 0000012495: KSqlCursor::Fetch({'DATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638326] 0000012496: KSqlCursor::Fetch({'NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638421] 0000012497: KSqlCursor::Fetch({'ORIGINOWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638503] 0000012498: KSqlCursor::Fetch({'ORIGINDATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638581] 0000012499: KSqlCursor::Fetch({'USERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638659] 0000012500: KSqlCursor::Fetch({'GROUPID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638758] 0000012501: KSqlCursor::Fetch({'UPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638844] 0000012502: KSqlCursor::Fetch({'GPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638925] 0000012503: KSqlCursor::Fetch({'WPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639003] 0000012504: KSqlCursor::Fetch({'SPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639082] 0000012505: KSqlCursor::Fetch({'ACLCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639160] 0000012506: KSqlCursor::Fetch({'PERMID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639239] 0000012507: KSqlCursor::Fetch({'DATATYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639317] 0000012508: KSqlCursor::Fetch({'CREATEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639403] 0000012509: KSqlCursor::Fetch({'CREATEDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639497] 0000012510: KSqlCursor::Fetch({'MODIFIEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639580] 0000012511: KSqlCursor::Fetch({'MODIFYDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639659] 0000012512: KSqlCursor::Fetch({'MAXVERS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639742] 0000012513: KSqlCursor::Fetch({'RESERVED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639823] 0000012514: KSqlCursor::Fetch({'RESERVEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640157] 0000012515: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699640249] 0000012516: KSqlCursor::Fetch({'RESERVEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640330] 0000012517: KSqlCursor::Fetch({'VERSIONNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640409] 0000012518: KSqlCursor::Fetch({'DCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640487] 0000012519: KSqlCursor::Fetch({'DCATEGORY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640565] 0000012520: KSqlCursor::Fetch({'SUBTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640642] 0000012521: KSqlCursor::Fetch({'EXATT1'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640719] 0000012522: KSqlCursor::Fetch({'EXATT2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640801] 0000012523: KSqlCursor::Fetch({'ORDERING'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640879] 0000012524: KSqlCursor::Fetch({'MAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640957] 0000012525: KSqlCursor::Fetch({'MINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641036] 0000012526: KSqlCursor::Fetch({'RELEASEREF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641113] 0000012527: KSqlCursor::Fetch({'CHILDCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641192] 0000012528: KSqlCursor::Fetch({'ASSIGNEDTO'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641270] 0000012529: KSqlCursor::Fetch({'DATEASSIGNED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641349] 0000012530: KSqlCursor::Fetch({'DATEEFFECTIVE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641427] 0000012531: KSqlCursor::Fetch({'DATEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641534] 0000012532: KSqlCursor::Fetch({'DATEDUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641640] 0000012533: KSqlCursor::Fetch({'DATESTARTED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641728] 0000012534: KSqlCursor::Fetch({'DATECOMPLETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641831] 0000012535: KSqlCursor::Fetch({'STATUS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641928] 0000012536: KSqlCursor::Fetch({'PRIORITY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642351] 0000012537: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699642446] 0000012538: KSqlCursor::Fetch({'GIF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642528] 0000012539: KSqlCursor::Fetch({'EXTENDEDDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642607] 0000012540: KSqlCursor::Fetch({'CATALOG'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642687] 0000012541: KSqlCursor::Fetch({'CACHEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642765] 0000012542: KSqlCursor::Fetch({'DELETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642847] 0000012543: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642925] 0000012544: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699643023] 0000012545: KSql::Execute(...) --> 'SUCCESS',49 records,[sec: 0 msec: 7]
09/19/2014 17:58:32 INFO [2699643689] 0000012546: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699643770] 0000012547: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699643855] 0000012548: KSqlCursor::Bind(1,{'DTREE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699644940] 0000012549: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645042] 0000012550: KSqlCursor::Fetch({'OWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645415] 0000012551: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699645517] 0000012552: KSqlCursor::Fetch({'PARENTID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645600] 0000012553: KSqlCursor::Fetch({'DATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645680] 0000012554: KSqlCursor::Fetch({'NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645760] 0000012555: KSqlCursor::Fetch({'ORIGINOWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645840] 0000012556: KSqlCursor::Fetch({'ORIGINDATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645918] 0000012557: KSqlCursor::Fetch({'USERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646015] 0000012558: KSqlCursor::Fetch({'GROUPID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646113] 0000012559: KSqlCursor::Fetch({'UPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646193] 0000012560: KSqlCursor::Fetch({'GPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646273] 0000012561: KSqlCursor::Fetch({'WPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646352] 0000012562: KSqlCursor::Fetch({'SPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646430] 0000012563: KSqlCursor::Fetch({'ACLCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646508] 0000012564: KSqlCursor::Fetch({'PERMID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646587] 0000012565: KSqlCursor::Fetch({'DATATYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646666] 0000012566: KSqlCursor::Fetch({'CREATEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646745] 0000012567: KSqlCursor::Fetch({'CREATEDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646823] 0000012568: KSqlCursor::Fetch({'MODIFIEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646901] 0000012569: KSqlCursor::Fetch({'MODIFYDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646979] 0000012570: KSqlCursor::Fetch({'MAXVERS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647062] 0000012571: KSqlCursor::Fetch({'RESERVED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647142] 0000012572: KSqlCursor::Fetch({'RESERVEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647481] 0000012573: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699647574] 0000012574: KSqlCursor::Fetch({'RESERVEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647656] 0000012575: KSqlCursor::Fetch({'VERSIONNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647735] 0000012576: KSqlCursor::Fetch({'DCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647813] 0000012577: KSqlCursor::Fetch({'DCATEGORY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647891] 0000012578: KSqlCursor::Fetch({'SUBTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647969] 0000012579: KSqlCursor::Fetch({'EXATT1'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648047] 0000012580: KSqlCursor::Fetch({'EXATT2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648127] 0000012581: KSqlCursor::Fetch({'ORDERING'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648207] 0000012582: KSqlCursor::Fetch({'MAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648285] 0000012583: KSqlCursor::Fetch({'MINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648417] 0000012584: KSqlCursor::Fetch({'RELEASEREF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648505] 0000012585: KSqlCursor::Fetch({'CHILDCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648585] 0000012586: KSqlCursor::Fetch({'ASSIGNEDTO'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648663] 0000012587: KSqlCursor::Fetch({'DATEASSIGNED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648742] 0000012588: KSqlCursor::Fetch({'DATEEFFECTIVE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648821] 0000012589: KSqlCursor::Fetch({'DATEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648899] 0000012590: KSqlCursor::Fetch({'DATEDUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648978] 0000012591: KSqlCursor::Fetch({'DATESTARTED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649056] 0000012592: KSqlCursor::Fetch({'DATECOMPLETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649134] 0000012593: KSqlCursor::Fetch({'STATUS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649213] 0000012594: KSqlCursor::Fetch({'PRIORITY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649575] 0000012595: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699649667] 0000012596: KSqlCursor::Fetch({'GIF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649748] 0000012597: KSqlCursor::Fetch({'EXTENDEDDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649828] 0000012598: KSqlCursor::Fetch({'CATALOG'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649908] 0000012599: KSqlCursor::Fetch({'CACHEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649987] 0000012600: KSqlCursor::Fetch({'DELETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650065] 0000012601: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650139] 0000012602: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650235] 0000012603: KSql::Execute(...) --> 'SUCCESS',49 records,[sec: 0 msec: 7]
09/19/2014 17:58:32 INFO [2699652151] 0000012604: The following columns in DTreeCore have default values and will not be inserted: GUID
09/19/2014 17:58:32 INFO [2699652907] 0000012605: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699652987] 0000012606: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699653071] 0000012607: KSqlCursor::Bind(1,{'DVERSDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654158] 0000012608: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654260] 0000012609: KSqlCursor::Fetch({'VERSIONID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654624] 0000012610: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699654716] 0000012611: KSqlCursor::Fetch({'DOCID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654797] 0000012612: KSqlCursor::Fetch({'VERSION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654876] 0000012613: KSqlCursor::Fetch({'VERSIONNAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654955] 0000012614: KSqlCursor::Fetch({'OWNER'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655034] 0000012615: KSqlCursor::Fetch({'VERCDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655113] 0000012616: KSqlCursor::Fetch({'VERMDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655192] 0000012617: KSqlCursor::Fetch({'PLATFORM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655270] 0000012618: KSqlCursor::Fetch({'FILENAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655348] 0000012619: KSqlCursor::Fetch({'DATASIZE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655427] 0000012620: KSqlCursor::Fetch({'RESSIZE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655539] 0000012621: KSqlCursor::Fetch({'FILETYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655624] 0000012622: KSqlCursor::Fetch({'FILECREATOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655703] 0000012623: KSqlCursor::Fetch({'FILECDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655787] 0000012624: KSqlCursor::Fetch({'FILEMDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655870] 0000012625: KSqlCursor::Fetch({'ICON'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655949] 0000012626: KSqlCursor::Fetch({'PROVIDERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656028] 0000012627: KSqlCursor::Fetch({'VERCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656106] 0000012628: KSqlCursor::Fetch({'LOCKED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656185] 0000012629: KSqlCursor::Fetch({'LOCKEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656264] 0000012630: KSqlCursor::Fetch({'LOCKEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656343] 0000012631: KSqlCursor::Fetch({'INDEXED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656774] 0000012632: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699656872] 0000012633: KSqlCursor::Fetch({'FINDERFLAGS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656956] 0000012634: KSqlCursor::Fetch({'MIMETYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657035] 0000012635: KSqlCursor::Fetch({'VERTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657113] 0000012636: KSqlCursor::Fetch({'VERMAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657192] 0000012637: KSqlCursor::Fetch({'VERMINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657271] 0000012638: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657345] 0000012639: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657442] 0000012640: KSql::Execute(...) --> 'SUCCESS',28 records,[sec: 0 msec: 4]
09/19/2014 17:58:32 INFO [2699658262] 0000012641: The following columns in DVersData have default values and will not be inserted: GUID
09/19/2014 17:58:32 INFO [2699658576] 0000012642: ****** DAPISetCallback called ...
09/19/2014 17:58:32 INFO [2699658656] 0000012643: KSession::SetCallback(000007FEF6776C50,0) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699658713] 0000012644: ****** DAPISetScriptCallback called ...
09/19/2014 17:58:32 INFO [2699659886] 0000012645: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699659974] 0000012646: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699660331] 0000012647: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699660413] 0000012648: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699660764] 0000012649: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699660843] 0000012650: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699661536] 0000012651: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699661625] 0000012652: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699661742] 0000012653: KSqlCursor::Bind(2,{'Livelink.DocStorage','Default'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662297] 0000012654: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662393] 0000012655: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662494] 0000012656: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699662574] 0000012657: ****** CAPIIniGet( Livelink.DocStorage, Default ) returned ?
09/19/2014 17:58:32 INFO [2699662672] 0000012658: ****** CAPIIniGet( Livelink.LogicalProviders, Default ) returned {'SQL',''}
09/19/2014 17:58:32 INFO [2699662768] 0000012659: ****** DAPISetDefaultProvider called ...
09/19/2014 17:58:32 INFO [2699663700] 0000012660: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699663780] 0000012661: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699663868] 0000012662: KSqlCursor::Bind(2,{'RecMan','settingsMask'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699664333] 0000012663: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699664859] 0000012664: KSqlCursor::Fetch({'44544'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699665177] 0000012665: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699665293] 0000012666: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699665380] 0000012667: ****** CAPIIniGet( RecMan, settingsMask ) returned 44544
09/19/2014 17:58:32 INFO [2699665896] 0000012668: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699665976] 0000012669: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699666062] 0000012670: KSqlCursor::Bind(2,{'RecMan','settingsMask2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699666527] 0000012671: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667075] 0000012672: KSqlCursor::Fetch({'134217728'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667374] 0000012673: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667503] 0000012674: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699667591] 0000012675: ****** CAPIIniGet( RecMan, settingsMask2 ) returned 134217728
09/19/2014 17:58:32 INFO [2699669215] 0000012676: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699669298] 0000012677: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699669386] 0000012678: KSqlCursor::Bind(2,{'RecMan','secureDelete'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699669918] 0000012679: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699670015] 0000012680: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699670117] 0000012681: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699670196] 0000012682: ****** CAPIIniGet( RecMan, secureDelete ) returned false
09/19/2014 17:58:32 INFO [2699671168] 0000012683: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699671249] 0000012684: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671337] 0000012685: KSqlCursor::Bind(2,{'OTDSIntegration','Settings'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671875] 0000012686: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671971] 0000012687: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699672072] 0000012688: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699672161] 0000012689: ****** CAPIIniGet( OTDSIntegration, Settings ) returned ?
09/19/2014 17:58:32 INFO [2699673836] 0000012690: ****** CAPIAllocConnect called ...
09/19/2014 17:58:32 INFO [2699673919] 0000012691: KConnect::AllocConnect() .. reusing existing connection.
09/19/2014 17:58:32 INFO [2699674053] 0000012692: ****** CAPIAllocLogin called ...
09/19/2014 17:58:32 INFO [2699675128] 0000012693: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699675226] 0000012694: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699675328] 0000012695: KSqlCursor::Bind(3,{0,0,'ntworld2\\00001023'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676051] 0000012696: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676197] 0000012697: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676338] 0000012698: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 2]
09/19/2014 17:58:32 ERROR [2699684173] 0000012699: KConnect::ErrLog --> [10106,5],'Invalid username/password specified.'
09/19/2014 17:58:32 ERROR [2699684272] 0000012700: KUAFUser::Get(ntworld2\00001023) --> 'Invalid username/password specified.'
09/19/2014 17:58:32 INFO [2699685711] 0000012701: ****** CAPIAllocConnect called ...
09/19/2014 17:58:32 INFO [2699685791] 0000012702: KConnect::AllocConnect() .. reusing existing connection.
09/19/2014 17:58:32 INFO [2699685920] 0000012703: ****** CAPIAllocLogin called ...
09/19/2014 17:58:32 INFO [2699686805] 0000012704: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699686889] 0000012705: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699686987] 0000012706: KSqlCursor::Bind(3,{0,0,'ntworld2\\00001023'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687738] 0000012707: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687852] 0000012708: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687981] 0000012709: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 ERROR [2699688074] 0000012710: KConnect::ErrLog --> [10106,5],'Invalid username/password specified.'
09/19/2014 17:58:32 ERROR [2699688150] 0000012711: KUAFUser::Get(ntworld2\00001023) --> 'Invalid username/password specified.'
09/19/2014 17:58:32 INFO [2699937233] 0000012712: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699937352] 0000012713: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699937444] 0000012714: KSqlCursor::Bind(2,{'BaseHref','Protocol'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938174] 0000012715: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938270] 0000012716: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938375] 0000012717: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699938461] 0000012718: ****** CAPIIniGet( BaseHref, Protocol ) returned ?
09/19/2014 17:58:32 INFO [2699938928] 0000012719: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699939007] 0000012720: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939093] 0000012721: KSqlCursor::Bind(2,{'BaseHref','LookForHost'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939549] 0000012722: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939643] 0000012723: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939744] 0000012724: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699939820] 0000012725: ****** CAPIIniGet( BaseHref, LookForHost ) returned ?
09/19/2014 17:58:32 INFO [2699954171] 0000012726: ****** CAPIUserInfo returned R<'ID'=1000,...>
09/19/2014 17:58:32 INFO [2699954273] 0000012727: ****** CAPIUserID returned 1000
09/19/2014 17:58:32 INFO [2699954371] 0000012728: ****** UAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699954563] 0000012729: ****** UAPIPrefsGet called ...
09/19/2014 17:58:32 INFO [2699955157] 0000012730: KSqlCursor::Open(2000,'select PrefsValue from KUAFPrefs where PrefsID=:A1 and PrefsKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699955244] 0000012731: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955334] 0000012732: KSqlCursor::Bind(2,{1000,'General'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955879] 0000012733: KSqlCursor::Execute({'PREFSVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955974] 0000012734: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699956076] 0000012735: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699957385] 0000012736: ****** UAPIGetUserLanguage called ...
09/19/2014 17:58:32 INFO [2699957463] 0000012737: ****** UAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699957569] 0000012738: ****** UAPIPrefsGet called ...
09/19/2014 17:58:32 INFO [2699958081] 0000012739: KSqlCursor::Open(2000,'select PrefsValue from KUAFPrefs where PrefsID=:A1 and PrefsKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699958161] 0000012740: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958249] 0000012741: KSqlCursor::Bind(2,{1000,'MetadataLanguage'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958773] 0000012742: KSqlCursor::Execute({'PREFSVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958867] 0000012743: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958967] 0000012744: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699959044] 0000012745: ****** UAPIFreeSession called ...
09/19/2014 17:58:32 INFO [2699959518] 0000012746: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699959599] 0000012747: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699959685] 0000012748: KSqlCursor::Bind(2,{'Metadata','DefaultLanguage'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960164] 0000012749: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960682] 0000012750: KSqlCursor::Fetch({'\'en\''}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960978] 0000012751: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699961092] 0000012752: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699961181] 0000012753: ****** CAPIIniGet( Metadata, DefaultLanguage ) returned 'en'
09/19/2014 17:58:32 INFO [2699970442] 0000012754: CAPI.Log: Fri Sep 19 17:58:32 2014 - 201032 Func='ll.login' Timing: 0.453 0.457 0.453
I have installed the Content Server Directory Services module to configure Content Server 10 SP2 Update 11 for external authentication.
In our environment we are using Microsoft ADS. For synchronization LDAP Read option has been set, and we are able to synchronize few of the users successfully.
On entering the valid credentials for one of the user in Domain\username [NTWORLD2\00001023] format with a valid Password, authentication is not successful. The message "Invalid username/password specified" is displayed.
Request you to help us analyze the issue. Listed below is the extract from one of the Connect log identified when Debug has been set to 2 with WantLogs as TRUE in opentext.ini
09/19/2014 17:55:28 INFO ..
09/19/2014 17:55:28 INFO [2516147191] 0000000480: --start of log------------------------
09/19/2014 17:58:31 INFO ..
09/19/2014 17:58:31 INFO [2699505976] 0000012289: CAPI.Log: AUTH_TYPE = ''
09/19/2014 17:58:31 INFO [2699506142] 0000012290: CAPI.Log: CONTENT_LENGTH = '169'
09/19/2014 17:58:31 INFO [2699506298] 0000012291: CAPI.Log: CONTENT_TYPE = 'application/x-09/19/2014 17:58:31 INFO [2699506478] 0000012292: CAPI.Log: CurrentClientTime = 'D/2014/9/19:17:56:34'
09/19/2014 17:58:31 INFO [2699506630] 0000012293: CAPI.Log: func = 'll.login'
09/19/2014 17:58:31 INFO [2699506785] 0000012294: CAPI.Log: GATEWAY_INTERFACE = 'CGI/1.1'
09/19/2014 17:58:31 INFO [2699506936] 0000012295: CAPI.Log: HTTPS = 'off'
09/19/2014 17:58:31 INFO [2699507156] 0000012296: CAPI.Log: HTTPS_KEYSIZE = ''
09/19/2014 17:58:31 INFO [2699507300] 0000012297: CAPI.Log: HTTPS_SECRETKEYSIZE = ''
09/19/2014 17:58:31 INFO [2699507441] 0000012298: CAPI.Log: HTTPS_SERVER_ISSUER = ''
09/19/2014 17:58:31 INFO [2699507591] 0000012299: CAPI.Log: HTTPS_SERVER_SUBJECT = ''
09/19/2014 17:58:31 INFO [2699507737] 0000012300: CAPI.Log: HTTP_ACCEPT = 'application/x-ms-application, image/jpeg, application/xaml+xml, image/gif, image/pjpeg, application/x-ms-xbap, */*'
09/19/2014 17:58:31 INFO [2699507883] 0000012301: CAPI.Log: HTTP_ACCEPT_ENCODING = 'gzip, deflate'
09/19/2014 17:58:31 INFO [2699508025] 0000012302: CAPI.Log: HTTP_ACCEPT_LANGUAGE = 'en-US'
09/19/2014 17:58:31 INFO [2699508166] 0000012303: CAPI.Log: HTTP_CACHE_CONTROL = 'no-cache'
09/19/2014 17:58:31 INFO [2699508305] 0000012304: CAPI.Log: HTTP_CONNECTION = 'Keep-Alive'
09/19/2014 17:58:31 INFO [2699508461] 0000012305: CAPI.Log: HTTP_CONTENT_LENGTH = '169'
09/19/2014 17:58:31 INFO [2699508603] 0000012306: CAPI.Log: HTTP_CONTENT_TYPE = 'application/x-09/19/2014 17:58:31 INFO [2699508775] 0000012307: CAPI.Log: HTTP_COOKIE = 'LLCookie=lBdBugrUvjxlUL3hd6gDrBPtV7plsgtUBXgfVEc%2FHMLX7rRQcxmm5yNNfnfUOg8MJx9GGatveWtypQTCrZTo%2BA%3D%3D; LLTZCookie=0; BrowseSettings=e7rkWUcn9qASnLwoY6lumAiTa7hP8TbDaLCs%2BcnwD9o%3D; AdminPwd=dQCRTdaK6V2nxOLwEP7ImkYEJUk6qbxqUsWc1WtTy1BM8RIsilrYPJTgsClRDlms; adminStyle=all'
09/19/2014 17:58:31 INFO [2699508928] 0000012308: CAPI.Log: HTTP_DNT = '1'
09/19/2014 17:58:31 INFO [2699509071] 0000012309: CAPI.Log: HTTP_HOST = 'vmesx22s40'
09/19/2014 17:58:31 INFO [2699509214] 0000012310: CAPI.Log: HTTP_REFERER = '09/19/2014 17:58:31 INFO [2699509368] 0000012311: CAPI.Log: HTTP_USER_AGENT = 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64; Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; .NET4.0E)'
09/19/2014 17:58:31 INFO [2699509571] 0000012312: CAPI.Log: NextURL = '/OTCS/livelink.exe?func=Enterprise.Home'
09/19/2014 17:58:31 INFO [2699509751] 0000012313: CAPI.Log: Password = 'XXXXXXXXXX'
09/19/2014 17:58:31 INFO [2699509960] 0000012314: CAPI.Log: PATH_INFO = ''
09/19/2014 17:58:31 INFO [2699510174] 0000012315: CAPI.Log: PATH_TRANSLATED = 'C:\inetpub\09/19/2014 17:58:31 INFO [2699510399] 0000012316: CAPI.Log: QUERY_STRING = ''
09/19/2014 17:58:31 INFO [2699510613] 0000012317: CAPI.Log: REMOTE_ADDR = '192.168.105.101'
09/19/2014 17:58:31 INFO [2699510811] 0000012318: CAPI.Log: REMOTE_HOST = '192.168.105.101'
09/19/2014 17:58:31 INFO [2699511029] 0000012319: CAPI.Log: REMOTE_USER = ''
09/19/2014 17:58:31 INFO [2699511244] 0000012320: CAPI.Log: REQUEST_METHOD = 'POST'
09/19/2014 17:58:31 INFO [2699511478] 0000012321: CAPI.Log: REQUEST_PROCESSING_DURATION = '0'
09/19/2014 17:58:31 INFO [2699511679] 0000012322: CAPI.Log: SCRIPT_NAME = '/OTCS/livelink.exe'
09/19/2014 17:58:31 INFO [2699511823] 0000012323: CAPI.Log: SERVER_NAME = 'vmesx22s40'
09/19/2014 17:58:31 INFO [2699511960] 0000012324: CAPI.Log: SERVER_PORT = '80'
09/19/2014 17:58:31 INFO [2699512098] 0000012325: CAPI.Log: SERVER_PROTOCOL = 'HTTP/1.1'
09/19/2014 17:58:31 INFO [2699512277] 0000012326: CAPI.Log: SERVER_SOFTWARE = 'Microsoft-IIS/7.5'
09/19/2014 17:58:31 INFO [2699512423] 0000012327: CAPI.Log: Username = 'ntworld2\00001023'
09/19/2014 17:58:31 INFO [2699512586] 0000012328: CAPI.Log: _REQUEST = 'llweb'
09/19/2014 17:58:31 INFO [2699521079] 0000012329: ****** CAPIAllocConnect called ...
09/19/2014 17:58:31 INFO [2699523347] 0000012330: KSqlOCI10::SubclassConnect() before OCIServerAttach
09/19/2014 17:58:31 INFO [2699558822] 0000012331: KSqlOCI10::SubclassConnect() before OCISessionBegin
09/19/2014 17:58:31 INFO [2699574113] 0000012332: KSqlOCI10::SubclassConnect() connect success. Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
09/19/2014 17:58:31 INFO [2699574214] 0000012333: KSqlOCI10::SubclassConnect() statement cache size set to: 0
09/19/2014 17:58:31 INFO [2699574307] 0000012334: KSql::Connect('local_orcl','LLFrontier','ADMIN','*','APIEngine','API100') --> 'SUCCESS',[sec: 0 msec: 50]
09/19/2014 17:58:31 INFO [2699574375] 0000012335: KSql::Connect .. ConnectionType = ORACLE
09/19/2014 17:58:31 INFO [2699574431] 0000012336: KSql::Connect .. DatabaseType = ORACLE7
09/19/2014 17:58:31 INFO [2699574489] 0000012337: KSql::Connect .. MaxLength = 4000
09/19/2014 17:58:31 INFO [2699574545] 0000012338: KSql::Connect .. MaxLongLength = 32767
09/19/2014 17:58:31 INFO [2699574599] 0000012339: KSql::Connect .. SubQueryBlobs = FALSE
09/19/2014 17:58:31 INFO [2699574890] 0000012340: KConnect::Connect(...) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699574967] 0000012341: KConnect::AllocConnect() .. allocate new connection.
09/19/2014 17:58:31 INFO [2699575322] 0000012342: ****** CAPIExec called ...
09/19/2014 17:58:31 INFO [2699576021] 0000012343: KSqlCursor::Open(201f,'select * from KIni where IniSection = 'Livelink.VersionInfo' and IniKeyword = 'DatabaseVersion'') -->'SUCCESS'
09/19/2014 17:58:31 INFO [2699576117] 0000012344: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699576186] 0000012345: KSqlCursor::Bind(0,{}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699576657] 0000012346: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577214] 0000012347: KSqlCursor::Fetch({'Livelink.VersionInfo','DatabaseVersion','{6,1,3}'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577589] 0000012348: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699577728] 0000012349: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:31 INFO [2699577912] 0000012350: ****** CAPIAllocLogin called ...
09/19/2014 17:58:31 INFO [2699579012] 0000012351: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:31 INFO [2699579097] 0000012352: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699579209] 0000012353: KSqlCursor::Bind(3,{0,0,'Admin'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580067] 0000012354: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580227] 0000012355: KSqlCursor::Fetch({1000,1000,0,0,'Admin',?,?,0,'xxxxxx',1001,16777215,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,1000,1,'DefaultGroup',?}) --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580615] 0000012356: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:31 INFO [2699580805] 0000012357: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699580937] 0000012358: KUAFUser::Get(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699581621] 0000012359: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699581701] 0000012360: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699581782] 0000012361: KSqlCursor::Bind(1,{2}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582307] 0000012362: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582414] 0000012363: KSqlCursor::Fetch({2,304,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582502] 0000012364: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699582600] 0000012365: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699583117] 0000012366: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699583196] 0000012367: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583276] 0000012368: KSqlCursor::Bind(1,{3}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583836] 0000012369: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699583943] 0000012370: KSqlCursor::Fetch({3,35902,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584030] 0000012371: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584128] 0000012372: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699584765] 0000012373: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699584845] 0000012374: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699584926] 0000012375: KSqlCursor::Bind(1,{4}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585527] 0000012376: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585634] 0000012377: KSqlCursor::Fetch({4,2,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585722] 0000012378: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699585827] 0000012379: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699585906] 0000012380: ****** CAPIExec called ...
09/19/2014 17:58:32 INFO [2699586820] 0000012381: KSqlCursor::Open(201f,'select sl.LanguageCode, sl.LanguageName, sl.LanguageNameLocal, ml.Enabled from SystemLanguages sl, MetadataLanguages ml where sl.LanguageCode = ml.LanguageCode') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699586904] 0000012382: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699586971] 0000012383: KSqlCursor::Bind(0,{}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699587942] 0000012384: KSqlCursor::Execute({'LANGUAGECODE','LANGUAGENAME','LANGUAGENAMELOCAL','ENABLED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588056] 0000012385: KSqlCursor::Fetch({'en','English','English',1}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588445] 0000012386: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699588572] 0000012387: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699589097] 0000012388: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699589176] 0000012389: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589257] 0000012390: KSqlCursor::Bind(1,{1}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589812] 0000012391: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699589919] 0000012392: KSqlCursor::Fetch({1,5,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590006] 0000012393: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590106] 0000012394: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699590619] 0000012395: KSqlCursor::Open(2000,'select * from KState where StateID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699590717] 0000012396: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699590833] 0000012397: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591396] 0000012398: KSqlCursor::Execute({'STATEID','STATENUM','STATEUSERNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591517] 0000012399: KSqlCursor::Fetch({1000,0,0}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591610] 0000012400: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699591709] 0000012401: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699592560] 0000012402: KSqlCursor::Open(20ff,'select a.ID,a.OwnerID,a.Type,a.SpaceID,a.Name,a.LeaderID,a.UserPrivileges from KUAF a where a.ID in (select distinct b.ID from KUAFChildren b start with b.ChildID=:A1 connect by nocycle prior b.ID=b.ChildID)') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699592676] 0000012403: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699592790] 0000012404: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699594496] 0000012405: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','LEADERID','USERPRIVILEGES'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699594615] 0000012406: KSqlCursor::Fetch({1001,1000,1,0,'DefaultGroup',?,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595162] 0000012407: KSqlOCI10Cursor: multi-fetched 3 rows
09/19/2014 17:58:32 INFO [2699595270] 0000012408: KSqlCursor::Fetch({5966,5964,5963,0,'Guests',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595365] 0000012409: KSqlCursor::Fetch({5964,5964,5963,0,'Coordinators',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595456] 0000012410: KSqlCursor::Fetch({5965,5964,5963,0,'Members',5964,?}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595553] 0000012411: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699595668] 0000012412: KSql::Execute(...) --> 'SUCCESS',4 records,[sec: 0 msec: 3]
09/19/2014 17:58:32 INFO [2699596307] 0000012413: KSqlCursor::Open(2000,'select ID,OwnerID,Type,SpaceID,Name,LeaderID,UserPrivileges from KUAF where ID=:A1') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699596388] 0000012414: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699596559] 0000012415: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597113] 0000012416: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','LEADERID','USERPRIVILEGES'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597227] 0000012417: KSqlCursor::Fetch({1000,1000,0,0,'Admin',?,16777215}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597510] 0000012418: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699597627] 0000012419: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699597709] 0000012420: KUAF::RightsListByID(1000) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699598394] 0000012421: KSqlCursor::Open(2000,'select distinct ProxyType from KUAFProxy where ProxyID=:A1 order by ProxyType') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699598477] 0000012422: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699598560] 0000012423: KSqlCursor::Bind(1,{1000}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599044] 0000012424: KSqlCursor::Execute({'PROXYTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599138] 0000012425: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599246] 0000012426: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699599317] 0000012427: KLogin::ReloadUserRightsList(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599379] 0000012428: KLogin::Login(Admin) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699599441] 0000012429: KLogin::AllocLogin() .. allocate new login.
09/19/2014 17:58:32 INFO [2699600901] 0000012430: ****** CAPIIniList( Module.VersionInfo ) called ...
09/19/2014 17:58:32 INFO [2699601559] 0000012431: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699601695] 0000012432: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699601792] 0000012433: KSqlCursor::Bind(1,{'Module.VersionInfo'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699602478] 0000012434: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699603009] 0000012435: KSqlCursor::Fetch({'Module.VersionInfo','Classification','{1,0,10}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699603716] 0000012436: KSqlCursor::Fetch({'Module.VersionInfo','PhysicalObjects','{5,5,2}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699604440] 0000012437: KSqlCursor::Fetch({'Module.VersionInfo','RecMan','{5,5,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699605147] 0000012438: KSqlCursor::Fetch({'Module.VersionInfo','WebSystemObj','{8,0,46}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699605910] 0000012439: KSqlCursor::Fetch({'Module.VersionInfo','appearances','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699606604] 0000012440: KSqlCursor::Fetch({'Module.VersionInfo','bestbets','{1,1,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699607295] 0000012441: KSqlCursor::Fetch({'Module.VersionInfo','collections','{1,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699608220] 0000012442: KSqlCursor::Fetch({'Module.VersionInfo','dc','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699608963] 0000012443: KSqlCursor::Fetch({'Module.VersionInfo','directory','{1,0,2}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699609692] 0000012444: KSqlCursor::Fetch({'Module.VersionInfo','distributedagent','{1,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699610380] 0000012445: KSqlCursor::Fetch({'Module.VersionInfo','indexobject','{1,0,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699611112] 0000012446: KSqlCursor::Fetch({'Module.VersionInfo','itemtemplate','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699611861] 0000012447: KSqlCursor::Fetch({'Module.VersionInfo','multifile','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699612962] 0000012448: KSqlCursor::Fetch({'Module.VersionInfo','polling','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699613750] 0000012449: KSqlCursor::Fetch({'Module.VersionInfo','pstage','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699614486] 0000012450: KSqlCursor::Fetch({'Module.VersionInfo','recommender','{1,1,11}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699615275] 0000012451: KSqlCursor::Fetch({'Module.VersionInfo','report','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699615973] 0000012452: KSqlCursor::Fetch({'Module.VersionInfo','searchstats','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699616661] 0000012453: KSqlCursor::Fetch({'Module.VersionInfo','storageprovider','{1,1,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699617350] 0000012454: KSqlCursor::Fetch({'Module.VersionInfo','undelete','{1,0,1}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699618041] 0000012455: KSqlCursor::Fetch({'Module.VersionInfo','webprospector','{4,0,5}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699618729] 0000012456: KSqlCursor::Fetch({'Module.VersionInfo','websovmgmt','{8,0,8}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699619417] 0000012457: KSqlCursor::Fetch({'Module.VersionInfo','webwork','{8,0,9}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620125] 0000012458: KSqlCursor::Fetch({'Module.VersionInfo','xmlsearch','{1,0,0}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620449] 0000012459: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699620568] 0000012460: KSql::Execute(...) --> 'SUCCESS',24 records,[sec: 0 msec: 19]
09/19/2014 17:58:32 INFO [2699625586] 0000012461: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699625668] 0000012462: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699625758] 0000012463: KSqlCursor::Bind(2,{'StorageProviderConfigCache','ConfigCache.Version'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699626234] 0000012464: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699626730] 0000012465: KSqlCursor::Fetch({'6939215'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699627022] 0000012466: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699627137] 0000012467: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699627226] 0000012468: ****** CAPIIniGet( StorageProviderConfigCache, ConfigCache.Version ) returned 6939215
09/19/2014 17:58:32 INFO [2699627776] 0000012469: ****** CAPIIniList( Livelink.LogicalProviders ) called ...
09/19/2014 17:58:32 INFO [2699628274] 0000012470: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699628354] 0000012471: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699628439] 0000012472: KSqlCursor::Bind(1,{'Livelink.LogicalProviders'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699628964] 0000012473: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629471] 0000012474: KSqlCursor::Fetch({'Livelink.LogicalProviders','Default','{\'SQL\',\'\'}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629824] 0000012475: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699629941] 0000012476: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699630683] 0000012477: ****** CAPIIniList( Livelink.LogicalProviderRules ) called ...
09/19/2014 17:58:32 INFO [2699631245] 0000012478: KSqlCursor::Open(2000,'select * from KIni where IniSection=:A1 order by IniKeyword') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699631325] 0000012479: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699631418] 0000012480: KSqlCursor::Bind(1,{'Livelink.LogicalProviderRules'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699631949] 0000012481: KSqlCursor::Execute({'INISECTION','INIKEYWORD','INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632449] 0000012482: KSqlCursor::Fetch({'Livelink.LogicalProviderRules','9999','{\'Default\',6,?}'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632773] 0000012483: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699632890] 0000012484: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699635376] 0000012485: ****** CAPIUserInfo returned R<'ID'=1000,...>
09/19/2014 17:58:32 INFO [2699635493] 0000012486: ****** CAPIUserID returned 1000
09/19/2014 17:58:32 INFO [2699635591] 0000012487: ****** DAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699636143] 0000012488: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699636223] 0000012489: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699636309] 0000012490: KSqlCursor::Bind(1,{'DTREECORE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699637664] 0000012491: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699637766] 0000012492: KSqlCursor::Fetch({'OWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638073] 0000012493: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699638165] 0000012494: KSqlCursor::Fetch({'PARENTID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638247] 0000012495: KSqlCursor::Fetch({'DATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638326] 0000012496: KSqlCursor::Fetch({'NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638421] 0000012497: KSqlCursor::Fetch({'ORIGINOWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638503] 0000012498: KSqlCursor::Fetch({'ORIGINDATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638581] 0000012499: KSqlCursor::Fetch({'USERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638659] 0000012500: KSqlCursor::Fetch({'GROUPID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638758] 0000012501: KSqlCursor::Fetch({'UPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638844] 0000012502: KSqlCursor::Fetch({'GPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699638925] 0000012503: KSqlCursor::Fetch({'WPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639003] 0000012504: KSqlCursor::Fetch({'SPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639082] 0000012505: KSqlCursor::Fetch({'ACLCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639160] 0000012506: KSqlCursor::Fetch({'PERMID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639239] 0000012507: KSqlCursor::Fetch({'DATATYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639317] 0000012508: KSqlCursor::Fetch({'CREATEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639403] 0000012509: KSqlCursor::Fetch({'CREATEDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639497] 0000012510: KSqlCursor::Fetch({'MODIFIEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639580] 0000012511: KSqlCursor::Fetch({'MODIFYDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639659] 0000012512: KSqlCursor::Fetch({'MAXVERS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639742] 0000012513: KSqlCursor::Fetch({'RESERVED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699639823] 0000012514: KSqlCursor::Fetch({'RESERVEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640157] 0000012515: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699640249] 0000012516: KSqlCursor::Fetch({'RESERVEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640330] 0000012517: KSqlCursor::Fetch({'VERSIONNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640409] 0000012518: KSqlCursor::Fetch({'DCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640487] 0000012519: KSqlCursor::Fetch({'DCATEGORY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640565] 0000012520: KSqlCursor::Fetch({'SUBTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640642] 0000012521: KSqlCursor::Fetch({'EXATT1'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640719] 0000012522: KSqlCursor::Fetch({'EXATT2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640801] 0000012523: KSqlCursor::Fetch({'ORDERING'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640879] 0000012524: KSqlCursor::Fetch({'MAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699640957] 0000012525: KSqlCursor::Fetch({'MINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641036] 0000012526: KSqlCursor::Fetch({'RELEASEREF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641113] 0000012527: KSqlCursor::Fetch({'CHILDCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641192] 0000012528: KSqlCursor::Fetch({'ASSIGNEDTO'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641270] 0000012529: KSqlCursor::Fetch({'DATEASSIGNED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641349] 0000012530: KSqlCursor::Fetch({'DATEEFFECTIVE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641427] 0000012531: KSqlCursor::Fetch({'DATEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641534] 0000012532: KSqlCursor::Fetch({'DATEDUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641640] 0000012533: KSqlCursor::Fetch({'DATESTARTED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641728] 0000012534: KSqlCursor::Fetch({'DATECOMPLETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641831] 0000012535: KSqlCursor::Fetch({'STATUS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699641928] 0000012536: KSqlCursor::Fetch({'PRIORITY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642351] 0000012537: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699642446] 0000012538: KSqlCursor::Fetch({'GIF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642528] 0000012539: KSqlCursor::Fetch({'EXTENDEDDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642607] 0000012540: KSqlCursor::Fetch({'CATALOG'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642687] 0000012541: KSqlCursor::Fetch({'CACHEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642765] 0000012542: KSqlCursor::Fetch({'DELETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642847] 0000012543: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699642925] 0000012544: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699643023] 0000012545: KSql::Execute(...) --> 'SUCCESS',49 records,[sec: 0 msec: 7]
09/19/2014 17:58:32 INFO [2699643689] 0000012546: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699643770] 0000012547: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699643855] 0000012548: KSqlCursor::Bind(1,{'DTREE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699644940] 0000012549: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645042] 0000012550: KSqlCursor::Fetch({'OWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645415] 0000012551: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699645517] 0000012552: KSqlCursor::Fetch({'PARENTID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645600] 0000012553: KSqlCursor::Fetch({'DATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645680] 0000012554: KSqlCursor::Fetch({'NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645760] 0000012555: KSqlCursor::Fetch({'ORIGINOWNERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645840] 0000012556: KSqlCursor::Fetch({'ORIGINDATAID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699645918] 0000012557: KSqlCursor::Fetch({'USERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646015] 0000012558: KSqlCursor::Fetch({'GROUPID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646113] 0000012559: KSqlCursor::Fetch({'UPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646193] 0000012560: KSqlCursor::Fetch({'GPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646273] 0000012561: KSqlCursor::Fetch({'WPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646352] 0000012562: KSqlCursor::Fetch({'SPERMISSIONS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646430] 0000012563: KSqlCursor::Fetch({'ACLCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646508] 0000012564: KSqlCursor::Fetch({'PERMID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646587] 0000012565: KSqlCursor::Fetch({'DATATYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646666] 0000012566: KSqlCursor::Fetch({'CREATEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646745] 0000012567: KSqlCursor::Fetch({'CREATEDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646823] 0000012568: KSqlCursor::Fetch({'MODIFIEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646901] 0000012569: KSqlCursor::Fetch({'MODIFYDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699646979] 0000012570: KSqlCursor::Fetch({'MAXVERS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647062] 0000012571: KSqlCursor::Fetch({'RESERVED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647142] 0000012572: KSqlCursor::Fetch({'RESERVEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647481] 0000012573: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699647574] 0000012574: KSqlCursor::Fetch({'RESERVEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647656] 0000012575: KSqlCursor::Fetch({'VERSIONNUM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647735] 0000012576: KSqlCursor::Fetch({'DCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647813] 0000012577: KSqlCursor::Fetch({'DCATEGORY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647891] 0000012578: KSqlCursor::Fetch({'SUBTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699647969] 0000012579: KSqlCursor::Fetch({'EXATT1'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648047] 0000012580: KSqlCursor::Fetch({'EXATT2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648127] 0000012581: KSqlCursor::Fetch({'ORDERING'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648207] 0000012582: KSqlCursor::Fetch({'MAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648285] 0000012583: KSqlCursor::Fetch({'MINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648417] 0000012584: KSqlCursor::Fetch({'RELEASEREF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648505] 0000012585: KSqlCursor::Fetch({'CHILDCOUNT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648585] 0000012586: KSqlCursor::Fetch({'ASSIGNEDTO'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648663] 0000012587: KSqlCursor::Fetch({'DATEASSIGNED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648742] 0000012588: KSqlCursor::Fetch({'DATEEFFECTIVE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648821] 0000012589: KSqlCursor::Fetch({'DATEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648899] 0000012590: KSqlCursor::Fetch({'DATEDUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699648978] 0000012591: KSqlCursor::Fetch({'DATESTARTED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649056] 0000012592: KSqlCursor::Fetch({'DATECOMPLETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649134] 0000012593: KSqlCursor::Fetch({'STATUS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649213] 0000012594: KSqlCursor::Fetch({'PRIORITY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649575] 0000012595: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699649667] 0000012596: KSqlCursor::Fetch({'GIF'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649748] 0000012597: KSqlCursor::Fetch({'EXTENDEDDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649828] 0000012598: KSqlCursor::Fetch({'CATALOG'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649908] 0000012599: KSqlCursor::Fetch({'CACHEEXPIRATION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699649987] 0000012600: KSqlCursor::Fetch({'DELETED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650065] 0000012601: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650139] 0000012602: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699650235] 0000012603: KSql::Execute(...) --> 'SUCCESS',49 records,[sec: 0 msec: 7]
09/19/2014 17:58:32 INFO [2699652151] 0000012604: The following columns in DTreeCore have default values and will not be inserted: GUID
09/19/2014 17:58:32 INFO [2699652907] 0000012605: KSqlCursor::Open(2014,'select column_name from user_tab_columns where table_name=:A1 order by Column_Id') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699652987] 0000012606: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699653071] 0000012607: KSqlCursor::Bind(1,{'DVERSDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654158] 0000012608: KSqlCursor::Execute({'COLUMN_NAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654260] 0000012609: KSqlCursor::Fetch({'VERSIONID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654624] 0000012610: KSqlOCI10Cursor: multi-fetched 21 rows
09/19/2014 17:58:32 INFO [2699654716] 0000012611: KSqlCursor::Fetch({'DOCID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654797] 0000012612: KSqlCursor::Fetch({'VERSION'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654876] 0000012613: KSqlCursor::Fetch({'VERSIONNAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699654955] 0000012614: KSqlCursor::Fetch({'OWNER'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655034] 0000012615: KSqlCursor::Fetch({'VERCDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655113] 0000012616: KSqlCursor::Fetch({'VERMDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655192] 0000012617: KSqlCursor::Fetch({'PLATFORM'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655270] 0000012618: KSqlCursor::Fetch({'FILENAME'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655348] 0000012619: KSqlCursor::Fetch({'DATASIZE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655427] 0000012620: KSqlCursor::Fetch({'RESSIZE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655539] 0000012621: KSqlCursor::Fetch({'FILETYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655624] 0000012622: KSqlCursor::Fetch({'FILECREATOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655703] 0000012623: KSqlCursor::Fetch({'FILECDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655787] 0000012624: KSqlCursor::Fetch({'FILEMDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655870] 0000012625: KSqlCursor::Fetch({'ICON'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699655949] 0000012626: KSqlCursor::Fetch({'PROVIDERID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656028] 0000012627: KSqlCursor::Fetch({'VERCOMMENT'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656106] 0000012628: KSqlCursor::Fetch({'LOCKED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656185] 0000012629: KSqlCursor::Fetch({'LOCKEDBY'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656264] 0000012630: KSqlCursor::Fetch({'LOCKEDDATE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656343] 0000012631: KSqlCursor::Fetch({'INDEXED'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656774] 0000012632: KSqlOCI10Cursor: multi-fetched 6 rows
09/19/2014 17:58:32 INFO [2699656872] 0000012633: KSqlCursor::Fetch({'FINDERFLAGS'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699656956] 0000012634: KSqlCursor::Fetch({'MIMETYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657035] 0000012635: KSqlCursor::Fetch({'VERTYPE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657113] 0000012636: KSqlCursor::Fetch({'VERMAJOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657192] 0000012637: KSqlCursor::Fetch({'VERMINOR'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657271] 0000012638: KSqlCursor::Fetch({'GUID'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657345] 0000012639: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699657442] 0000012640: KSql::Execute(...) --> 'SUCCESS',28 records,[sec: 0 msec: 4]
09/19/2014 17:58:32 INFO [2699658262] 0000012641: The following columns in DVersData have default values and will not be inserted: GUID
09/19/2014 17:58:32 INFO [2699658576] 0000012642: ****** DAPISetCallback called ...
09/19/2014 17:58:32 INFO [2699658656] 0000012643: KSession::SetCallback(000007FEF6776C50,0) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699658713] 0000012644: ****** DAPISetScriptCallback called ...
09/19/2014 17:58:32 INFO [2699659886] 0000012645: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699659974] 0000012646: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699660331] 0000012647: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699660413] 0000012648: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699660764] 0000012649: ****** DAPIAddProvider called ...
09/19/2014 17:58:32 INFO [2699660843] 0000012650: ****** DAPISetProviderScriptFeature called ...
09/19/2014 17:58:32 INFO [2699661536] 0000012651: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699661625] 0000012652: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699661742] 0000012653: KSqlCursor::Bind(2,{'Livelink.DocStorage','Default'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662297] 0000012654: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662393] 0000012655: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699662494] 0000012656: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699662574] 0000012657: ****** CAPIIniGet( Livelink.DocStorage, Default ) returned ?
09/19/2014 17:58:32 INFO [2699662672] 0000012658: ****** CAPIIniGet( Livelink.LogicalProviders, Default ) returned {'SQL',''}
09/19/2014 17:58:32 INFO [2699662768] 0000012659: ****** DAPISetDefaultProvider called ...
09/19/2014 17:58:32 INFO [2699663700] 0000012660: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699663780] 0000012661: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699663868] 0000012662: KSqlCursor::Bind(2,{'RecMan','settingsMask'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699664333] 0000012663: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699664859] 0000012664: KSqlCursor::Fetch({'44544'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699665177] 0000012665: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699665293] 0000012666: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699665380] 0000012667: ****** CAPIIniGet( RecMan, settingsMask ) returned 44544
09/19/2014 17:58:32 INFO [2699665896] 0000012668: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699665976] 0000012669: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699666062] 0000012670: KSqlCursor::Bind(2,{'RecMan','settingsMask2'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699666527] 0000012671: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667075] 0000012672: KSqlCursor::Fetch({'134217728'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667374] 0000012673: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699667503] 0000012674: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 2]
09/19/2014 17:58:32 INFO [2699667591] 0000012675: ****** CAPIIniGet( RecMan, settingsMask2 ) returned 134217728
09/19/2014 17:58:32 INFO [2699669215] 0000012676: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699669298] 0000012677: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699669386] 0000012678: KSqlCursor::Bind(2,{'RecMan','secureDelete'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699669918] 0000012679: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699670015] 0000012680: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699670117] 0000012681: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699670196] 0000012682: ****** CAPIIniGet( RecMan, secureDelete ) returned false
09/19/2014 17:58:32 INFO [2699671168] 0000012683: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699671249] 0000012684: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671337] 0000012685: KSqlCursor::Bind(2,{'OTDSIntegration','Settings'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671875] 0000012686: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699671971] 0000012687: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699672072] 0000012688: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699672161] 0000012689: ****** CAPIIniGet( OTDSIntegration, Settings ) returned ?
09/19/2014 17:58:32 INFO [2699673836] 0000012690: ****** CAPIAllocConnect called ...
09/19/2014 17:58:32 INFO [2699673919] 0000012691: KConnect::AllocConnect() .. reusing existing connection.
09/19/2014 17:58:32 INFO [2699674053] 0000012692: ****** CAPIAllocLogin called ...
09/19/2014 17:58:32 INFO [2699675128] 0000012693: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699675226] 0000012694: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699675328] 0000012695: KSqlCursor::Bind(3,{0,0,'ntworld2\\00001023'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676051] 0000012696: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676197] 0000012697: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699676338] 0000012698: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 2]
09/19/2014 17:58:32 ERROR [2699684173] 0000012699: KConnect::ErrLog --> [10106,5],'Invalid username/password specified.'
09/19/2014 17:58:32 ERROR [2699684272] 0000012700: KUAFUser::Get(ntworld2\00001023) --> 'Invalid username/password specified.'
09/19/2014 17:58:32 INFO [2699685711] 0000012701: ****** CAPIAllocConnect called ...
09/19/2014 17:58:32 INFO [2699685791] 0000012702: KConnect::AllocConnect() .. reusing existing connection.
09/19/2014 17:58:32 INFO [2699685920] 0000012703: ****** CAPIAllocLogin called ...
09/19/2014 17:58:32 INFO [2699686805] 0000012704: KSqlCursor::Open(2000,'select a.*,b.OwnerID GroupOwnerID,b.Type GroupType,b.Name GroupName,b.UserData GroupUserData from KUAF a,KUAF b where a.Type=:A1 and a.SpaceID=:A2 and a.Name=:A3 and a.GroupID=b.ID') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699686889] 0000012705: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699686987] 0000012706: KSqlCursor::Bind(3,{0,0,'ntworld2\\00001023'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687738] 0000012707: KSqlCursor::Execute({'ID','OWNERID','TYPE','SPACEID','NAME','USERDATA','LEADERID','DELETED','USERPWD','GROUPID','USERPRIVILEGES','LASTNAME','MIDDLENAME','FIRSTNAME','MAILADDRESS','CONTACT','TITLE','PWDEXPIREDATE','PWDEXPIREMODE','SETTINGSNUM','FAX','OFFICELOCATION','TIMEZONE','PHOTOID','GENDER','BIRTHDAY','PERSONALEMAIL','HOMEADDRESS1','HOMEADDRESS2','HOMEPHONE','HOMEFAX','CELLULARPHONE','PAGER','HOMEPAGE','FAVORITES1','FAVORITES2','FAVORITES3','INTERESTS','GROUPOWNERID','GROUPTYPE','GROUPNAME','GROUPUSERDATA'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687852] 0000012708: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699687981] 0000012709: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 ERROR [2699688074] 0000012710: KConnect::ErrLog --> [10106,5],'Invalid username/password specified.'
09/19/2014 17:58:32 ERROR [2699688150] 0000012711: KUAFUser::Get(ntworld2\00001023) --> 'Invalid username/password specified.'
09/19/2014 17:58:32 INFO [2699937233] 0000012712: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699937352] 0000012713: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699937444] 0000012714: KSqlCursor::Bind(2,{'BaseHref','Protocol'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938174] 0000012715: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938270] 0000012716: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699938375] 0000012717: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699938461] 0000012718: ****** CAPIIniGet( BaseHref, Protocol ) returned ?
09/19/2014 17:58:32 INFO [2699938928] 0000012719: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699939007] 0000012720: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939093] 0000012721: KSqlCursor::Bind(2,{'BaseHref','LookForHost'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939549] 0000012722: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939643] 0000012723: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699939744] 0000012724: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699939820] 0000012725: ****** CAPIIniGet( BaseHref, LookForHost ) returned ?
09/19/2014 17:58:32 INFO [2699954171] 0000012726: ****** CAPIUserInfo returned R<'ID'=1000,...>
09/19/2014 17:58:32 INFO [2699954273] 0000012727: ****** CAPIUserID returned 1000
09/19/2014 17:58:32 INFO [2699954371] 0000012728: ****** UAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699954563] 0000012729: ****** UAPIPrefsGet called ...
09/19/2014 17:58:32 INFO [2699955157] 0000012730: KSqlCursor::Open(2000,'select PrefsValue from KUAFPrefs where PrefsID=:A1 and PrefsKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699955244] 0000012731: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955334] 0000012732: KSqlCursor::Bind(2,{1000,'General'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955879] 0000012733: KSqlCursor::Execute({'PREFSVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699955974] 0000012734: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699956076] 0000012735: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699957385] 0000012736: ****** UAPIGetUserLanguage called ...
09/19/2014 17:58:32 INFO [2699957463] 0000012737: ****** UAPIAllocSession called ...
09/19/2014 17:58:32 INFO [2699957569] 0000012738: ****** UAPIPrefsGet called ...
09/19/2014 17:58:32 INFO [2699958081] 0000012739: KSqlCursor::Open(2000,'select PrefsValue from KUAFPrefs where PrefsID=:A1 and PrefsKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699958161] 0000012740: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958249] 0000012741: KSqlCursor::Bind(2,{1000,'MetadataLanguage'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958773] 0000012742: KSqlCursor::Execute({'PREFSVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958867] 0000012743: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699958967] 0000012744: KSql::Execute(...) --> 'SUCCESS',0 records,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699959044] 0000012745: ****** UAPIFreeSession called ...
09/19/2014 17:58:32 INFO [2699959518] 0000012746: KSqlCursor::Open(2000,'select IniValue from KIni where IniSection=:A1 and IniKeyword=:A2') -->'SUCCESS'
09/19/2014 17:58:32 INFO [2699959599] 0000012747: KSqlCursor:repare() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699959685] 0000012748: KSqlCursor::Bind(2,{'Metadata','DefaultLanguage'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960164] 0000012749: KSqlCursor::Execute({'INIVALUE'}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960682] 0000012750: KSqlCursor::Fetch({'\'en\''}) --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699960978] 0000012751: KSqlCursor::Close() --> 'SUCCESS'
09/19/2014 17:58:32 INFO [2699961092] 0000012752: KSql::Execute(...) --> 'SUCCESS',1 record,[sec: 0 msec: 1]
09/19/2014 17:58:32 INFO [2699961181] 0000012753: ****** CAPIIniGet( Metadata, DefaultLanguage ) returned 'en'
09/19/2014 17:58:32 INFO [2699970442] 0000012754: CAPI.Log: Fri Sep 19 17:58:32 2014 - 201032 Func='ll.login' Timing: 0.453 0.457 0.453