Merge pull request #204 from xtuml/188_enhance_logging

188 enhance logging
xtuml · Apr 23, 2024 · ecfe207 · ecfe207
2 parents 0855bb5 + 659f6a6
commit ecfe207
Show file tree

Hide file tree

Showing 28 changed files with 388 additions and 145 deletions.
diff --git a/bin/.env b/bin/.env
@@ -1 +1 @@
-MASL_VERSION=4.4.3-logging
+MASL_VERSION=4.4.3-logging2
diff --git a/bin/plus2json.pyz b/bin/plus2json.pyz
diff --git a/deploy/.env b/deploy/.env
@@ -1 +1 @@
-MASL_VERSION=4.4.3-logging
+MASL_VERSION=4.4.3-logging2
diff --git a/deploy/config/benchmarking-config.json b/deploy/config/benchmarking-config.json
@@ -16,12 +16,12 @@
   "DefaultBlockedAuditEventDuration": "PT5S",
   "JobStoreAgeLimit": "PT1H",
   "InvariantStoreLoadRate": "PT2M",
-  "MaxIntraSequenceEventTimeoutPeriod": "PT1S",
+  "MaxIntraSequenceEventTimeoutPeriod": "PT2S",
   "WaitPeriodForAllJobsCompletedCheck": "P1D",
   "WaitPeriodForJobDeletion": "PT0S",
   "WaitPeriodForInvariantDeletion": "P1D",
   "TimeoutPeriodForRetreivingStoredInvariants": "PT10S",
-  "TimeoutPeriodForHangingJob": "PT2S",
+  "TimeoutPeriodForHangingJob": "PT10S",
   "MaxJobsPerWorker": "500",
   "MaxUnassignedJobs": "100000",
   "RetiredWorkerDeletionTime": "PT10M",

diff --git a/deploy/config/configure-kafka.sh b/deploy/config/configure-kafka.sh
@@ -1,5 +1,6 @@
 #!/bin/bash
 
 # configure topics
-/opt/kafka/bin/kafka-configs.sh --alter --bootstrap-server kafka:9093 --topic JobManagement_service0 --add-config retention.ms=60000
+/opt/kafka/bin/kafka-configs.sh --alter --bootstrap-server kafka:9093 --topic Protocol_Verifier_Reception --add-config retention.ms=60000
+/opt/kafka/bin/kafka-configs.sh --alter --bootstrap-server kafka:9093 --topic Protocol_Verifier_InfoWarn --add-config retention.ms=6000000
 /opt/kafka/bin/kafka-configs.sh --alter --bootstrap-server kafka:9093 --topic BenchmarkingProbe_service0 --add-config retention.ms=6000000
diff --git a/deploy/config/log-config-pv-proc.properties → deploy/config/log-pv-files.properties b/deploy/config/log-config-pv-proc.properties → deploy/config/log-pv-files.properties
@@ -19,7 +19,7 @@ log4cplus.logger.pv=INFO, pv_appender
 log4cplus.additivity.pv=FALSE
 
 # domain loggers
-log4cplus.logger.pv.jm=INFO, pv_appender
+log4cplus.logger.pv.jm=INFO, pv_jm_appender
 #log4cplus.logger.pv.jm=DEBUG, pv_appender, pv_debug_appender
 log4cplus.additivity.pv.jm=FALSE
 log4cplus.logger.pv.aeo=INFO, pv_appender
@@ -44,14 +44,25 @@ log4cplus.logger.pv.vg.audit=FATAL, pv_vg_audit_appender
 log4cplus.additivity.pv.vg.audit=FALSE
 
 # benchmarking logger
-# Enable by setting to INFO.
-log4cplus.logger.pv.benchmark=FATAL, pv_benchmark_appender
+# Enable by setting to INFO.  Disable by setting to FATAL.
+log4cplus.logger.pv.benchmark=INFO, pv_benchmark_appender
 log4cplus.additivity.pv.benchmark=FALSE
 
