Fixes ISSUE-50012: Enables logging info about slow datasource queries

Configuration

Configuration is done in the Datasource Observability Configuration window, using the System Administrator role:

Configuration is done per tab. For each tab that needs to be monitored we need to select it and also specify a number of milliseconds (0 if the field is left empty). Then, when a datasource request is done to request data from that tab, if datasource query took longer that the number of milliseconds specified, information about that query will be written in the log.

Separate log file setup

It is possible to write the observability log in a separate log file. This lets us take advantage of all featured log4j provides us regarding file handling, log rotation, etc.

To configure this feature, add the following in config/log4j2-web.xml:

• In the <Appenders> section, add a new file appender. The following is an example but you can adjust it in order to suit your needs:

		<RollingFile name="DatasourceEventsFile"
			fileName="${logDir}/observability/datasource_events.log"
			filePattern="${logDir}/observability/datasource_events-%d{yyyyMMdd}-%i.log.gz">
			<PatternLayout pattern="%m%n" />
			<Policies>
				<SizeBasedTriggeringPolicy size="100MB" />
				<TimeBasedTriggeringPolicy />
			</Policies>
			<DefaultRolloverStrategy max="30">
				<Delete basePath="${logDir}">
					<IfFileName glob="datasource_events-*.log.gz">
						<IfAccumulatedFileCount exceeds="30" />
					</IfFileName>
				</Delete>
			</DefaultRolloverStrategy>
		</RollingFile>

• In the <Loggers> section add a new logger called "DatasourceEvents" that uses your newly created file appender as its only appender:

		<Logger name="DatasourceEvents" level="info" additivity="false">
			<AppenderRef ref="DatasourceEventsFile" />
		</Logger>

Demo

See here an example, after configuring all requests to the header tab of the sales order window to be written into a separate file:

This is the JSON object that was written in the log in one of the demoed events:

{"type":"dsEvent","tabIdentifier":"Header - Sales Order","logTime":"Fri Aug 19 10:15:34 CEST 2022","duration":14,"query":"select e from Order as e where ( e.salesTransaction=true AND e.transactionDocument.return= false AND e.transactionDocument.sOSubType NOT LIKE 'OB' ) and e.organization.id in (:_dal_readableOrganizations_dal_) and e.client.id in (:_dal_readableClients_dal_)order by e.documentNo,e.id","params":{"tabId":"186","_textMatchStyle":"substring","_noCount":"true","whereAndFilterClause":"e.salesTransaction=true AND e.transactionDocument.return= false AND e.transactionDocument.sOSubType NOT LIKE 'OB'","Constants_IDENTIFIER":"_identifier","@Order.documentType@":"null","@Order.posted@":"null","_operationType":"fetch","_sortBy":"documentNo","isc_dataFormat":"json","@Order.partnerAddress@":"null","_extraProperties":"","_className":"OBViewDataSource","@Order.shippingCompany@":"null","@Order.processed@":"null","_componentId":"isc_OBViewGrid_0","@Order.client@":"null","@Order.deliveryMethod@":"null","_startRow":"0","_endRow":"100","_entityName":"Order","_selectedProperties":"id,client,organization,updatedBy,updated,creationDate,createdBy,documentNo,orderDate,grandTotalAmount,aPRMAddPayment,documentAction,copyFrom,copyFromPO,calculatePromotions,obdiscAddpack,cancelandreplace,confirmcancelandreplace,rtestLalaa,obomsocOrderconfirmation,processNow,posted,generateTemplate,Replacementorder_ID,processed,grandTotalAmount,documentStatus,cancelledorder,iscancelled,alternateLocation,quotation,cancelledorder,replacedorder,externalBusinessPartnerReference,obpos2OrgSchema,obscoErrors,obscoTimeSpent,obomsRun,organization,transactionDocument,orderDate,businessPartner,partnerAddress,priceList,scheduledDeliveryDate,warehouse,documentStatus,grandTotalAmount,currency,documentType,deliveryMethod,shippingCompany,freightCostRule,replacementorder,id,client,processed,salesTransaction,posted,transactionDocument,transactionDocument,id,client,id,processNow,processed,organization,documentNo,transactionDocument,orderDate,businessPartner,partnerAddress,grandTotalAmount,currency,documentStatus,deliveryStatus,invoiceStatus,iscancelled,cashVAT,delivered","moduleId":"0","@Order.transactionDocument@":"null","sendOriginalIDBack":"true","@Order.freightCostRule@":"null","@Order.organization@":"null","@Order.id@":"null","_noActiveFilter":"true","@Order.documentStatus@":"null","@Order.priceList@":"null","isc_metaDataPrefix":"_","@Order.orderDate@":"null","@Order.scheduledDeliveryDate@":"null","@Order.warehouse@":"null","dataSourceName":"Order","@Order.businessPartner@":"null","windowId":"143","_dataSource":"isc_OBViewDataSource_0","whereClauseHasBeenChecked":"false","_use_alias":"true","isImplicitFilterApplied":"false","@Order.salesTransaction@":"null","@Order.grandTotalAmount@":"null","Constants_FIELDSEPARATOR":"$","@Order.currency@":"null","@Order.replacementorder@":"null"}}