search

rickbansal-mulesoft / otel-mule4-observability-agent

12 stars 6 forks source link

Failed to send traces in Hybrid and RTF implementation. #10

Closed ksawant17 closed 5 months ago

ksawant17 commented 1 year ago

Hi Rick,

Thanks for the detailed documentation and the custom connector. I have followed all the steps mentioned in the doc and configured OTLP connector in one of the test app. While testing from Studio, the connector works as expected and I could see the traces in Dynatrace. But as I deploy the same app in our self managed RTF cluster, I don't see any traces being sent out to Dynatrace. Same issue I am seeing with our hybrid implementation of Mule.

Current RTF setup using Azure kubernetes and Hybrid implementation is on Windows and Redhat linux. Mule Version - 4.4.0

In the debug logs there is no trace or exception. 

[2023-04-26 20:32:07.674] DEBUG MulePipelineNotificationListener [http.listener.06 SelectorRunner] [event: ]: ===> Received org.mule.runtime.api.notification.PipelineMessageNotification:pipeline process start
[2023-04-26 20:32:07.675] DEBUG OTelMuleNotificationHandler [http.listener.06 SelectorRunner] [event: ]: Handling flow start event
[2023-04-26 20:32:07.717] INFO  OtelSdkConnection [http.listener.06 SelectorRunner] [event: ]: Initializing the OpenTelemetry Mule 4 Observability Agent org.mulesoft.extension.otel.mule4.observability.agent:1.0.0
[2023-04-26 20:32:07.734] DEBUG OtlpTraceExporterConfig [http.listener.06 SelectorRunner] [event: ]: get certificate : is empty:true
[2023-04-26 20:32:07.734] INFO  OtlpTraceExporterConfig [http.listener.06 SelectorRunner] [event: ]: Trace processing is ENABLED
[2023-04-26 20:32:07.734] INFO  OtlpMetricExporterConfig [http.listener.06 SelectorRunner] [event: ]: Metric processing is DISABLED
[2023-04-26 20:32:08.089] INFO  MuleMetricMemoryUsage [http.listener.06 SelectorRunner] [event: ]: Initializing the Memory Usage Metric
[2023-04-26 20:32:08.090] INFO  MuleMetricSystemWorkload [http.listener.06 SelectorRunner] [event: ]: Initializing the System Workload Utilization Metric
[2023-04-26 20:32:08.119] DEBUG MuleConnectorConfigStore [http.listener.06 SelectorRunner] [event: ]: Application source files folder: /opt/mule/apps/helloworldapp
[2023-04-26 20:32:08.122] DEBUG MuleConnectorConfigStore [http.listener.06 SelectorRunner] [event: ]: Application source files folder: /opt/mule/apps/helloworldapp
[2023-04-26 20:32:08.123] DEBUG MuleConnectorConfigStore [http.listener.06 SelectorRunner] [event: ]: Application source files folder: /opt/mule/apps/helloworldapp
[2023-04-26 20:32:08.144] DEBUG MuleMessageProcessorNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: ]: ===> Received org.mule.runtime.api.notification.MessageProcessorNotification:message processor pre invoke
[2023-04-26 20:32:08.144] DEBUG OTelMuleNotificationHandler [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: ]: Handling processor start event
[2023-04-26 20:32:08.198] DEBUG TracingProcessorInterceptor [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: ]: created TRACE_CONTEXT_MAP_KEY variable for MuleSoft traceId (correlationId): 69d0c380-e471-11ed-8927-9aa7100e4bbf
[2023-04-26 20:32:08.305] DEBUG MuleMessageProcessorNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: ===> Received org.mule.runtime.api.notification.MessageProcessorNotification:message processor post invoke
[2023-04-26 20:32:08.305] DEBUG OTelMuleNotificationHandler [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: Handling end event
[2023-04-26 20:32:08.308] DEBUG MuleMessageProcessorNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: ===> Received org.mule.runtime.api.notification.MessageProcessorNotification:message processor pre invoke
[2023-04-26 20:32:08.308] DEBUG OTelMuleNotificationHandler [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: Handling processor start event
[2023-04-26 20:32:08.346] DEBUG TracingProcessorInterceptor [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: around::Intercepted a logger message resolved: {
  "out": "app"
}
[2023-04-26 20:32:08.346] DEBUG TracingProcessorInterceptor [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: around::Intercepted a logger processor
[2023-04-26 20:32:08.352] INFO  LoggerMessageProcessor [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: {
  "out": "app"
}
[2023-04-26 20:32:08.352] DEBUG TracingProcessorInterceptor [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: around::Intercepted a logger processor
[2023-04-26 20:32:08.353] DEBUG MuleMessageProcessorNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: ===> Received org.mule.runtime.api.notification.MessageProcessorNotification:message processor post invoke
[2023-04-26 20:32:08.353] DEBUG OTelMuleNotificationHandler [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: Handling end event
[2023-04-26 20:32:08.356] DEBUG MulePipelineNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: ===> Received org.mule.runtime.api.notification.PipelineMessageNotification:pipeline request message processing end
[2023-04-26 20:32:08.405] DEBUG MulePipelineNotificationListener [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: ===> Received org.mule.runtime.api.notification.PipelineMessageNotification:pipeline process complete
[2023-04-26 20:32:08.406] DEBUG OTelMuleNotificationHandler [[MuleRuntime].uber.03: [helloworldapp].helloworldFlow.CPU_LITE @3c7f7dc5] [event: 69d0c380-e471-11ed-8927-9aa7100e4bbf]: Handling flow end event

by looking at it further on the pod using netstat, I do not even see any new connection initialized to APM tool. I have tested it with Jagar Otel collector and i don't see any connections opened on port 4318. 

app@helloworldapp-7d6f6f8467-7sppw:/opt/mule$ netstat -an | grep ESTABLISHED
tcp        0      0 100.64.13.84:50470      3.85.187.110:443        ESTABLISHED
tcp        0      0 100.64.13.84:38496      10.16.10.193:9999       ESTABLISHED
tcp        0      0 127.0.0.1:34000         127.0.0.1:31000         ESTABLISHED
tcp        0      0 100.64.13.84:38490      10.16.10.193:9999       ESTABLISHED
tcp        0      0 100.64.13.84:55974      34.200.193.228:5044     ESTABLISHED
tcp        0      0 100.64.13.84:52812      3.85.187.110:443        ESTABLISHED
tcp        0      0 127.0.0.1:31000         127.0.0.1:34000         ESTABLISHED
udp     2560      0 100.64.13.84:40872      192.168.0.10:53         ESTABLISHED

Is there any known compatibility issue with self hosted runtime? or am I missing something?

Here is the configuration that I am using

POM - Locally compiled after checkout

<dependency>
            <groupId>org.mulesoft.extensions.otel</groupId>
            <artifactId>otel-mule4-observability-agent</artifactId>
            <version>1.0.0</version>
            <classifier>mule-plugin</classifier>
        </dependency>

Mule xml 

<?xml version="1.0" encoding="UTF-8"?>

<mule xmlns:azure-key-vault-properties-provider="http://www.mulesoft.org/schema/mule/azure-key-vault-properties-provider" xmlns:otel-mule4-observablity-agent="http://www.mulesoft.org/schema/mule/otel-mule4-observablity-agent"
    xmlns:opentelemetry="http://www.mulesoft.org/schema/mule/opentelemetry"
    xmlns:tls="http://www.mulesoft.org/schema/mule/tls" xmlns:http="http://www.mulesoft.org/schema/mule/http" xmlns="http://www.mulesoft.org/schema/mule/core" xmlns:doc="http://www.mulesoft.org/schema/mule/documentation" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.mulesoft.org/schema/mule/core http://www.mulesoft.org/schema/mule/core/current/mule.xsd
http://www.mulesoft.org/schema/mule/http http://www.mulesoft.org/schema/mule/http/current/mule-http.xsd
http://www.mulesoft.org/schema/mule/tls http://www.mulesoft.org/schema/mule/tls/current/mule-tls.xsd
http://www.mulesoft.org/schema/mule/opentelemetry http://www.mulesoft.org/schema/mule/opentelemetry/current/mule-opentelemetry.xsd
http://www.mulesoft.org/schema/mule/otel-mule4-observablity-agent http://www.mulesoft.org/schema/mule/otel-mule4-observablity-agent/current/mule-otel-mule4-observablity-agent.xsd
http://www.mulesoft.org/schema/mule/azure-key-vault-properties-provider http://www.mulesoft.org/schema/mule/azure-key-vault-properties-provider/current/mule-azure-key-vault-properties-provider.xsd">
    <http:listener-config name="HTTP_Listener_config" doc:name="HTTP Listener config" doc:id="4a71ffa5-16a5-4f54-bc59-ebec31e965ad" >
        <http:listener-connection host="0.0.0.0" port="4310" protocol="HTTPS" tlsContext="TLS_Context">
        </http:listener-connection>
    </http:listener-config>
    <tls:context name="TLS_Context" doc:name="TLS Context" doc:id="3c98251b-abc3-4f8d-a4df-bf553145078a" >
        <tls:trust-store insecure="true" />
        <tls:key-store type="jks" path="server.keystore.jks" keyPassword="******" password="********" />
    </tls:context>
    <otel-mule4-observablity-agent:config name="OpenTelemetry_Mule_4_Observablity_Agent_Config" doc:name="OpenTelemetry Mule 4 Observablity Agent Config" doc:id="d6c06539-04dd-4035-8087-e0b658b170c4" traceCollectorEndpoint="https://vws.live.dynatrace.com/api/v2/otlp/v1/traces" serviceName="mule-test-aws">
        <otel-mule4-observablity-agent:resource-attributes >
            <otel-mule4-observablity-agent:attribute key="env" value="sb1" />
        </otel-mule4-observablity-agent:resource-attributes>
        <otel-mule4-observablity-agent:trace-headers >
            <otel-mule4-observablity-agent:header key="Authorization" value="Api-Token ****************************************************************" />
        </otel-mule4-observablity-agent:trace-headers>
        <otel-mule4-observablity-agent:bypass-components >
        </otel-mule4-observablity-agent:bypass-components>
    </otel-mule4-observablity-agent:config>
    <flow name="helloworldFlow" doc:id="835e39b1-93bf-4395-848f-eebca4051899" >
        <http:listener doc:name="Listener" doc:id="b95d3daa-54df-449a-82bf-054a8a470373" config-ref="HTTP_Listener_config" path="/ping"/>
        <set-payload value='#[%dw 2.0
&#10;output application/json&#10;---
&#10;{
&#10;   "out" : "app"
&#10;}]' doc:name="Set Payload 1" doc:id="45f9b4fa-54a1-48fe-b66f-0990134f97ec" mimeType="application/json" encoding="UTF-8"/>
        <logger level="INFO" doc:name="Logger" doc:id="fa66955f-0ce6-476c-95f7-a5f8a2d258c1" message="#[payload]" />
    </flow>
</mule>
ksawant17 commented 1 year ago

Sorry I couldnt attach a complete log for some reason. If more details are needed please let me know.

Thanks, Kamlesh

rickbansal-mulesoft commented 1 year ago

Hi Kamlesh, I've updated the extension and will be updating the documentation shortly. Can you please tell me which customer(s) you're working with? Thanks.