+log4cplus.appender.pv_jm_appender=log4cplus::RollingFileAppender
+log4cplus.appender.pv_jm_appender.File=/var/log/protocol_verifier/pv_jm.log
+log4cplus.appender.pv_jm_appender.Threshold=INFO
+log4cplus.appender.pv_jm_appender.AsyncAppend=TRUE
+log4cplus.appender.pv_jm_appender.UseLockFile=TRUE
+log4cplus.appender.pv_jm_appender.MaxFileSize=50MB
+log4cplus.appender.pv_jm_appender.MaxBackupIndex=5
+log4cplus.appender.pv_jm_appender.layout=log4cplus::PatternLayout
+log4cplus.appender.pv_jm_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m%n
+
 log4cplus.appender.pv_appender=log4cplus::RollingFileAppender
 log4cplus.appender.pv_appender.File=/var/log/protocol_verifier/pv.log
 log4cplus.appender.pv_appender.Threshold=INFO
 log4cplus.appender.pv_appender.AsyncAppend=TRUE
+log4cplus.appender.pv_appender.UseLockFile=TRUE
 log4cplus.appender.pv_appender.MaxFileSize=50MB
 log4cplus.appender.pv_appender.MaxBackupIndex=5
 log4cplus.appender.pv_appender.layout=log4cplus::PatternLayout
@@ -63,6 +74,7 @@ log4cplus.appender.pv_debug_appender.filters.1=log4cplus::spi::LogLevelRangeFilt
 log4cplus.appender.pv_debug_appender.filters.1.LogLevelMax=DEBUG
 log4cplus.appender.pv_debug_appender.filters.1.LogLevelMin=TRACE
 log4cplus.appender.pv_debug_appender.AsyncAppend=TRUE
+log4cplus.appender.pv_debug_appender.UseLockFile=TRUE
 log4cplus.appender.pv_debug_appender.MaxFileSize=50MB
 log4cplus.appender.pv_debug_appender.MaxBackupIndex=5
 log4cplus.appender.pv_debug_appender.layout=log4cplus::PatternLayout
@@ -71,6 +83,7 @@ log4cplus.appender.pv_debug_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %F
 log4cplus.appender.pv_vg_audit_appender=log4cplus::RollingFileAppender
 log4cplus.appender.pv_vg_audit_appender.File=/var/log/protocol_verifier/pv_vg_audit.log
 log4cplus.appender.pv_vg_audit_appender.AsyncAppend=TRUE
+log4cplus.appender.pv_vg_audit_appender.UseLockFile=TRUE
 log4cplus.appender.pv_vg_audit_appender.MaxFileSize=50MB
 log4cplus.appender.pv_vg_audit_appender.MaxBackupIndex=5
 log4cplus.appender.pv_vg_audit_appender.layout=log4cplus::PatternLayout
@@ -79,14 +92,9 @@ log4cplus.appender.pv_vg_audit_appender.layout.ConversionPattern=%d{%FT%T.%q}Z -
 log4cplus.appender.pv_benchmark_appender=log4cplus::RollingFileAppender
 log4cplus.appender.pv_benchmark_appender.File=/var/log/protocol_verifier/pv_benchmark.log
 log4cplus.appender.pv_benchmark_appender.AsyncAppend=TRUE
+log4cplus.appender.pv_benchmark_appender.UseLockFile=TRUE
 log4cplus.appender.pv_benchmark_appender.MaxFileSize=50MB
 log4cplus.appender.pv_benchmark_appender.MaxBackupIndex=5
 log4cplus.appender.pv_benchmark_appender.layout=log4cplus::PatternLayout
-log4cplus.appender.pv_benchmark_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m%n
-
-#log4cplus.appender.pv_benchmark_appender=xtuml::KafkaAppender
-#log4cplus.appender.pv_benchmark_appender.topic=BenchmarkingProbe_service0
-#log4cplus.appender.pv_benchmark_appender.layout=log4cplus::PatternLayout
-#log4cplus.appender.pv_benchmark_appender.layout=xtuml::JsonLayout
-#log4cplus.appender.pv_benchmark_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m
+log4cplus.appender.pv_benchmark_appender.layout.ConversionPattern={"timestamp":"%d{%FT%T.%q}Z",%m}%n
 
