criteria: {COD_FIELD_ID:"UNRECORD_REASON"}	values: {COD_FIELD_ID:"UNRECORD_REASON"}
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOD_LOOKUP_DATA_fetch] derived query: SELECT 
            	VCOD_LOOKUP_DATA.COD_FIELD_ID ,
            	TRIM(VCOD_LOOKUP_DATA.COD_FIELD_VALUE) AS COD_FIELD_VALUE  ,
            	VCOD_LOOKUP_DATA.COD_CODE_ENGLISH_DESCRIPTION ,
            	VCOD_LOOKUP_DATA.COD_CODE_ARABIC_DESCRIPTION 
			 FROM $defaultTableClause WHERE $defaultWhereClause
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOD_LOOKUP_DATA_fetch] 112: Executing SQL query on 'EAD': SELECT 
            	VCOD_LOOKUP_DATA.COD_FIELD_ID ,
            	TRIM(VCOD_LOOKUP_DATA.COD_FIELD_VALUE) AS COD_FIELD_VALUE  ,
            	VCOD_LOOKUP_DATA.COD_CODE_ENGLISH_DESCRIPTION ,
            	VCOD_LOOKUP_DATA.COD_CODE_ARABIC_DESCRIPTION 
			 FROM VCOD_LOOKUP_DATA WHERE (LOWER(VCOD_LOOKUP_DATA.COD_FIELD_ID) LIKE 'unrecord\_reason%' {ESCAPE '\'})
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG SQLConnectionManager - [builtinApplication.VCOD_LOOKUP_DATA_fetch] Borrowed connection '1773496757'
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG SQLDriver - [builtinApplication.VCOD_LOOKUP_DATA_fetch] About to execute SQL query in 'EAD' using connection '1773496757'
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  SQLDriver - [builtinApplication.VCOD_LOOKUP_DATA_fetch] Executing SQL query on 'EAD': SELECT 
            	VCOD_LOOKUP_DATA.COD_FIELD_ID ,
            	TRIM(VCOD_LOOKUP_DATA.COD_FIELD_VALUE) AS COD_FIELD_VALUE  ,
            	VCOD_LOOKUP_DATA.COD_CODE_ENGLISH_DESCRIPTION ,
            	VCOD_LOOKUP_DATA.COD_CODE_ARABIC_DESCRIPTION 
			 FROM VCOD_LOOKUP_DATA WHERE (LOWER(VCOD_LOOKUP_DATA.COD_FIELD_ID) LIKE 'unrecord\_reason%' {ESCAPE '\'})
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG SQLTransform - [builtinApplication.VCOD_LOOKUP_DATA_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  DSResponse - [builtinApplication.VCOD_LOOKUP_DATA_fetch] DSResponse: List with 6 items
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1192 -> 417 bytes
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  RequestContext - URL: '/ERP/isomorphic/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)': MSIE with Accept-Encoding header, ready for compressed JS
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:984
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - Header Name:Value pair: Cookie:JSESSIONID=22E766F65C4A399D1949BD6C2601EEB4; GLog=%7B%0D%20%20%20%20left%3A0%2C%20%0D%20%20%20%20top%3A105%2C%20%0D%20%20%20%20width%3A1382%2C%20%0D%20%20%20%20height%3A766%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%2C%20%0D%20%20%20%20%20%20%20%20CubeGrid%3A5%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Afalse%0D%7D; isc_cState=ready; JSESSIONID=000039n-QMskZfYfJc7Xq33MQeK:-1
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
        COM_DEP_NUMBER:"#"
    },
    operationConfig:{
        dataSource:"VCOM_DEP",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_5",
    appID:"builtinApplication",
    operation:"VCOM_DEP_fetch",
    oldValues:{
        COM_DEP_NUMBER:"#"
    }
}
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOM_DEP is not in the pre-checked list, processing...
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O 2013-12-03 13:19:20,393 - DEBUG - q.g.m.e.w.d.DepartmentMainDMI - 37 - fetch -  - Called - 94822615696967
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O 2013-12-03 13:19:20,393 - INFO - q.g.m.e.w.d.DepartmentMainDMI - 43 - fetch - #
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOM_DEP is not in the pre-checked list, processing...
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG AppBase - [builtinApplication.VCOM_DEP_fetch] No userTypes defined, allowing anyone access to all operations for this application
[12/3/13 13:19:20:393 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,393 [ : 3] DEBUG AppBase - [builtinApplication.VCOM_DEP_fetch] No public zero-argument method named '_VCOM_DEP_fetch' found, performing generic datasource operation
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOM_DEP_fetch] Performing fetch operation with
	criteria: {COM_DEP_NUMBER:"#"}	values: {COM_DEP_NUMBER:"#"}
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOM_DEP_fetch] derived query: SELECT 
			       	COM_ID,COM_DEP_NUMBER,COM_DEP_ARABIC_NAME,COM_DEP_ENGLISH_NAME,
			        DECODE(VCOM_DEP.COM_DEP_VIRTUAL_FLAG,'Y','true','N','false') as COM_DEP_VIRTUAL_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_BUDGET_FLAG,'Y','true','N','false') as COM_DEP_BUDGET_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_NATURE,'Y','true','N','false') as COM_DEP_NATURE,
			        COM_DEP_TYPE,COM_DEP_SEQ
				 FROM 
				 	VCOM_DEP
			 	 WHERE $defaultWhereClause
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOM_DEP_fetch] 104: Executing SQL query on 'EAD': SELECT 
			       	COM_ID,COM_DEP_NUMBER,COM_DEP_ARABIC_NAME,COM_DEP_ENGLISH_NAME,
			        DECODE(VCOM_DEP.COM_DEP_VIRTUAL_FLAG,'Y','true','N','false') as COM_DEP_VIRTUAL_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_BUDGET_FLAG,'Y','true','N','false') as COM_DEP_BUDGET_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_NATURE,'Y','true','N','false') as COM_DEP_NATURE,
			        COM_DEP_TYPE,COM_DEP_SEQ
				 FROM 
				 	VCOM_DEP
			 	 WHERE (LOWER(VCOM_DEP.COM_DEP_NUMBER) LIKE '#%' {ESCAPE '\'})
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG SQLTransform - [builtinApplication.VCOO_UNIT_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG SQLConnectionManager - [builtinApplication.VCOM_DEP_fetch] Borrowed connection '1773496757'
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] INFO  DSResponse - [builtinApplication.VCOO_UNIT_fetch] DSResponse: List with 0 items
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG SQLDriver - [builtinApplication.VCOM_DEP_fetch] About to execute SQL query in 'EAD' using connection '1773496757'
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDriver - [builtinApplication.VCOM_DEP_fetch] Executing SQL query on 'EAD': SELECT 
			       	COM_ID,COM_DEP_NUMBER,COM_DEP_ARABIC_NAME,COM_DEP_ENGLISH_NAME,
			        DECODE(VCOM_DEP.COM_DEP_VIRTUAL_FLAG,'Y','true','N','false') as COM_DEP_VIRTUAL_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_BUDGET_FLAG,'Y','true','N','false') as COM_DEP_BUDGET_FLAG,
			        DECODE(VCOM_DEP.COM_DEP_NATURE,'Y','true','N','false') as COM_DEP_NATURE,
			        COM_DEP_TYPE,COM_DEP_SEQ
				 FROM 
				 	VCOM_DEP
			 	 WHERE (LOWER(VCOM_DEP.COM_DEP_NUMBER) LIKE '#%' {ESCAPE '\'})
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG RPCManager - non-DMI response, dropExtraFields: false
[12/3/13 13:19:20:409 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,409 [ : 4] DEBUG SQLDriver - Freeing SQLDriver dbConnection 294195593
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG SQLTransform - [builtinApplication.VCOM_DEP_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  DSResponse - [builtinApplication.VCOM_DEP_fetch] DSResponse: List with 0 items
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 173 -> 148 bytes
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  RequestContext - URL: '/ERP/isomorphic/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)': MSIE with Accept-Encoding header, ready for compressed JS
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:908
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - Header Name:Value pair: Cookie:JSESSIONID=22E766F65C4A399D1949BD6C2601EEB4; GLog=%7B%0D%20%20%20%20left%3A0%2C%20%0D%20%20%20%20top%3A105%2C%20%0D%20%20%20%20width%3A1382%2C%20%0D%20%20%20%20height%3A766%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%2C%20%0D%20%20%20%20%20%20%20%20CubeGrid%3A5%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Afalse%0D%7D; isc_cState=ready; JSESSIONID=000039n-QMskZfYfJc7Xq33MQeK:-1
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"VCU2_MOI_OFFICES",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_6",
    appID:"builtinApplication",
    operation:"VCU2_MOI_OFFICES_fetch",
    oldValues:{
    }
}
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG DeclarativeSecurity - DataSource VCU2_MOI_OFFICES is not in the pre-checked list, processing...
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG DeclarativeSecurity - DataSource VCU2_MOI_OFFICES is not in the pre-checked list, processing...
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG AppBase - [builtinApplication.VCU2_MOI_OFFICES_fetch] No userTypes defined, allowing anyone access to all operations for this application
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] DEBUG AppBase - [builtinApplication.VCU2_MOI_OFFICES_fetch] No public zero-argument method named '_VCU2_MOI_OFFICES_fetch' found, performing generic datasource operation
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDataSource - [builtinApplication.VCU2_MOI_OFFICES_fetch] Performing fetch operation with
	criteria: {}	values: {}
[12/3/13 13:19:20:409 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLWhereClause - [builtinApplication.VCU2_MOI_OFFICES_fetch] empty condition
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,409 [ : 3] INFO  SQLDataSource - [builtinApplication.VCU2_MOI_OFFICES_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  SQLDataSource - [builtinApplication.VCU2_MOI_OFFICES_fetch] 146: Executing SQL query on 'EAD': SELECT VCU2_MOI_OFFICES.CU2_CRE_SMP, VCU2_MOI_OFFICES.CU2_CRE_USER, VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID, VCU2_MOI_OFFICES.CU2_DEP_ID, VCU2_MOI_OFFICES.CU2_DEP_NUMBER, VCU2_MOI_OFFICES.CU2_OFFICE_AR_NAME, VCU2_MOI_OFFICES.CU2_OFFICE_EN_NAME, VCU2_MOI_OFFICES.CU2_OFFICE_NUMBER FROM VCU2_MOI_OFFICES WHERE ('1'='1')
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG SQLConnectionManager - [builtinApplication.VCU2_MOI_OFFICES_fetch] Borrowed connection '1773496757'
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG SQLDriver - [builtinApplication.VCU2_MOI_OFFICES_fetch] About to execute SQL query in 'EAD' using connection '1773496757'
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  SQLDriver - [builtinApplication.VCU2_MOI_OFFICES_fetch] Executing SQL query on 'EAD': SELECT VCU2_MOI_OFFICES.CU2_CRE_SMP, VCU2_MOI_OFFICES.CU2_CRE_USER, VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID, VCU2_MOI_OFFICES.CU2_DEP_ID, VCU2_MOI_OFFICES.CU2_DEP_NUMBER, VCU2_MOI_OFFICES.CU2_OFFICE_AR_NAME, VCU2_MOI_OFFICES.CU2_OFFICE_EN_NAME, VCU2_MOI_OFFICES.CU2_OFFICE_NUMBER FROM VCU2_MOI_OFFICES WHERE ('1'='1')
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "294195593"
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLDriver - Freeing SQLDriver dbConnection 518266596
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG SQLTransform - [builtinApplication.VCU2_MOI_OFFICES_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  DSResponse - [builtinApplication.VCU2_MOI_OFFICES_fetch] DSResponse: List with 4 items
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "518266596"
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLDriver - Freeing SQLDriver dbConnection 806891544
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1435 -> 644 bytes
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "806891544"
[12/3/13 13:19:20:424 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,424 [ : 4] DEBUG SQLDriver - Freeing SQLDriver dbConnection 197921740
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  RequestContext - URL: '/ERP/isomorphic/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)': MSIE with Accept-Encoding header, ready for compressed JS
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; InfoPath.3; .NET4.0C)
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:2038
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - Header Name:Value pair: Cookie:JSESSIONID=22E766F65C4A399D1949BD6C2601EEB4; GLog=%7B%0D%20%20%20%20left%3A0%2C%20%0D%20%20%20%20top%3A105%2C%20%0D%20%20%20%20width%3A1382%2C%20%0D%20%20%20%20height%3A766%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%2C%20%0D%20%20%20%20%20%20%20%20CubeGrid%3A5%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Afalse%0D%7D; isc_cState=ready; JSESSIONID=000039n-QMskZfYfJc7Xq33MQeK:-1
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
        _constructor:"AdvancedCriteria",
        operator:"and",
        criteria:[
            {
                fieldName:"II0_STATUS",
                operator:"inSet",
                value:[
                    "COMPLETED",
                    "DRAFT",
                    "NOTCOMPLETE",
                    "RETURNED_APPROVER",
                    "PENDING"
                ]
            }
        ]
    },
    operationConfig:{
        dataSource:"CUSTODY_RETURN_MAIN",
        operationType:"fetch",
        textMatchStyle:"exact"
    },
    startRow:0,
    endRow:13,
    componentId:"isc_ERPListGrid_0",
    appID:"builtinApplication",
    operation:"listByEditor",
    oldValues:{
        _constructor:"AdvancedCriteria",
        operator:"and",
        criteria:[
            {
                fieldName:"II0_STATUS",
                operator:"inSet",
                value:[
                    "COMPLETED",
                    "DRAFT",
                    "NOTCOMPLETE",
                    "RETURNED_APPROVER",
                    "PENDING"
                ]
            }
        ]
    }
}
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG DeclarativeSecurity - DataSource CUSTODY_RETURN_MAIN is not in the pre-checked list, processing...
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O 2013-12-03 13:19:20,424 - DEBUG - q.g.m.e.w.d.CustodyReturnMainDMI - 32 - fetch -  - Called - 94822642181059
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG DeclarativeSecurity - DataSource CUSTODY_RETURN_MAIN is not in the pre-checked list, processing...
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG AppBase - [builtinApplication.listByEditor] No userTypes defined, allowing anyone access to all operations for this application
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] DEBUG AppBase - [builtinApplication.listByEditor] No public zero-argument method named '_listByEditor' found, performing generic datasource operation
[12/3/13 13:19:20:424 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,424 [ : 3] INFO  SQLDataSource - [builtinApplication.listByEditor] Performing fetch operation with