Loading...

XML

Word

Printable

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 4.0.23
Affects Version/s: 4.0.7
Component/s: Rule Compiler/Interpreter
Labels:
None

Steps to Reproduce:

Hide

see above

Show
see above
Affects:

Compatibility/Configuration, User Experience
Workaround:

Workaround Exists
Workaround Description:

Hide

Remove the COMPILE option

Show
Remove the COMPILE option
Products:

Azure Red Hat Openshift

I have my application running inside Felix Server. I need to track a method execution time. For that at method entry a started a timer and then when method Exit, the timer is stopped and the end time is calculated.

Application code:

package com.alcatel.tpapps.common.monitoring.client;

public class RestMonitoringJobRegistry extends BaseMonitoringJobRegistry
{
           

public synchronized <T> void updateMonitoredState(
            MonitoringJob<T> aInMonitoringJob, T aInState)
    {
        if (aInMonitoringJob == null || aInState == null)
        {
            TPAResources.debug(logger,
                    "Cannot send: missing required information.");
            return;
        }

..
..
    }

At Entry:

RULE record_startTime_RestMonitoringJobRegistry
CLASS com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry
METHOD updateMonitoredState
COMPILE
AT ENTRY
BIND
    LOGGER:Logger = com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.logger;
    startTime = System.currentTimeMillis();
IF true
DO
    LOGGER.info("[JA] AT ENTRY");
    link(Thread.currentThread(), "startTime", startTime);
ENDRULE

At Exit:

RULE check_duration_RestMonitoringJobRegistry
CLASS com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry
METHOD updateMonitoredState
COMPILE
AT EXIT
BIND
    LOGGER:Logger = com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.logger;
    startTime:int = unlink(Thread.currentThread(), "startTime");
    endTime = System.currentTimeMillis()
IF true
DO
    LOGGER.info("[JA] AT EXIT: updateMonitoredState took elapsedTime [" + (endTime - startTime) + "] $aInMonitoringJob.getKey() [" + $aInMonitoringJob.getKey() +"]");
    
ENDRULE

The rules are pushed, there are no error/exceptions thrown at submit time, but getting exceptions at runtime as:

{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.725Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"WARN","log":{"classname":"com.mypackage.monitoring.client.BaseMonitoringJobRegistry$MonitoringTask:210","message":"Exception occurred while running monitoring job 'MonitoringJobRegistration{pollingInterval=5, key='rerate_eoc_kafka_consumer_group'}' : check_duration_RestMonitoringJobRegistry  : caught java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack : stacktraceInfo : org.jboss.byteman.rule.Rule.execute(Rule.java:841),org.jboss.byteman.rule.Rule.execute(Rule.java:778),","stacktrace":"","threadname":"MonitoringJobRegistry-2"},"process":"run","service":"","time":"2024-03-22T00:20:50.725Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.731Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"WARN","log":{"classname":"com.mypackage.monitoring.client.BaseMonitoringJobRegistry$MonitoringTask:210","message":"Exception occurred while running monitoring job 'MonitoringJobRegistration{pollingInterval=5, key='ltm_client'}' : check_duration_RestMonitoringJobRegistry  : caught java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack : stacktraceInfo : org.jboss.byteman.rule.Rule.execute(Rule.java:841),org.jboss.byteman.rule.Rule.execute(Rule.java:778),","stacktrace":"","threadname":"MonitoringJobRegistry-4"},"process":"run","service":"","time":"2024-03-22T00:20:50.731Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.732Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"WARN","log":{"classname":"com.mypackage.monitoring.client.BaseMonitoringJobRegistry$MonitoringTask:210","message":"Exception occurred while running monitoring job 'MonitoringJobRegistration{pollingInterval=5, key='httpio'}' : check_duration_RestMonitoringJobRegistry  : caught java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack : stacktraceInfo : org.jboss.byteman.rule.Rule.execute(Rule.java:841),org.jboss.byteman.rule.Rule.execute(Rule.java:778),","stacktrace":"","threadname":"MonitoringJobRegistry-3"},"process":"run","service":"","time":"2024-03-22T00:20:50.732Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"WARN","log":{"classname":"com.mypackage.monitoring.client.BaseMonitoringJobRegistry$MonitoringTask:210","message":"Exception occurred while running monitoring job 'MonitoringJobRegistration{pollingInterval=5, key='diameterio'}' : check_duration_RestMonitoringJobRegistry  : caught java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack : stacktraceInfo : org.jboss.byteman.rule.Rule.execute(Rule.java:841),org.jboss.byteman.rule.Rule.execute(Rule.java:778),","stacktrace":"","threadname":"MonitoringJobRegistry-6"},"process":"run","service":"","time":"2024-03-22T00:20:50.733Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.734Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.734Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"WARN","log":{"classname":"com.mypackage.monitoring.client.BaseMonitoringJobRegistry$MonitoringTask:210","message":"Exception occurred while running monitoring job 'MonitoringJobRegistration{pollingInterval=5, key='policy'}' : check_duration_RestMonitoringJobRegistry  : caught java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack : stacktraceInfo : org.jboss.byteman.rule.Rule.execute(Rule.java:841),org.jboss.byteman.rule.Rule.execute(Rule.java:778),","stacktrace":"","threadname":"MonitoringJobRegistry-8"},"process":"run","service":"","time":"2024-03-22T00:20:50.735Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"ERROR","log":{"classname":"com.pkg.as.service.log.impl.asrlog.Stdout2Log4jOutputStream$StdoutRedirectorThread:104","message":"check_duration_RestMonitoringJobRegistry : java.lang.VerifyError: (class: org/jboss/byteman/rule/helper/Helper_HelperAdapter_Compiled_53, method: execute0 signature: ()V) Expecting to find integer on stack","stacktrace":"","threadname":"StdoutThread"},"process":"run","service":"","time":"2024-03-22T00:20:50.735Z","timezone":"Asia/Kolkata","type":"log"}

While when I remove the COMPILE option, all is well:

{"host":"host","level":"INFO","log":{"classname":"org.jboss.byteman.rule.helper.Helper_HelperAdapter_Compiled_51:11","message":"[JA] AT ENTRY","stacktrace":"","threadname":"MonitoringJobRegistry-4"},"process":"execute0","service":"","time":"2024-03-22T00:20:30.714Z","timezone":"Asia/Kolkata","type":"log"}
{"host":"host","level":"INFO","log":{"classname":"sun.reflect.GeneratedMethodAccessor173:?","message":"[JA] AT EXIT: updateMonitoredState took elapsedTime [1] $aInMonitoringJob.getKey() [ltm_client]","stacktrace":"","threadname":"MonitoringJobRegistry-4"},"process":"invoke","service":"","time":"2024-03-22T00:20:30.715Z","timezone":"Asia/Kolkata","type":"log"}

I raised this issue on stackoverflow

https://stackoverflow.com/questions/78203507/getting-runtime-exception-with-compile-option/78521905#78521905

and team suggested to open a defect

with additional information.

I did that: -Dorg.jboss.byteman.verbose

tpaadmin  3384     0 43 18:53 pts/0    00:03:05 /opt/tpa/java/bin/java --add-opens=java.base/jdk.internal.loader=ALL-UNNAMED -Dgroup.name=FE -Dcomponent.name=component -Dinstance.name=instance -Dinstance.pid=3262 -Dhost.name=localhost -Dplatform.name=asr -Dconfig.dir=/opt/SPS_24_0_R1/osgi/instance -DINSTALL_DIR=/opt/SPS_24_0_R1/osgi -Dbundle.installer=bundles/com.alcatel.as.service.bundleinstaller.impl-1.0.18.jar -Dfelix.config.properties=file:/opt/SPS_24_0_R1/osgi/instance/felix.properties -DFastCacheImpl.retryConnect=true -Dk8s.namespace=ig1 -cp bundles/org.apache.felix.main-7.0.1.jar:bundles/com.alcatel.as.felix.launcher-1.0.18.jar:/opt/jdk11deps/classpath/JAF-1.0.2.jar:/opt/jdk11deps/classpath/jaxb-api.jar:/opt/jdk11deps/classpath/jaxb-core.jar:/opt/jdk11deps/classpath/jaxb-impl.jar:/opt/SPS_24_0_R1/osgi/instance:/opt/SPS_24_0_R1/osgi/resource:/opt/SPS_24_0_R1/osgi/resource -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=3333 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.registry.ssl=true -Dcom.sun.management.jmxremote.ssl=true -Dcom.sun.management.jmxremote.ssl.need.client.auth=true -Djava.security.egd=file:/dev/./urandom -Djavax.net.ssl.keyStore=/opt/tpa/conf/sac/server.keystore -Djavax.net.ssl.trustStore=/opt/tpa/conf/sac/server.keystore -Dlog4j2.formatMsgNoLookups=true -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent -XX:+UseStringDeduplication -XX:+ParallelRefProcEnabled -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/opt/tpa/logs/ -XX:G1ReservePercent=20 -XX:InitiatingHeapOccupancyPercent=45 -XX:MaxGCPauseMillis=250 -XX:MaxMetaspaceSize=256M -XX:MetaspaceSize=128M -XX:CompressedClassSpaceSize=64M -server -Xms1536m -Xmx1536m -Xss512k -Djavax.xml.soap.MetaFactory=com.sun.xml.messaging.saaj.soap.SAAJMetaFactoryImpl -Djavax.xml.soap.SAAJMetaFactory=com.sun.xml.messaging.saaj.soap.SAAJMetaFactoryImpl -Djavax.xml.ws.spi.Provider=com.sun.xml.ws.spi.ProviderImpl -Djdk.attach.allowAttachSelf=true -Dorg.apache.cxf.binding.soap.messageFactoryClassName=com.sun.xml.messaging.saaj.soap.ver1_1.SOAPMessageFactory1_1Impl --add-opens java.base/jdk.internal.loader=ALL-UNNAMED --add-opens java.base/sun.net.util=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.math=ALL-UNNAMED --add-opens java.management/sun.management=ALL-UNNAMED --add-opens java.management/javax.management.modelmbean=ALL-UNNAMED --add-opens jdk.attach/sun.tools.attach=ALL-UNNAMED --add-opens java.base/sun.security.tools.keytool=ALL-UNNAMED --add-opens java.base/sun.security.x509=ALL-UNNAMED --add-opens java.base/java.net=ALL-UNNAMED --add-opens java.base/java.text=ALL-UNNAMED --illegal-access=warn -Xlog:gc*:file=/opt/tpa/logs/gc.log:time,level,tags:filecount=8,filesize=8m -Djava.security.properties=/opt/tpa/osgi/instance/java.security -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=0.0.0.0:5005 -Dunifiedlogging.host=ig-centralmanagement-0 -Dunifiedlogging.system=ig1 -Dunifiedlogging.systemname=ig1 -Dunifiedlogging.systemid=1 -Dunifiedlogging.timezone=GMT -Dunifiedlogging.port=8514 -Dunifiedlogging.timestamp=UTC -Dorg.jboss.byteman.verbose -XX:+UnlockDiagnosticVMOptions -XX:+UnsyncloadClass -Djava.awt.headless=true -Djava.library.path=lib:/opt/tpa/lib -Djava.util.logging.config.file=/opt/SPS_24_0_R1/osgi/instance/jul.properties com.alcatel.as.felix.FelixLauncher /opt/SPS_24_0_R1/osgi/instance/felix.properties component FE__instance 0 ig-centralmanagement-0 3262 localhost false

# File 1.btm line 20
RULE check_duration_RestMonitoringJobRegistry
CLASS com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry
METHOD updateMonitoredState
COMPILE
AT EXIT
BIND
LOGGER:Logger = com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.logger;
startTime:int = unlink(Thread.currentThread(), "startTime");
endTime = System.currentTimeMillis()
IF true
DO
LOGGER.info("[JA] AT EXIT: updateMonitoredState took elapsedTime [" + (endTime - startTime) + "] $aInMonitoringJob.getKey() [" + $aInMonitoringJob.getKey() +"]");ENDRULE
Transformed in:
loader: com.nokia.tpapps.common-monitoring-client [129]
trigger method: com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.updateMonitoredState(com.alcatel.tpapps.common.common.monitoring.MonitoringJob,java.lang.Object) void
compiled successfully

# File 1.btm line 6
RULE record_startTime_RestMonitoringJobRegistry
CLASS com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry
METHOD updateMonitoredState
COMPILE
AT ENTRY
BIND
LOGGER:Logger = com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.logger;
startTime = System.currentTimeMillis();
IF true
DO
LOGGER.info("[JA] AT ENTRY");
link(Thread.currentThread(), "startTime", startTime);
ENDRULE
Transformed in:
loader: com.nokia.tpapps.common-monitoring-client [129]
trigger method: com.alcatel.tpapps.common.monitoring.client.RestMonitoringJobRegistry.updateMonitoredState(com.alcatel.tpapps.common.common.monitoring.MonitoringJob,java.lang.Object) void
compiled successfully

logs are attached.

Its a kubernetes env. I am running on microk8s, and inside a pod.

[root@asif-mk8s-8 ig1]# microk8s kubectl version
Client Version: version.Info{Major:"1", Minor:"21+", GitVersion:"v1.21.13-3+cbc10c94808907", GitCommit:"cbc10c9480890724de6cfadc4c95aaa8d81cabdd", GitTreeState:"clean", BuildDate:"2022-06-08T09:56:13Z", GoVersion:"go1.16.15", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"21+", GitVersion:"v1.21.13-3+cbc10c94808907", GitCommit:"cbc10c9480890724de6cfadc4c95aaa8d81cabdd", GitTreeState:"clean", BuildDate:"2022-06-08T09:53:55Z", GoVersion:"go1.16.15", Compiler:"gc", Platform:"linux/amd64"}

Byteman version

Agent Version: 4.0.7

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

cm4.log
1.02 MB
2024/05/24 7:58 PM
cm3.log
4.19 MB
2024/05/24 7:58 PM
cm2.log
3.86 MB
2024/05/24 7:49 PM
cm1.log
3.31 MB
2024/05/24 7:26 PM

Assignee:: Andrew Dinn

Reporter:: Narendra SINGH2 (Inactive)

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Created:: 2024/05/24 7:26 PM

Updated:: 2024/05/29 9:58 PM

Resolved:: 2024/05/28 11:28 AM

Details

Description

Attachments

Attachments

Easy Agile Planning Poker

Activity

People

Dates