diff --git a/deploy/config/log-pv-kafka.properties b/deploy/config/log-pv-kafka.properties
@@ -0,0 +1,82 @@
+# Protocol Verifier Logger Configuration
+#
+# Notes:
+#
+# - Each logger has additivity FALSE so that the root logger does not
+#   repeat to the console.
+#
+
+# Root logger logs to the console.
+log4cplus.rootLogger=FATAL, console
+
+# console logger
+log4cplus.appender.console=log4cplus::ConsoleAppender
+log4cplus.appender.console.layout=log4cplus::PatternLayout
+log4cplus.appender.console.layout.ConversionPattern=%d{%FT%T}Z - %m%n
+
+# hierarchical loggers
+log4cplus.logger.pv=INFO, pv_svk_appender
+log4cplus.additivity.pv=FALSE
+
+# domain loggers
+log4cplus.logger.pv.jm=INFO, pv_jmk_appender
+#log4cplus.logger.pv.jm=DEBUG, pv_jmk_appender, pv_debug_appender
+log4cplus.additivity.pv.jm=FALSE
+log4cplus.logger.pv.aeo=INFO, pv_svk_appender
+#log4cplus.logger.pv.aeo=DEBUG, pv_svk_appender, pv_debug_appender
+log4cplus.additivity.pv.aeo=FALSE
+log4cplus.logger.pv.sv=INFO, pv_svk_appender
+#log4cplus.logger.pv.sv=DEBUG, pv_svk_appender, pv_debug_appender
+log4cplus.additivity.pv.sv=FALSE
+log4cplus.logger.pv.istore=INFO, pv_svk_appender
+#log4cplus.logger.pv.istore=DEBUG, pv_svk_appender, pv_debug_appender
+log4cplus.additivity.pv.istore=FALSE
+log4cplus.logger.pv.vg=INFO, pv_svk_appender
+#log4cplus.logger.pv.vg=DEBUG, pv_svk_appender, pv_debug_appender
+log4cplus.additivity.pv.vg=FALSE
+log4cplus.logger.pv.fr=INFO, pv_svk_appender
+#log4cplus.logger.pv.fr=DEBUG, pv_svk_appender, pv_debug_appender
+log4cplus.additivity.pv.fr=FALSE
+
+# audit event logger
+# Enable by setting to INFO.
+log4cplus.logger.pv.vg.audit=FATAL, pv_vg_auditk_appender
+log4cplus.additivity.pv.vg.audit=FALSE
+
+# benchmarking logger
+# Enable by setting to INFO.  Disable by setting to FATAL.
+log4cplus.logger.pv.benchmark=FATAL, pv_benchmark_appender
+log4cplus.additivity.pv.benchmark=FALSE
+
+log4cplus.appender.pv_jmk_appender=xtuml::KafkaAppender
+log4cplus.appender.pv_jmk_appender.topic=Protocol_Verifier_Statistics
+log4cplus.appender.pv_jmk_appender.layout=log4cplus::PatternLayout
+log4cplus.appender.pv_jmk_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m%n
+
+log4cplus.appender.pv_svk_appender=xtuml::KafkaAppender
+log4cplus.appender.pv_svk_appender.topic=Protocol_Verifier_InfoWarn
+log4cplus.appender.pv_svk_appender.layout=log4cplus::PatternLayout
+log4cplus.appender.pv_svk_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m%n
+
+#log4cplus.appender.pv_debug_appender=log4cplus::RollingFileAppender
+#log4cplus.appender.pv_debug_appender.File=/var/log/protocol_verifier/pv_debug.log
+#log4cplus.appender.pv_debug_appender.filters.1=log4cplus::spi::LogLevelRangeFilter
+#log4cplus.appender.pv_debug_appender.filters.1.LogLevelMax=DEBUG
+#log4cplus.appender.pv_debug_appender.filters.1.LogLevelMin=TRACE
+#log4cplus.appender.pv_debug_appender.AsyncAppend=TRUE
+#log4cplus.appender.pv_debug_appender.UseLockFile=TRUE
+#log4cplus.appender.pv_debug_appender.MaxFileSize=50MB
+#log4cplus.appender.pv_debug_appender.MaxBackupIndex=5
+#log4cplus.appender.pv_debug_appender.layout=log4cplus::PatternLayout
+#log4cplus.appender.pv_debug_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %F:%L %m%n
+
+log4cplus.appender.pv_vg_auditk_appender=xtuml::KafkaAppender
+log4cplus.appender.pv_vg_auditk_appender.topic=Protocol_Verifier_VGateway
+log4cplus.appender.pv_vg_auditk_appender.layout=log4cplus::PatternLayout
+log4cplus.appender.pv_vg_auditk_appender.layout.ConversionPattern=%d{%FT%T.%q}Z - %m%n
+
+log4cplus.appender.pv_benchmark_appender=xtuml::KafkaAppender
+log4cplus.appender.pv_benchmark_appender.topic=BenchmarkingProbe_service0
+log4cplus.appender.pv_benchmark_appender.layout=log4cplus::PatternLayout
+log4cplus.appender.pv_benchmark_appender.layout.ConversionPattern={"timestamp":"%d{%FT%T.%q}Z",%m}
+
diff --git a/deploy/config/pv-config.json b/deploy/config/pv-config.json
@@ -13,7 +13,7 @@
   "JobDefinitionDirectory": "config/job_definitions",
   "DefaultJobExpiryDuration": "P99W",
   "DefaultStaleAuditEventDuration": "PT10M",
