Logging

While Flexter runs, it collects and displays relevant logs as a list of recorded events:

10:09:34.227 INFO Initialized in 3055 milliseconds

The example shows the timestamp of the event, its level (INFO highlights progress in the process) and the corresponding message. Other levels you can see when executing Flexter:

• WARN if the application encountered a potentially harmful situation
• ERROR which highlights a possible cause of failure

Flexter logging is built on top of the Log4j APIs, a package which is freely distributed under the Apache Software License.

The configuration is a file of properties stored as key-value pairs, e.g.

• log4j2.properties (Spark 3.3+)
• log4j.properties (Spark 3.1-3.2)

rootLogger.level = warn
rootLogger.appenderRef.stdout.ref = stdout
rootLogger.appenderRef.stderr.ref = stderr

log4j.rootCategory=WARN,stdout,stderr

The –log or -L parameter

You can customise this configuration using the -L parameter and pointing to the path of your log4j2.properties or log4j.properties file:

# Spark 3.3 or higher
xml2er -L /path/to/log4j2.properties ...

# Spark 3.1-3.2
xml2er -L /path/to/log4j.properties ...

Common log4j configuration locations

Alternatively, place the file in one of the locations that are picked up by default, listed in order of precedence:

# 1. Current folder
./log4j2.properties
./log4j.properties

# 2. User home folder
~/.config/flexter/log4j2.properties
~/.config/flexter/log4j.properties
%LOCALDATA%/flexter/log4j2.properties
%LOCALDATA%/flexter/log4j.properties

# 3. Installation folder
/etc/flexter/conf/log4j2.properties
/etc/flexter/conf/log4j.properties
%ProgramFiles(x86)%/flexter/conf/log4j2.properties
%ProgramFiles(x86)%/flexter/conf/log4j.properties

Log Levels in different sections

Log4j has 7 levels:

• OFF: Disable the log entirely
• FATAL: Prints the log when it finishes with a fatal error
• ERROR: Prints other errors and fatal errors
• WARN: Prints warnings, errors and fatal errors
• INFO: Prints info logs, warnings, errors and fatal errors
• DEBUG: Prints debug logs, info, errors and fatal errors
• TRACE: Prints trace logs, debug, info, errors and fatal errors

With these options it’s possible to filter the Flexter logs per section, like below:

• log4j2.properties (Spark 3.3+)
• log4j.properties (Spark 3.1-3.2)

rootLogger.level = warn
rootLogger.appenderRef.stdout.ref = stdout
rootLogger.appenderRef.stderr.ref = stderr

...

# FLEXTER
logger.flexter_spark_metrics.name = io.sonra.flexter.spark.metrics
logger.flexter_spark_metrics.level = info
logger.flexter_spark_schema.name = io.sonra.flexter.spark.schema
logger.flexter_spark_schema.level = info
logger.flexter_spark_parser.name = io.sonra.flexter.spark.parser
logger.flexter_spark_parser.level = info
logger.flexter_xml_parser.name = io.sonra.flexter.xml.parser
logger.flexter_xml_parser.level = info
logger.flexter_json_parser.name = io.sonra.flexter.json.parser
logger.flexter_json_parser.level = info
logger.flexter.name = io.sonra.flexter
logger.flexter.level = info

log4j.rootCategory=WARN,stdout,stderr

...

# FLEXTER
log4j.logger.io.sonra.flexter.spark.metrics=INFO
log4j.logger.io.sonra.flexter.spark.schema=INFO
log4j.logger.io.sonra.flexter.spark.parser=INFO
log4j.logger.io.sonra.flexter.xml.parser=INFO
log4j.logger.io.sonra.flexter.json.parser=INFO
log4j.logger.io.sonra.flexter=INFO

Flexter uses the following loggers:

• io.sonra.flexter.spark.metrics: Messages when the --metrics parameter is on
• io.sonra.flexter.spark.schema: Messages when the data flow (mapped schema) is loaded from the Flexter metadata
• io.sonra.flexter.spark.parser: Messages when Flexter is parsing the JSON/XML files
• io.sonra.flexter.xml.parser: Messages when Flexter is parsing the XML files
• io.sonra.flexter.json.parser: Messages when Flexter is parsing the JSON files
• io.sonra.flexter: All messages related to Flexter

