[12/3/13 13:19:20:284 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,284 [ : 4] INFO  SQLDataSource - [builtinApplication.VCOO_UNIT_fetch] 162: Executing SQL query on 'EAD': SELECT VCOO_UNIT.COO_ID, VCOO_UNIT.COO_SECTION_ID, VCOO_UNIT.COO_UNIT_ARABIC_NAME, VCOO_UNIT.COO_UNIT_ENGLISH_NAME, VCOO_UNIT.COO_UNIT_NUMBER FROM VCOO_UNIT WHERE (VCOO_UNIT.COO_SECTION_ID='')
[12/3/13 13:19:20:284 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,284 [ : 4] DEBUG SQLConnectionManager - [builtinApplication.VCOO_UNIT_fetch] Borrowed connection '806891544'
[12/3/13 13:19:20:284 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,284 [ : 4] DEBUG SQLDriver - [builtinApplication.VCOO_UNIT_fetch] About to execute SQL query in 'EAD' using connection '806891544'
[12/3/13 13:19:20:284 AST] 00000020 SystemOut     O === 2013-12-03 13:19:20,284 [ : 4] INFO  SQLDriver - [builtinApplication.VCOO_UNIT_fetch] Executing SQL query on 'EAD': SELECT VCOO_UNIT.COO_ID, VCOO_UNIT.COO_SECTION_ID, VCOO_UNIT.COO_UNIT_ARABIC_NAME, VCOO_UNIT.COO_UNIT_ENGLISH_NAME, VCOO_UNIT.COO_UNIT_NUMBER FROM VCOO_UNIT WHERE (VCOO_UNIT.COO_SECTION_ID='')
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG SQLTransform - [builtinApplication.VCOO_UNIT_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] INFO  DSResponse - [builtinApplication.VCOO_UNIT_fetch] DSResponse: List with 7 items
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOM_DEP_CACHE is not in the pre-checked list, processing...
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] INFO  DSResponse - DSResponse: List with 4 items
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG RPCManager - non-DMI response, dropExtraFields: false
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1839230368
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1839230368"
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:284 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,284 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:299 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,299 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 5457 -> 1319 bytes
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 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:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 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:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:904
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 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:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"VCOM_DEP_CACHE",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_0",
    appID:"builtinApplication",
    operation:"VCOM_DEP_CACHE_fetch",
    oldValues:{
    }
}
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOM_DEP_CACHE is not in the pre-checked list, processing...
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] INFO  DSResponse - DSResponse: List with 5 items
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:315 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,315 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1436 -> 545 bytes
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 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:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 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:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:900
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 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:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"VCON_SECTION",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_1",
    appID:"builtinApplication",
    operation:"VCON_SECTION_fetch",
    oldValues:{
    }
}
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG DeclarativeSecurity - DataSource VCON_SECTION is not in the pre-checked list, processing...
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O 2013-12-03 13:19:20,331 - DEBUG - q.g.m.e.web.dmi.SectionMainDMI - 33 - fetch -  - Called - 94822547489136
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG DeclarativeSecurity - DataSource VCON_SECTION is not in the pre-checked list, processing...
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG AppBase - [builtinApplication.VCON_SECTION_fetch] No userTypes defined, allowing anyone access to all operations for this application
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG AppBase - [builtinApplication.VCON_SECTION_fetch] No public zero-argument method named '_VCON_SECTION_fetch' found, performing generic datasource operation
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  SQLDataSource - [builtinApplication.VCON_SECTION_fetch] Performing fetch operation with
	criteria: {}	values: {}
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  SQLWhereClause - [builtinApplication.VCON_SECTION_fetch] empty condition
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  SQLDataSource - [builtinApplication.VCON_SECTION_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  SQLDataSource - [builtinApplication.VCON_SECTION_fetch] 217: Executing SQL query on 'EAD': SELECT VCON_SECTION.CON_DEPARTMENT, VCON_SECTION.CON_ID, VCON_SECTION.CON_SEC_ARABIC_NAME, VCON_SECTION.CON_SEC_ENGLISH_NAME, VCON_SECTION.CON_SEC_NUMBER, VCON_SECTION.CON_SEC_TYPE FROM VCON_SECTION WHERE ('1'='1')
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG SQLConnectionManager - [builtinApplication.VCON_SECTION_fetch] Borrowed connection '1773496757'
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG SQLDriver - [builtinApplication.VCON_SECTION_fetch] About to execute SQL query in 'EAD' using connection '1773496757'
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  SQLDriver - [builtinApplication.VCON_SECTION_fetch] Executing SQL query on 'EAD': SELECT VCON_SECTION.CON_DEPARTMENT, VCON_SECTION.CON_ID, VCON_SECTION.CON_SEC_ARABIC_NAME, VCON_SECTION.CON_SEC_ENGLISH_NAME, VCON_SECTION.CON_SEC_NUMBER, VCON_SECTION.CON_SEC_TYPE FROM VCON_SECTION WHERE ('1'='1')
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG SQLTransform - [builtinApplication.VCON_SECTION_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] INFO  DSResponse - [builtinApplication.VCON_SECTION_fetch] DSResponse: List with 6 items
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:331 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,331 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1316 -> 595 bytes
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 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:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 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:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:894
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 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:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:346 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,346 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 16ms
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"VCOO_UNIT",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_2",
    appID:"builtinApplication",
    operation:"VCOO_UNIT_fetch",
    oldValues:{
    }
}
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOO_UNIT is not in the pre-checked list, processing...
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG ServerObject - Couldn't find a public method named: fetch on class: qa.gov.moi.erp.web.dmi.UnitMainDMI
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG DataSourceDMI - DataSourceDMI: no public method name: fetch available on class: qa.gov.moi.erp.web.dmi.UnitMainDMI - defaulting to builtin operations.
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG AppBase - [builtinApplication.VCOO_UNIT_fetch] No userTypes defined, allowing anyone access to all operations for this application
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG AppBase - [builtinApplication.VCOO_UNIT_fetch] No public zero-argument method named '_VCOO_UNIT_fetch' found, performing generic datasource operation
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOO_UNIT_fetch] Performing fetch operation with
	criteria: {}	values: {}
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  SQLWhereClause - [builtinApplication.VCOO_UNIT_fetch] empty condition
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOO_UNIT_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  SQLDataSource - [builtinApplication.VCOO_UNIT_fetch] 500: Executing SQL query on 'EAD': SELECT VCOO_UNIT.COO_ID, VCOO_UNIT.COO_SECTION_ID, VCOO_UNIT.COO_UNIT_ARABIC_NAME, VCOO_UNIT.COO_UNIT_ENGLISH_NAME, VCOO_UNIT.COO_UNIT_NUMBER FROM VCOO_UNIT WHERE ('1'='1')
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG SQLConnectionManager - [builtinApplication.VCOO_UNIT_fetch] Borrowed connection '1773496757'
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG SQLDriver - [builtinApplication.VCOO_UNIT_fetch] About to execute SQL query in 'EAD' using connection '1773496757'
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  SQLDriver - [builtinApplication.VCOO_UNIT_fetch] Executing SQL query on 'EAD': SELECT VCOO_UNIT.COO_ID, VCOO_UNIT.COO_SECTION_ID, VCOO_UNIT.COO_UNIT_ARABIC_NAME, VCOO_UNIT.COO_UNIT_ENGLISH_NAME, VCOO_UNIT.COO_UNIT_NUMBER FROM VCOO_UNIT WHERE ('1'='1')
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG SQLTransform - [builtinApplication.VCOO_UNIT_fetch] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  DSResponse - [builtinApplication.VCOO_UNIT_fetch] DSResponse: List with 7 items
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG RPCManager - non-DMI response, dropExtraFields: false
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1773496757
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1773496757"
[12/3/13 13:19:20:362 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,362 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1646 -> 686 bytes
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:1002
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG XML - Parsed XML from (in memory stream): 0ms
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG RPCManager - Processing 1 requests.
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
        USER_ROLE_ID:"STRCTLOFFC"
    },
    operationConfig:{
        dataSource:"VCOM_DEP_CACHE",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_3",
    appID:"builtinApplication",
    operation:"VCOM_DEP_CACHE_fetch",
    oldValues:{
        USER_ROLE_ID:"STRCTLOFFC"
    }
}
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] INFO  IDACall - Performing 1 operation(s)
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG DeclarativeSecurity - DataSource VCOM_DEP_CACHE is not in the pre-checked list, processing...
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] INFO  DSResponse - DSResponse: List with 4 items
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG RPCManager - DMI response, dropExtraFields: true
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] INFO  Compression - /ERP/isomorphic/IDACall: 1197 -> 494 bytes
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept:*/*
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-us
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Referer:http://localhost:9080/ERP/documents/CustodyReturn.jsp
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Host:localhost:9080
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Content-Length:1016
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Connection:Keep-Alive
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - session exists: 39n-QMskZfYfJc7Xq33MQeK
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 3] DEBUG IDACall - remote user: null
[12/3/13 13:19:20:377 AST] 0000001f SystemOut     O === 2013-12-03 13:19:20,377 [ : 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:{
        COD_FIELD_ID:"UNRECORD_REASON"
    },
    operationConfig:{
        dataSource:"VCOD_LOOKUP_DATA",
        operationType:"fetch",
        textMatchStyle:"startsWith"
    },
    componentId:"isc_PickListMenu_4",
    appID:"builtinApplication",
    operation:"VCOD_LOOKUP_DATA_fetch",
    oldValues:{
        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  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 VCOD_LOOKUP_DATA 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 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 VCOD_LOOKUP_DATA 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.VCOD_LOOKUP_DATA_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.VCOD_LOOKUP_DATA_fetch] No public zero-argument method named '_VCOD_LOOKUP_DATA_fetch' found, performing generic datasource operation
[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] Performing fetch operation with