-  "DefaultBlockedAuditEventDuration": "PT55S",
+  "DefaultBlockedAuditEventDuration": "PT5S",
   "JobStoreAgeLimit": "PT1H",
   "InvariantStoreLoadRate": "PT2M",
   "MaxIntraSequenceEventTimeoutPeriod": "PT5S",
@@ -27,5 +27,5 @@
   "RetiredWorkerDeletionTime": "PT01M",
   "WorkerHeartbeatRate": "PT1M",
   "WorkerHeartbeatFailureThreshold": "3",
-  "ReportFrequency": "PT1S"
+  "ReportFrequency": "PT5S"
 }
diff --git a/deploy/docker-compose.kafka.yml b/deploy/docker-compose.kafka.yml
@@ -19,14 +19,12 @@ services:
       - "../models/PV_PROC/build:/work/build"
       - "../models/PV_PROC/schedule:/root/schedule"
       - "./config:/root/config"
-      - "./logs/protocol_verifier:/var/log/protocol_verifier"
-      - "./JM_PROC-db:/root/JM_PROC-db"
     ulimits:
       sigpending: -1
     logging:
       driver: local
     working_dir: /root
-    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/JM_PROC_transient -log-config config/log-config-pv-proc.properties -configFile ${CONFIG_FILE:-pv-config.json} -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
+    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/JM_PROC_transient -log-config config/log-pv-kafka.properties -configFile ${CONFIG_FILE:-pv-config.json} -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
 
   istore_proc:
     image: levistarrett/masl-dev:${MASL_VERSION:-latest}
@@ -40,14 +38,13 @@ services:
       - "../models/PV_PROC/build:/work/build"
       - "../models/PV_PROC/schedule:/root/schedule"
       - "./config:/root/config"
-      - "./logs/protocol_verifier:/var/log/protocol_verifier"
       - "./InvariantStore:/root/InvariantStore"
     ulimits:
       sigpending: -1
     logging:
       driver: local
     working_dir: /root
-    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/ISTORE_PROC_sqlite -db ./InvariantStore/InvariantStore.db -log-config config/log-config-pv-proc.properties -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
+    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/ISTORE_PROC_sqlite -db ./InvariantStore/InvariantStore.db -log-config config/log-pv-kafka.properties -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
 
   aeo_svdc_proc:
     image: levistarrett/masl-dev:${MASL_VERSION:-latest}