File output appender

To turn on generating log files:

• log4j2.properties (Spark 3.3+)
• log4j.properties (Spark 3.1-3.2)

#rootLogger.appenderRef.file.ref=file

log4j.rootCategory=WARN,stdout,stderr,file

By default, one file is generated per job in the first of these locations that is writable:

1. /var/log/flexter
2. ~/.cache/flexter/log
3. %LOCALDATA%/flexter/log
4. ./

Other log4j appenders are available for logging into files, such as RollingFileAppender and DailyRollingFileAppender, which are recommended to keep all jobs in the same log files.

It’s also possible to change the file name path with the setting below:

• log4j2.properties (Spark 3.3+)
• log4j.properties (Spark 3.1-3.2)

appender.file.routes.default.file.fileName=${ctx:loc}/${ctx:app}_${ctx:job}_${ctx:user}_${ctx:appId}.log

log4j.appender.file.Encoding={loc}/{app}_{job}_{user}_{appId}.log

The variables mentioned above:

SQL Commands

Another handy option is the -c or --commands parameter, which can be used for debugging purposes. All the SQL commands are then exposed in the logs, showing what is actually happening behind the scenes. For instance:

10:09:34.227 INFO Initialized in 3055 milliseconds
10:09:34.232 INFO Parsing data
10:09:35.044 INFO calculating xpath statistics
INSERT INTO schma(sch_name, id_org) VALUES('donut', 1) ;

WITH rps AS (SELECT 20 AS jump) ,setget AS (SELECT jump ,setval('seq_du_stat', nextval('seq_du_stat')+jump-1) as end_id FROM rps) SELECT end_id-jump+1 AS begin_id FROM setget ;

10:09:40.996 INFO writing xpath statistics
batching 19 statements: 1: INSERT INTO "du_stat" ("du_addr","du_ns","id_du","id_parent_du","found_qty","found_ne_qty","max_length_char_num","numeric_max_decimal_precision","per_parent_min_occurs","per_parent_min_ne_occurs","per_parent_max_occurs","per_parent_max_ne_occurs","min_val","max_val","mixed_flg","id_du_stat","id_parent_du_stat","du_name","du_type_cd","stat_stdtype","datetime_field_ord","id_job","id_sch") VALUES ('/items/item/fillings/filling',NULL,NULL,NULL,7,0,0,NULL,3,0,4,0,NULL,NULL,false,3945823,3945822,'filling','e',NULL,NULL,16019,4639)
2: INSERT INTO "du_stat" ("du_addr","du_ns","id_du","id_parent_du","found_qty","found_ne_qty","max_length_char_num","numeric_max_decimal_precision","per_parent_min_occurs","per_parent_min_ne_occurs","per_parent_max_occurs","per_parent_max_ne_occurs","min_val","max_val","mixed_flg","id_du_stat","id_parent_du_stat","du_name","du_type_cd","stat_stdtype","datetime_field_ord","id_job","id_sch") VALUES ('/items',NULL,NULL,NULL,1,0,0,NULL,0,0,0,0,NULL,NULL,false,3945820,NULL,'items','e',NULL,NULL,16019,4639)
...
10:09:43.252 INFO updating schema origin 4639
10:09:43.253 INFO calculating document statistics
10:09:44.879 INFO writing document statistics
batching 1 statements: 1: INSERT INTO "doc_stat" ("id_doc","id_doc32","id_doc_num","status_flg","du_addr_qty","converter_calls_qty","converter_errors_qty","converter_warns_qty","truncations_qty","empty_notnull_qty","missing_maps_qty","fks_qty","missing_fks_qty","parser_warns_qty","doc_size","id_job","id_sch") VALUES ('Documents/flexter/samples/donut.zip!/donut.xml','ter/samples/donut.zip!/donut.xml',NULL,'C',154,0,0,0,0,0,154,0,0,0,4644,16019,4639) ;