Unable to see api metrics in api manager
Closed this issue · 10 comments
Describe the bug
Metrics in API Manager aren't accessible.
Severity of the problem [CRITICAL]
To Reproduce
Steps to reproduce the behavior:
Expected behavior
Similar to the view in node manager, we need to be able to see the metrics in api manager. The node manager allows metrics up-to 5days, whereas, the api manager can allow custom date to be provided, which is the main need here
Technical context(please complete the following information):
- Helmchart version: 2.10.1
- Kubernetes version: v1.23.0
- Kubernetes distribution: EKS
Hello @dokuboyejo, Could you show me the environment variable for api-manager component please ? Are you using the mysql component ?
@NComandini it looks like below
externalMetricsDB:
env:
- name: METRICS_DB_URL
value: "jdbc:mysql://<host>:3306/metrics?useSSL=false"
- name: METRICS_DB_USERNAME
value: "...."
- name: METRICS_DB_PASS
valueFrom:
secretKeyRef:
name: "...."
key: "...."
Thank you. I suppose the host value has been replaced.
Could you check logs on apimgr and anm pods for any issue with the mysql connection (read/write/access to mysql) ?
@NComandini double checked the anm logs, no error on mysql connection, but unsure why it's not writing metrics to the DB
DEBUG 20/Sep/2022:18:39:55.812 [0001:000000000000000000000000] The field 'timeToIdleSeconds' expanded '${env.WEBMANAGER.SESSION.IDLE.TIMEOUT}' to '1800
DATA 20/Sep/2022:18:39:55.812 [0001:000000000000000000000000] configure loadable module JDBCDriverSet/JDBC Drivers in pack [local]-0-[local], load order = 92, classLoader = java.net.URLClassLoader@7186333e
DEBUG 20/Sep/2022:18:39:55.813 [0001:000000000000000000000000] JDBCDriverSet {
ESPK: PrimaryStore:-8573337843464290957
ParentPK: (ES_NULL_PK)
Key Fields:
name: {JDBC Drivers}
Fields:
_version: {3}
class: {com.vordel.store.system.JDBCDrivers}
loadorder: {92}
}
DATA 20/Sep/2022:18:39:55.813 [0001:000000000000000000000000] configure loadable module DbConnectionGroup/Database Connections in pack [local]-0-[local], load order = 93, classLoader = java.net.URLClassLoader@7186333e
DEBUG 20/Sep/2022:18:39:55.813 [0001:000000000000000000000000] DbConnectionGroup {
ESPK: ExtConnsStore:1118597239691800889
ParentPK: (ES_NULL_PK)
Key Fields:
name: {Database Connections}
Fields:
class: {com.vordel.common.db.DbConnectionCache}
_version: {1}
loadorder: {93}
}
DATA 20/Sep/2022:18:39:55.889 [0001:000000000000000000000000] configure loadable module MetricsGenerator/Metrics Generation Configuration in pack [local]-0-[local], load order = 95, classLoader = java.net.URLClassLoader@7186333e
DEBUG 20/Sep/2022:18:39:55.890 [0001:000000000000000000000000] MetricsGenerator {
ESPK: PrimaryStore:-5276339373454762122
ParentPK: (ES_NULL_PK)
Key Fields:
name: {Metrics Generation Configuration}
Fields:
dbConn: {<key type='DbConnectionGroup'><id field='name' value='Database Connections'/><key type='DbConnection'><id field='name' value='Default Database Connection'/></key></key>}
dbWriterThreadPoolSize: {5}
dirSizeMb: {1024}
enabled: {1}
logMgtPollFrequencySecs: {300}
metricInsertBatchSize: {1000}
numEventLogsWaiting: {1}
pollFrequencySecs: {5}
processCustomMessageAttributes: {true}
processCustomMetrics: {true}
processedEventLogDir: {${environment.VDISTDIR}/events/processed}
retainProcessedEventLogs: {false}
sourceEventLogDir: {${environment.VDISTDIR}/events}
storeMetricsAgainstUniqueClients: {true}
_version: {0}
class: {com.vordel.metrics.generator.MetricsGenerator}
loadorder: {95}
}
DEBUG 20/Sep/2022:18:39:55.891 [0001:000000000000000000000000] decrypting ciphertext in PBKDF2_HMAC_CipherAES256 mode...
DEBUG 20/Sep/2022:18:39:55.897 [0001:000000000000000000000000] DbConnection {
ESPK: ExtConnsStore:-615689434358873227
ParentPK: (ES_NULL_PK)
Key Fields:
name: {Default Database Connection}
Fields:
initialSize: {0}
maxActive: {8}
maxIdle: {8}
maxWait: {10000}
minEvictableIdleTimeMillis: {1000}
minIdle: {0}
numTestsPerEvictionRun: {3}
password: {XXXXXX}
passwordType: {entered}
setPoolPreparedStatements: {0}
timeBetweenEvictionRunsMillis: {-1}
timezoneAware: {0}
url: {${environment.METRICS_DB_URL}}
username: {${environment.METRICS_DB_USERNAME}}
wildcardPassword: {}
_version: {2}
}
DEBUG 20/Sep/2022:18:39:55.897 [0001:000000000000000000000000] Setting up per user datasource for DB Connection: Default Database Connection
DEBUG 20/Sep/2022:18:39:55.902 [0001:000000000000000000000000] decrypting ciphertext in PBKDF2_HMAC_CipherAES256 mode...
DEBUG 20/Sep/2022:18:39:55.905 [0001:000000000000000000000000] [Default Database Connection] The URL jdbc:mysql://<host-redacted>:3306/metrics?useSSL=false
DEBUG 20/Sep/2022:18:39:55.908 [0001:000000000000000000000000] Selector: Registering ELResolver: com.vordel.el.PropertiesResolver
DEBUG 20/Sep/2022:18:39:55.908 [0001:000000000000000000000000] Retrieving the productName from the jdbc url of database jdbc:mysql://<host-redacted>:3306/metrics?useSSL=false
DEBUG 20/Sep/2022:18:39:55.908 [0001:000000000000000000000000] [Default Database Connection] The DbDriver productName from the URL is mysql
DEBUG 20/Sep/2022:18:39:55.909 [0001:000000000000000000000000] [Default Database Connection] TZ aware: false
DEBUG 20/Sep/2022:18:39:58.011 [0001:000000000000000000000000] DB Connection testOnReturn: true
DEBUG 20/Sep/2022:18:39:58.089 [0001:000000000000000000000000] DB Connection removeAbandoned: true
DEBUG 20/Sep/2022:18:39:58.089 [0001:000000000000000000000000] DB Connection removeAbandonedTimeout: 300
DEBUG 20/Sep/2022:18:40:00.910 [0001:000000000000000000000000] DB Connection successfully loaded: com.mysql.cj.jdbc.Driver
DATA 20/Sep/2022:18:40:01.199 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.492 [0001:000000000000000000000000] Processing column of type: INTEGER
DATA 20/Sep/2022:18:40:01.496 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DEBUG 20/Sep/2022:18:40:01.499 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.499 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.499 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.500 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.500 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.500 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.500 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.500 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.501 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.502 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.505 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.506 [0001:000000000000000000000000] Processing column of type: CHAR
DATA 20/Sep/2022:18:40:01.510 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DEBUG 20/Sep/2022:18:40:01.512 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.589 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.589 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: VARCHAR
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: INTEGER
DEBUG 20/Sep/2022:18:40:01.590 [0001:000000000000000000000000] Processing column of type: VARCHAR
DATA 20/Sep/2022:18:40:01.595 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.601 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.690 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.696 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.702 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.707 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.794 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.800 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.804 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.892 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.897 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.901 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.905 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.992 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:01.996 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.093 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.097 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.101 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.105 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.109 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.114 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.189 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.195 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.199 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.203 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.207 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.212 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.216 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.221 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.293 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DATA 20/Sep/2022:18:40:02.299 [0001:000000000000000000000000] DataSource after getConnection {numActive = 1, numIdle = 0}
DEBUG 20/Sep/2022:18:40:02.393 [0001:000000000000000000000000] MetricsEventLogRetriever: scheduling job every: 5 seconds
INFO 20/Sep/2022:18:40:02.394 [0001:000000000000000000000000] Writing to the metrics database is enabled, sourceEventLogDir=/opt/Axway/apigateway/events, processCustomMetrics=true, processCustomMessageAttributes=true, metricInsertBatchSize=1000, dbWriterThreadPoolSize=5, numEventLogsWaiting=1, storeMetricsAgainstUniqueClients=true, retainProcessedEventLogs=false
DATA 20/Sep/2022:18:40:02.394 [0001:000000000000000000000000] configure loadable module NamespacesConfiguration/Namespace Configuration in pack [local]-0-[local], load order = 100, classLoader = java.net.URLClassLoader@7186333e
DEBUG 20/Sep/2022:18:40:02.394 [0001:000000000000000000000000] NamespacesConfiguration {
ESPK: PrimaryStore:-8473055413683039451
ParentPK: (ES_NULL_PK)
Key Fields:
name: {Namespace Configuration}
Fields:
_version: {1}
class: {com.vordel.common.EntityStoreNamespaceProvider}
loadorder: {100}
}
Thank you.
I see that metrics is correctly configured.
But I don't see any logs that wrote data.
Could you verify your events log persistant volume to be sure that some data are written and reachable from the ANM pod please ?
@NComandini I confirmed no issues with the volumes
For the actual events writes to the DB, any idea what could cause it not to be working?
I tried it on many installations and can confirmed the same behaviors, the events aren't been written to DB
Ok, so volumes are correclty mounted on pods.
Have you verified that apimgr and apitraffic events logs are visible in the anm pod events folder (/opt/Axway/apigateway/events/) ?
You must see those lines in anm logs :
INFO 10/Oct/2022:14:40:05.598 [004b:000000000000000000000000] Wrote 12 metrics to DB in 231 ms for 'traffic-7cf75d57f5-5lt8d', time window start: Mon Oct 10 14:35:00 UTC 2022
Could you check also that something is written in those files ?
@NComandini Yes, affirmative, the logs are written to the event folder
However, not seeing Wrote x metrics to DB in x ms for...
To summarize our verifications:
- Gateway pods write correclty events in the events folder (it means that server settings logging are good).
- ANM pod is able to read this file (no issues in logs)
- ANM pod has a correct configuration to access the mysql database.
I suspect a bad configuration but impossible to find it.
Could you open an Axway support case by resuming our tests ?
I will be able to help you directly.
I close this issue.
The problem is related to the kind of storage that you are using for Read Write Many access mode.
The storage must be a NFS like. Only the EFS storage is compatible in AWS context.