@@ -63,14 +60,12 @@ services:
       - "../models/PV_PROC/build:/work/build"
       - "../models/PV_PROC/schedule:/root/schedule"
       - "./config:/root/config"
-      - "./logs/protocol_verifier:/var/log/protocol_verifier"
-      - "./InvariantStore:/root/InvariantStore"
     ulimits:
       sigpending: -1
     logging:
       driver: local
     working_dir: /root
-    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/AEO_SVDC_PROC_transient -log-config config/log-config-pv-proc.properties -configFile ${CONFIG_FILE:-pv-config.json} -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
+    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/AEO_SVDC_PROC_transient -log-config config/log-pv-kafka.properties -configFile ${CONFIG_FILE:-pv-config.json} -util Kafka -kafka-broker-list kafka:9093 -util MetaData"
 
   zookeeper:
     image: wurstmeister/zookeeper:3.4.6
@@ -97,7 +92,7 @@ services:
       # KAFKA_LOG_ROLL_MS: 60000                      # roll the log every minute
       KAFKA_LOG_SEGMENT_DELETE_DELAY_MS: 1            # delete immediately after log roll
       KAFKA_LOG_RETENTION_CHECK_INTERVAL_MS: 10000    # check the retention condition every 10 seconds
-      KAFKA_CREATE_TOPICS: "Protocol_Verifier_Reception:1:1,JobManagement_service0:1:1,JobManagement_service1:1:1,JobManagement_service2:1:1,JobManagement_service3:1:1,JobManagement_service4:1:1,JobManagement_service5:1:1,JobManagement_service6:1:1,AEOrdering_service0:1:1,AEOrdering_service1:1:1,AEOrdering_service2:1:1,AEOrdering_service3:1:1,AEOrdering_service4:1:1,AEOrdering_service5:1:1,AEOrdering_service6:1:1,AEOrdering_service7:1:1,AEOrdering_service8:1:1,AEOrdering_service9:1:1,AESequenceDC_service12:1:1,AESequenceDC_service31:1:1,IStore_service0:1:1,IStore_service1:1:1,IStore_service2:1:1,IStore_service3:1:1,IStore_service4:1:1,BenchmarkingProbe_service0:1:1"
+      KAFKA_CREATE_TOPICS: "Protocol_Verifier_Reception:1:1,Protocol_Verifier_InfoWarn:1:1,Protocol_Verifier_Statistics:1:1,Protocol_Verifier_VGateway:1:1,JobManagement_service0:1:1,JobManagement_service1:1:1,JobManagement_service2:1:1,JobManagement_service3:1:1,JobManagement_service4:1:1,JobManagement_service5:1:1,JobManagement_service6:1:1,AEOrdering_service0:1:1,AEOrdering_service1:1:1,AEOrdering_service2:1:1,AEOrdering_service3:1:1,AEOrdering_service4:1:1,AEOrdering_service5:1:1,AEOrdering_service6:1:1,AEOrdering_service7:1:1,AEOrdering_service8:1:1,AEOrdering_service9:1:1,AESequenceDC_service12:1:1,AESequenceDC_service31:1:1,IStore_service0:1:1,IStore_service1:1:1,IStore_service2:1:1,IStore_service3:1:1,IStore_service4:1:1,BenchmarkingProbe_service0:1:1"
     volumes:
       - /var/run/docker.sock:/var/run/docker.sock
 

diff --git a/deploy/docker-compose.yml b/deploy/docker-compose.yml
@@ -23,7 +23,7 @@ services:
     working_dir: /root
     logging:
       driver: local
-    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/PV_PROC_transient -fileStore -configFile pv-config.json -log-config config/log-config-pv-proc.properties -util Inspector"
+    command: bash -c "source /work/build/Release/generators/conanrun.sh && export LD_LIBRARY_PATH=$${LD_LIBRARY_PATH}:/work/build/Release/lib && /work/build/Release/bin/PV_PROC_transient -fileStore -configFile pv-config.json -log-config config/log-pv-files.properties -util Inspector"
 
 volumes:
   ConanCache: