=== 2013-12-03 07:15:46,154 [01-5] INFO  RequestContext - URL: '/ERP/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2013-12-03 07:15:46,154 [01-5] DEBUG IDACall - Header Name:Value pair: accept:*/*
=== 2013-12-03 07:15:46,154 [01-5] DEBUG IDACall - Header Name:Value pair: accept-language:en-us
=== 2013-12-03 07:15:46,154 [01-5] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:2001/ERP/documents/CustodyRequisition.jsp
=== 2013-12-03 07:15:46,154 [01-5] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2013-12-03 07:15:46,154 [01-5] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0)
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: host:localhost:2001
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: content-length:1958
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: connection:Keep-Alive
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - Header Name:Value pair: cookie:JSESSIONID=32F3FDE4393E954C4EE219D6FBCAA76C; isc_cState=ready
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - session exists: 32F3FDE4393E954C4EE219D6FBCAA76C
=== 2013-12-03 07:15:46,156 [01-5] DEBUG IDACall - remote user: null
=== 2013-12-03 07:15:46,156 [01-5] DEBUG XML - Parsed XML from (in memory stream): 0ms
=== 2013-12-03 07:15:46,156 [01-5] DEBUG RPCManager - Processing 1 requests.
=== 2013-12-03 07:15:46,156 [01-5] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    values:{
        RQ1_CONVERSION_RATE:1,
        RQ1_ASSIGNEE_TYPE:"ASSIGNEE_TYPE",
        ParentPrimayKey3:"CSRQ/2013/044/00008             ",
        ParentPrimayKey1:"461ea5dd8a8240dcac6321bbb3cc36e7",
        ParentPrimayKey2:"D",
        PR0_IS_SERIAL_DEFINED:false,
        REQUESTED_QUANTITY:"10",
        RQ1_PRODUCT_NUMBER:"037/000007",
        RQ1_REQESTED_QUANTITY:10,
        PR0_NAME_ARABIC:"Laptop",
        RQ1_PRODUCT_UOM_ID:"U1005                           ",
        RQ1_ASSIGNEE_TYPE_V:"Department",
        RQ1_ASSIGNEE_DEPARTMENT:"044"
    },
    operationConfig:{
        dataSource:"TRQ1_REQUISITION_DETAIL",
        operationType:"add"
    },
    componentId:"custodyRequisitionDetailForm",
    useStrictJSON:true,
    appID:"builtinApplication",
    operation:"TRQ1_REQUISITION_DETAIL_add",
    oldValues:{
    },
    criteria:{
    }
}
=== 2013-12-03 07:15:46,156 [01-5] INFO  IDACall - Performing 1 operation(s)
=== 2013-12-03 07:15:46,156 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2013-12-03 07:15:46,156 [01-5] DEBUG DeclarativeSecurity - DataSource TRQ1_REQUISITION_DETAIL is not in the pre-checked list, processing...
=== 2013-12-03 07:15:46,174 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
2013-12-03 07:15:46,174 - DEBUG - q.g.m.e.w.d.CustodyRequisitionMainDMI - 33 - fetch -  - Called - 157017467758493
=== 2013-12-03 07:15:46,174 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2013-12-03 07:15:46,174 [01-5] DEBUG AppBase - [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2013-12-03 07:15:46,174 [01-5] DEBUG AppBase - [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2013-12-03 07:15:46,174 [01-5] INFO  SQLDataSource - [builtinApplication.null] Performing fetch operation with
	criteria: {RQ0_MODE:"D",RQ0_ID:"461ea5dd8a8240dcac6321bbb3cc36e7",RQ0_DOC_TYPE:"CSRQ"}	values: {RQ0_MODE:"D",RQ0_ID:"461ea5dd8a8240dcac6321bbb3cc36e7",RQ0_DOC_TYPE:"CSRQ"}
=== 2013-12-03 07:15:46,190 [01-5] INFO  SQLDataSource - [builtinApplication.null] derived query: SELECT 
			VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ID, VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ROLE, 
            VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_SMP, VRQ0_REQUISITION_MAIN.RQ0_DOC_DESCRIPTION, VRQ0_REQUISITION_MAIN.RQ0_DOC_HEADER, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE_V, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_AMOUNT, VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_ITEMS, VRQ0_REQUISITION_MAIN.RQ0_DOC_TYPE, 
            VRQ0_REQUISITION_MAIN.RQ0_ID, VRQ0_REQUISITION_MAIN.RQ0_ISSUE_DEPARTMENT, VRQ0_REQUISITION_MAIN.RQ0_IS_LINKED, 
            VRQ0_REQUISITION_MAIN.RQ0_IS_PROGRAM_RELATED, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ROLE, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_SMP, 
            VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_KEY, VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_TYPE, VRQ0_REQUISITION_MAIN.RQ0_LOCK_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_MODE, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_ID, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_MODE, 
            VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_REF_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_REASON_CODE, VRQ0_REQUISITION_MAIN.RQ0_REQ_DEPARTMENT, 
            VRQ0_REQUISITION_MAIN.RQ0_REQ_SECTION_ID, VRQ0_REQUISITION_MAIN.RQ0_REQ_UNIT_ID, VRQ0_REQUISITION_MAIN.RQ0_STATUS,
            (SELECT AT0_USER_REMARKS FROM VAT0_AUDIT_TRAIL_MAIN WHERE
			VAT0_AUDIT_TRAIL_MAIN.AT0_DOCUMENT_NUMBER = VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER 
			ORDER BY AT0_TIME_STAMP DESC FETCH FIRST 1 ROWS ONLY) FEEDBACK
			 FROM $defaultTableClause WHERE $defaultWhereClause
=== 2013-12-03 07:15:46,190 [01-5] INFO  SQLDataSource - [builtinApplication.null] 59: Executing SQL query on 'EAD': SELECT 
			VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ID, VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ROLE, 
            VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_SMP, VRQ0_REQUISITION_MAIN.RQ0_DOC_DESCRIPTION, VRQ0_REQUISITION_MAIN.RQ0_DOC_HEADER, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE_V, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_AMOUNT, VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_ITEMS, VRQ0_REQUISITION_MAIN.RQ0_DOC_TYPE, 
            VRQ0_REQUISITION_MAIN.RQ0_ID, VRQ0_REQUISITION_MAIN.RQ0_ISSUE_DEPARTMENT, VRQ0_REQUISITION_MAIN.RQ0_IS_LINKED, 
            VRQ0_REQUISITION_MAIN.RQ0_IS_PROGRAM_RELATED, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ROLE, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_SMP, 
            VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_KEY, VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_TYPE, VRQ0_REQUISITION_MAIN.RQ0_LOCK_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_MODE, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_ID, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_MODE, 
            VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_REF_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_REASON_CODE, VRQ0_REQUISITION_MAIN.RQ0_REQ_DEPARTMENT, 
            VRQ0_REQUISITION_MAIN.RQ0_REQ_SECTION_ID, VRQ0_REQUISITION_MAIN.RQ0_REQ_UNIT_ID, VRQ0_REQUISITION_MAIN.RQ0_STATUS,
            (SELECT AT0_USER_REMARKS FROM VAT0_AUDIT_TRAIL_MAIN WHERE
			VAT0_AUDIT_TRAIL_MAIN.AT0_DOCUMENT_NUMBER = VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER 
			ORDER BY AT0_TIME_STAMP DESC FETCH FIRST 1 ROWS ONLY) FEEDBACK
			 FROM VRQ0_REQUISITION_MAIN WHERE (VRQ0_REQUISITION_MAIN.RQ0_MODE='D' AND VRQ0_REQUISITION_MAIN.RQ0_ID='461ea5dd8a8240dcac6321bbb3cc36e7' AND VRQ0_REQUISITION_MAIN.RQ0_DOC_TYPE='CSRQ')
=== 2013-12-03 07:15:46,190 [01-5] DEBUG SQLConnectionManager - [builtinApplication.null] Borrowed connection '1849716288'
=== 2013-12-03 07:15:46,190 [01-5] DEBUG SQLDriver - [builtinApplication.null] About to execute SQL query in 'EAD' using connection '1849716288'
=== 2013-12-03 07:15:46,190 [01-5] INFO  SQLDriver - [builtinApplication.null] Executing SQL query on 'EAD': SELECT 
			VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ID, VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_ROLE, 
            VRQ0_REQUISITION_MAIN.RQ0_CREATED_USER_SMP, VRQ0_REQUISITION_MAIN.RQ0_DOC_DESCRIPTION, VRQ0_REQUISITION_MAIN.RQ0_DOC_HEADER, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE, VRQ0_REQUISITION_MAIN.RQ0_DOC_SUB_TYPE_V, 
            VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_AMOUNT, VRQ0_REQUISITION_MAIN.RQ0_DOC_TOTAL_ITEMS, VRQ0_REQUISITION_MAIN.RQ0_DOC_TYPE, 
            VRQ0_REQUISITION_MAIN.RQ0_ID, VRQ0_REQUISITION_MAIN.RQ0_ISSUE_DEPARTMENT, VRQ0_REQUISITION_MAIN.RQ0_IS_LINKED, 
            VRQ0_REQUISITION_MAIN.RQ0_IS_PROGRAM_RELATED, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_ROLE, VRQ0_REQUISITION_MAIN.RQ0_LASTUPDATED_USER_SMP, 
            VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_KEY, VRQ0_REQUISITION_MAIN.RQ0_LINKED_DOC_TYPE, VRQ0_REQUISITION_MAIN.RQ0_LOCK_ID, 
            VRQ0_REQUISITION_MAIN.RQ0_MODE, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_ID, VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_MODE, 
            VRQ0_REQUISITION_MAIN.RQ0_PROGRAM_REF_NUMBER, VRQ0_REQUISITION_MAIN.RQ0_REASON_CODE, VRQ0_REQUISITION_MAIN.RQ0_REQ_DEPARTMENT, 
            VRQ0_REQUISITION_MAIN.RQ0_REQ_SECTION_ID, VRQ0_REQUISITION_MAIN.RQ0_REQ_UNIT_ID, VRQ0_REQUISITION_MAIN.RQ0_STATUS,
            (SELECT AT0_USER_REMARKS FROM VAT0_AUDIT_TRAIL_MAIN WHERE
			VAT0_AUDIT_TRAIL_MAIN.AT0_DOCUMENT_NUMBER = VRQ0_REQUISITION_MAIN.RQ0_DOC_NUMBER 
			ORDER BY AT0_TIME_STAMP DESC FETCH FIRST 1 ROWS ONLY) FEEDBACK
			 FROM VRQ0_REQUISITION_MAIN WHERE (VRQ0_REQUISITION_MAIN.RQ0_MODE='D' AND VRQ0_REQUISITION_MAIN.RQ0_ID='461ea5dd8a8240dcac6321bbb3cc36e7' AND VRQ0_REQUISITION_MAIN.RQ0_DOC_TYPE='CSRQ')
=== 2013-12-03 07:15:46,205 [01-5] DEBUG SQLTransform - [builtinApplication.null] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
=== 2013-12-03 07:15:46,237 [01-5] INFO  DSResponse - [builtinApplication.null] DSResponse: List with 1 items
=== 2013-12-03 07:15:46,237 [01-5] DEBUG XML - Parsed XML from D:\Softwares\apache-tomcat-6.0.35\webapps\ERPWeb\common\smartclientConfig\ds\ProdTree.ds.xml: 0ms
=== 2013-12-03 07:15:46,237 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2013-12-03 07:15:46,237 [01-5] DEBUG AppBase - [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2013-12-03 07:15:46,252 [01-5] DEBUG AppBase - [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2013-12-03 07:15:46,252 [01-5] INFO  SQLDataSource - [builtinApplication.null] Performing fetch operation with
	criteria: {PR0_NUMBER:"037/000007"}	values: {PR0_NUMBER:"037/000007"}
=== 2013-12-03 07:15:46,252 [01-5] INFO  SQLDataSource - [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2013-12-03 07:15:46,252 [01-5] INFO  SQLDataSource - [builtinApplication.null] 121: Executing SQL query on 'EAD': SELECT VPR0_PRODUCT.PR0_BUY_DEPARTMENT, VPR0_PRODUCT.PR0_ISACTIVE, VPR0_PRODUCT.PR0_IS_CONSUMABLE, VPR0_PRODUCT.PR0_IS_SERIAL_DEFINED, VPR0_PRODUCT.PR0_NUMBER, VPR0_PRODUCT.PR0_PRODUCT_ID, VPR0_PRODUCT.PR0_PRODUCT_TYPE, VPR0_PRODUCT.PR0_REQ_DEPARTMENT FROM VPR0_PRODUCT WHERE (VPR0_PRODUCT.PR0_NUMBER='037/000007')
=== 2013-12-03 07:15:46,252 [01-5] DEBUG SQLConnectionManager - [builtinApplication.null] Borrowed connection '540287028'
=== 2013-12-03 07:15:46,252 [01-5] DEBUG SQLDriver - [builtinApplication.null] About to execute SQL query in 'EAD' using connection '540287028'
=== 2013-12-03 07:15:46,252 [01-5] INFO  SQLDriver - [builtinApplication.null] Executing SQL query on 'EAD': SELECT VPR0_PRODUCT.PR0_BUY_DEPARTMENT, VPR0_PRODUCT.PR0_ISACTIVE, VPR0_PRODUCT.PR0_IS_CONSUMABLE, VPR0_PRODUCT.PR0_IS_SERIAL_DEFINED, VPR0_PRODUCT.PR0_NUMBER, VPR0_PRODUCT.PR0_PRODUCT_ID, VPR0_PRODUCT.PR0_PRODUCT_TYPE, VPR0_PRODUCT.PR0_REQ_DEPARTMENT FROM VPR0_PRODUCT WHERE (VPR0_PRODUCT.PR0_NUMBER='037/000007')
=== 2013-12-03 07:15:46,315 [01-5] DEBUG SQLTransform - [builtinApplication.null] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
=== 2013-12-03 07:15:46,315 [01-5] INFO  DSResponse - [builtinApplication.null] DSResponse: List with 1 items
=== 2013-12-03 07:15:46,315 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
2013-12-03 07:15:46,315 - DEBUG - q.g.m.e.w.d.CustodyRequsitionDetailDMI - 145 - fetch -  - fetch Called - 157017604453051
=== 2013-12-03 07:15:46,315 [01-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2013-12-03 07:15:46,315 [01-5] DEBUG AppBase - [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2013-12-03 07:15:46,315 [01-5] DEBUG AppBase - [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2013-12-03 07:15:46,315 [01-5] INFO  SQLDataSource - [builtinApplication.null] Performing fetch operation with
	criteria: {RQ1_MMODE:"D",RQ1_ASSIGNEE_TYPE_V:"Department",RQ1_ASSIGNEE_DEPARTMENT:"044",RQ1_PRODUCT_NUMBER:"037/000007",RQ1_MID:"461ea5dd8a8240dcac6321bbb3cc36e7"}	values: {RQ1_MMODE:"D",RQ1_ASSIGNEE_TYPE_V:"Department",RQ1_ASSIGNEE_DEPARTMENT:"044",RQ1_PRODUCT_NUMBER:"037/000007",RQ1_MID:"461ea5dd8a8240dcac6321bbb3cc36e7"}
=== 2013-12-03 07:15:46,315 [01-5] INFO  SQLDataSource - [builtinApplication.null] derived query: SELECT 
				RQ1_ID, RQ1_MODE, RQ1_MID, RQ1_MMODE,
				RQ1_CUS_HOLDING_ID,
				RQ1_PRODUCT_ID,
				RQ1_PRODUCT_NUMBER,
				RQ1_PRODUCT_STATE,
				RQ1_PRODUCT_STATE_V,
				RQ1_REQESTED_QUANTITY,
				RQ1_ISSUED_QUANTITY,
				RQ1_CONVERSION_RATE,
				RQ1_LOCK_ID,
				RQ1_CREATED_USER_ID, RQ1_CREATED_USER_ROLE,  
				RQ1_CREATED_USER_SMP,   
				RQ1_ASSIGNEE_ID,
				RQ1_CUS_TYPE, RQ1_CUS_TYPE_V, RQ1_PRODUCT_UOM_ID,
				P.PR0_NAME_ARABIC,
				P.PR0_DESCRIPTION,
				DECODE(P.PR0_IS_SERIAL_DEFINED,'Y','true','N','false') as
				PR0_IS_SERIAL_DEFINED,
				RQ1_ASSIGNEE_TYPE_V,
				RQ1_ASSIGNEE_TYPE,
				RQ1_ASSIGNEE_QIDNO, RQ1_ASSIGNEE_RANK, RQ1_ASSIGNEE_STAFF_NUMBER,
				RQ1_ASSIGNEE_DEPARTMENT, RQ1_PRODUCT_PKG_ID ,
				RQ1_ASSIGNEE_OFFICE_ID, RQ1_ASSIGNEE_SECTION_ID,
				RQ1_ASSIGNEE_UNIT_ID,
				RQ1_ASSIGNEE_VISA_NUM, RQ1_ASSIGNEE_ID AS
				ASSIGNEE_DESC, 
				RQ1_PRODUCT_UNIT_PRICE,
				RQ1_PRODUCT_TOTAL_PRICE,RQ1_ASSIGNEE_PLATE_TYPE,
				RQ1_ASSIGNEE_PLATE_NUMBER,

				(SELECT COM_DEP_ARABIC_NAME FROM
				VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ARABIC,

				(SELECT COM_DEP_ENGLISH_NAME FROM VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ENGLISH,

				(SELECT CON_SEC_ARABIC_NAME FROM VCON_SECTION
				WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ARABIC,

				(SELECT CON_SEC_ENGLISH_NAME FROM
				VCON_SECTION WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ENGLISH,

				(SELECT COO_UNIT_ARABIC_NAME FROM VCOO_UNIT
				WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ARABIC,

				(SELECT COO_UNIT_ENGLISH_NAME FROM VCOO_UNIT WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ENGLISH FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ARABIC FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ARABIC,
				(SELECT CU2_OFFICE_AR_NAME FROM VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ARABIC,

				(SELECT CU2_OFFICE_EN_NAME FROM
				VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ENGLISH, 
				RQ1_LASTUPDATED_USER_ID, RQ1_LASTUPDATED_USER_ROLE, 
				RQ1_LASTUPDATED_USER_SMP, RQ1_REQESTED_QUANTITY/RQ1_CONVERSION_RATE REQUESTED_QUANTITY  
      	   FROM VRQ1_REQUISITION_DETAIL
				RD left join VPR0_PRODUCT P
				on(P.PR0_PRODUCT_ID=RD.RQ1_PRODUCT_ID) WHERE $defaultWhereClause
=== 2013-12-03 07:15:46,315 [01-5] INFO  SQLDataSource - [builtinApplication.null] 122: Executing SQL query on 'EAD': SELECT 
				RQ1_ID, RQ1_MODE, RQ1_MID, RQ1_MMODE,
				RQ1_CUS_HOLDING_ID,
				RQ1_PRODUCT_ID,
				RQ1_PRODUCT_NUMBER,
				RQ1_PRODUCT_STATE,
				RQ1_PRODUCT_STATE_V,
				RQ1_REQESTED_QUANTITY,
				RQ1_ISSUED_QUANTITY,
				RQ1_CONVERSION_RATE,
				RQ1_LOCK_ID,
				RQ1_CREATED_USER_ID, RQ1_CREATED_USER_ROLE,  
				RQ1_CREATED_USER_SMP,   
				RQ1_ASSIGNEE_ID,
				RQ1_CUS_TYPE, RQ1_CUS_TYPE_V, RQ1_PRODUCT_UOM_ID,
				P.PR0_NAME_ARABIC,
				P.PR0_DESCRIPTION,
				DECODE(P.PR0_IS_SERIAL_DEFINED,'Y','true','N','false') as
				PR0_IS_SERIAL_DEFINED,
				RQ1_ASSIGNEE_TYPE_V,
				RQ1_ASSIGNEE_TYPE,
				RQ1_ASSIGNEE_QIDNO, RQ1_ASSIGNEE_RANK, RQ1_ASSIGNEE_STAFF_NUMBER,
				RQ1_ASSIGNEE_DEPARTMENT, RQ1_PRODUCT_PKG_ID ,
				RQ1_ASSIGNEE_OFFICE_ID, RQ1_ASSIGNEE_SECTION_ID,
				RQ1_ASSIGNEE_UNIT_ID,
				RQ1_ASSIGNEE_VISA_NUM, RQ1_ASSIGNEE_ID AS
				ASSIGNEE_DESC, 
				RQ1_PRODUCT_UNIT_PRICE,
				RQ1_PRODUCT_TOTAL_PRICE,RQ1_ASSIGNEE_PLATE_TYPE,
				RQ1_ASSIGNEE_PLATE_NUMBER,

				(SELECT COM_DEP_ARABIC_NAME FROM
				VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ARABIC,

				(SELECT COM_DEP_ENGLISH_NAME FROM VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ENGLISH,

				(SELECT CON_SEC_ARABIC_NAME FROM VCON_SECTION
				WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ARABIC,

				(SELECT CON_SEC_ENGLISH_NAME FROM
				VCON_SECTION WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ENGLISH,

				(SELECT COO_UNIT_ARABIC_NAME FROM VCOO_UNIT
				WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ARABIC,

				(SELECT COO_UNIT_ENGLISH_NAME FROM VCOO_UNIT WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ENGLISH FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ARABIC FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ARABIC,
				(SELECT CU2_OFFICE_AR_NAME FROM VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ARABIC,

				(SELECT CU2_OFFICE_EN_NAME FROM
				VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ENGLISH, 
				RQ1_LASTUPDATED_USER_ID, RQ1_LASTUPDATED_USER_ROLE, 
				RQ1_LASTUPDATED_USER_SMP, RQ1_REQESTED_QUANTITY/RQ1_CONVERSION_RATE REQUESTED_QUANTITY  
      	   FROM VRQ1_REQUISITION_DETAIL
				RD left join VPR0_PRODUCT P
				on(P.PR0_PRODUCT_ID=RD.RQ1_PRODUCT_ID) WHERE (VRQ1_REQUISITION_DETAIL.RQ1_MMODE='D' AND VRQ1_REQUISITION_DETAIL.RQ1_ASSIGNEE_TYPE_V='Department' AND VRQ1_REQUISITION_DETAIL.RQ1_ASSIGNEE_DEPARTMENT='044' AND VRQ1_REQUISITION_DETAIL.RQ1_PRODUCT_NUMBER='037/000007' AND VRQ1_REQUISITION_DETAIL.RQ1_MID='461ea5dd8a8240dcac6321bbb3cc36e7')
=== 2013-12-03 07:15:46,315 [01-5] DEBUG SQLConnectionManager - [builtinApplication.null] Borrowed connection '272764994'
=== 2013-12-03 07:15:46,315 [01-5] DEBUG SQLDriver - [builtinApplication.null] About to execute SQL query in 'EAD' using connection '272764994'
=== 2013-12-03 07:15:46,315 [01-5] INFO  SQLDriver - [builtinApplication.null] Executing SQL query on 'EAD': SELECT 
				RQ1_ID, RQ1_MODE, RQ1_MID, RQ1_MMODE,
				RQ1_CUS_HOLDING_ID,
				RQ1_PRODUCT_ID,
				RQ1_PRODUCT_NUMBER,
				RQ1_PRODUCT_STATE,
				RQ1_PRODUCT_STATE_V,
				RQ1_REQESTED_QUANTITY,
				RQ1_ISSUED_QUANTITY,
				RQ1_CONVERSION_RATE,
				RQ1_LOCK_ID,
				RQ1_CREATED_USER_ID, RQ1_CREATED_USER_ROLE,  
				RQ1_CREATED_USER_SMP,   
				RQ1_ASSIGNEE_ID,
				RQ1_CUS_TYPE, RQ1_CUS_TYPE_V, RQ1_PRODUCT_UOM_ID,
				P.PR0_NAME_ARABIC,
				P.PR0_DESCRIPTION,
				DECODE(P.PR0_IS_SERIAL_DEFINED,'Y','true','N','false') as
				PR0_IS_SERIAL_DEFINED,
				RQ1_ASSIGNEE_TYPE_V,
				RQ1_ASSIGNEE_TYPE,
				RQ1_ASSIGNEE_QIDNO, RQ1_ASSIGNEE_RANK, RQ1_ASSIGNEE_STAFF_NUMBER,
				RQ1_ASSIGNEE_DEPARTMENT, RQ1_PRODUCT_PKG_ID ,
				RQ1_ASSIGNEE_OFFICE_ID, RQ1_ASSIGNEE_SECTION_ID,
				RQ1_ASSIGNEE_UNIT_ID,
				RQ1_ASSIGNEE_VISA_NUM, RQ1_ASSIGNEE_ID AS
				ASSIGNEE_DESC, 
				RQ1_PRODUCT_UNIT_PRICE,
				RQ1_PRODUCT_TOTAL_PRICE,RQ1_ASSIGNEE_PLATE_TYPE,
				RQ1_ASSIGNEE_PLATE_NUMBER,

				(SELECT COM_DEP_ARABIC_NAME FROM
				VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ARABIC,

				(SELECT COM_DEP_ENGLISH_NAME FROM VCOM_DEP WHERE
				VCOM_DEP.COM_DEP_NUMBER=RQ1_ASSIGNEE_DEPARTMENT) as
				DEP_NAME_ENGLISH,

				(SELECT CON_SEC_ARABIC_NAME FROM VCON_SECTION
				WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ARABIC,

				(SELECT CON_SEC_ENGLISH_NAME FROM
				VCON_SECTION WHERE
				VCON_SECTION.CON_ID=RQ1_ASSIGNEE_SECTION_ID) as
				SECTION_NAME_ENGLISH,

				(SELECT COO_UNIT_ARABIC_NAME FROM VCOO_UNIT
				WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ARABIC,

				(SELECT COO_UNIT_ENGLISH_NAME FROM VCOO_UNIT WHERE
				VCOO_UNIT.COO_ID=RQ1_ASSIGNEE_UNIT_ID) as UNIT_NAME_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ENGLISH FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ENGLISH,
				(Select VPR1_PRODUCT_PKG.PR1_PKG_NAME_ARABIC FROM VPR1_PRODUCT_PKG where VPR1_PRODUCT_PKG.PR1_ID = RQ1_PRODUCT_PKG_ID) as PKG_ARABIC,
				(SELECT CU2_OFFICE_AR_NAME FROM VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ARABIC,

				(SELECT CU2_OFFICE_EN_NAME FROM
				VCU2_MOI_OFFICES WHERE
				VCU2_MOI_OFFICES.CU2_DEPOFFICE_ID=RQ1_ASSIGNEE_OFFICE_ID) as
				OFFICE_NAME_ENGLISH, 
				RQ1_LASTUPDATED_USER_ID, RQ1_LASTUPDATED_USER_ROLE, 
				RQ1_LASTUPDATED_USER_SMP, RQ1_REQESTED_QUANTITY/RQ1_CONVERSION_RATE REQUESTED_QUANTITY  
      	   FROM VRQ1_REQUISITION_DETAIL
				RD left join VPR0_PRODUCT P
				on(P.PR0_PRODUCT_ID=RD.RQ1_PRODUCT_ID) WHERE (VRQ1_REQUISITION_DETAIL.RQ1_MMODE='D' AND VRQ1_REQUISITION_DETAIL.RQ1_ASSIGNEE_TYPE_V='Department' AND VRQ1_REQUISITION_DETAIL.RQ1_ASSIGNEE_DEPARTMENT='044' AND VRQ1_REQUISITION_DETAIL.RQ1_PRODUCT_NUMBER='037/000007' AND VRQ1_REQUISITION_DETAIL.RQ1_MID='461ea5dd8a8240dcac6321bbb3cc36e7')
=== 2013-12-03 07:15:46,346 [01-5] DEBUG SQLTransform - [builtinApplication.null] isBeforeFirst()/isAfterLast() throwing exceptions - attempting workaround
=== 2013-12-03 07:15:46,346 [01-5] INFO  DSResponse - [builtinApplication.null] DSResponse: List with 1 items
=== 2013-12-03 07:15:46,346 [01-5] DEBUG SQLDriver - Freeing SQLDriver dbConnection 272764994
=== 2013-12-03 07:15:46,346 [01-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "272764994"
2013-12-03 07:15:46,346 - TRACE - q.g.m.e.c.e.ExternalSystemManager - 207 - getAssigneeInformation -  - assigneeType - Department - direction - rtl - 157017637168611
=== 2013-12-03 07:15:46,346 [01-5] INFO  DSResponse - DSResponse: List with 1 items
2013-12-03 07:15:46,455 - DEBUG - q.g.m.e.u.helpers.ERPUtility - 289 - getMessageValues - getMessageLabel.messageDTO.get_messageCode() : custody.requisition.product.assignee.duplicate.validation.error
=== 2013-12-03 07:15:46,455 [01-5] DEBUG ValidationContext - Adding validation errors at path '/TRQ1_REQUISITION_DETAIL/RQ1_PRODUCT_NUMBER/RQ1_PRODUCT_NUMBER': {errorMessage=This Product already exists in the child for the selected Assignee. Please select a different product or Assignee.}
=== 2013-12-03 07:15:46,471 [01-5] INFO  Validation - Validation error: [
    {
        RQ1_PRODUCT_NUMBER:{
            errorMessage:"This Product already exists in the child for the selected Assignee. Please select a different product or Assignee."
        }
    }
]
=== 2013-12-03 07:15:46,471 [01-5] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2013-12-03 07:15:46,471 [01-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2013-12-03 07:15:46,471 [01-5] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1849716288
=== 2013-12-03 07:15:46,471 [01-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1849716288"
=== 2013-12-03 07:15:46,471 [01-5] DEBUG SQLDriver - Freeing SQLDriver dbConnection 540287028
=== 2013-12-03 07:15:46,471 [01-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "540287028"
=== 2013-12-03 07:15:46,471 [01-5] INFO  Compression - /ERP/isomorphic/IDACall: 323 -> 244 bytes