APM index logs default to epoch


(Ioannis Mavroukakis) #1

I'm having this difficult to replicate issue. Sometimes, seemingly at random, an apm index will be created with the index date set to epoch i.e. apm-6.3.0-transaction-1970.01.01
I've turned on debugging in the logs but I don't see anything that would point to the root cause. Where else should I be looking? I'm using v0.7.0 of the Java agent.

TIA!


(Felix Barnsteiner) #2

Hi and thanks for giving the Java agent a try! Could you post the documents inside that index?


(Ioannis Mavroukakis) #3

Hey Felix, will do, as soon as I stop wiping the damn thing in anger :slight_smile:


(Felix Barnsteiner) #4

Haha, sounds like a plan :wink:

Some more questions: How often does that happen? Which frameworks and application server are you using? What are your settings? Which apm server version are you using?


(Ioannis Mavroukakis) #5

Hard to say. It's a custom spring boot app that I'm tracing with a Spring Hessian handled endpoint, but I've turned off everything via the configuration and I'm tracing only inside a single method in our codebase.
Having said that, before I decided to add custom traces, I did observe the same issue without using the APM library in the project. I'm using APM 6.3 and my settings are as follows

service_name=app-search-engine
server_urls=http://xxxxxxx:8200
application_packages=com.insight
service_version=9faf8110c20d0fe72ad84f36f1cdbcccbe7a936f
capture_body=transactions
application_packages=com.insight
ignore_urls=(?i)/app-search-engine/metrics*,(?i)/app-search-engine/health*
disable_instrumentations=jdbc,servlet-api,servlet-api-async,spring-mvc,http-client,apache-httpclient,spring-resttemplate,incubating

EDIT: just noticed I'm duplicating the application_packages property, oops.


(Felix Barnsteiner) #6

What do you mean by that? How do you trace this method?


(Ioannis Mavroukakis) #7

Using apm-agent-api :slight_smile: v0.7


(Ioannis Mavroukakis) #8

to be precise

final Transaction transaction = ElasticApm.startTransaction();
transaction.setType(type);
transaction.setName(name);
// method body goes here
// Spans throughout, example below
Span span = transaction.createSpan();
span.setType(type);
span.setName(name);
// some more code to trace
span.end()
transaction.end()

(Felix Barnsteiner) #9

You should end the transactions and spans in a finally block as shown in the documentation. Otherwise, this is looking fine.

For further analysis, I'd have to have a look at the documents inside the apm-6.3.0-transaction-1970.01.01 index.


(Ioannis Mavroukakis) #10

Thanks, I already do, but elided for brevity. As soon as one of these nasties shows up again I'll post it here :slight_smile:


(Ioannis Mavroukakis) #11

Whilst I'm setting my traps for this bad boy, I had a general nature tracing question I was hoping you could shed some light on.

Given the following calling chain

A -> B -> D 
     C -> E

meaning: Class A within the context of a single method, calls methods from class B and C, and they in turn call methods from D and E respectively.

I want to create a single transaction that spans all the classes involved in A's method call. What's the best way to do this? I keep thinking that I have to pass the created Transaction object to B,C,D,E so that I can create Span instances from it, but that doesn't feel right at all.


(Felix Barnsteiner) #12

That would currently the way to go. At its current state, the public API does not yet offer a method which makes a span "active", so that you can retrieve it with ElasticApm.currentSpan(). The reason is that there is a lot which can go wrong in terms of leaking the spans in a ThreadLocal. So at the moment, you really have to pass along the Spans and Transactions. Is that a bummer for you?


(Ioannis Mavroukakis) #13

I'd say so. For all given paths that my application will start a root Transaction, I have to modify all methods from participating classes to accept a Span as an argument. This forces an additional concern on the developer.
So, given a class Foo that begins a Transaction and has a dependency on class Bar , that means for class Baz that uses Bar (and every other class) I have to "force" instrumentation upon them, even if Baz doesn't care about tracing. At best, this will create needless noise, at worst it will confuse the viewer, with rootless Spans appearing in the APM dashboard. This also forces me to make decisions that will be hard to change (because, recompile/release :wink: )

At this point, I'm considering writing a solution with AOP/Pointcuts and annotations, but it's somewhat hand-wavy in my head and I've yet to examine the finer points. I'm currently trying something out abstracting the APM API away in a Spring component with ThreadLocal but I've had mixed success..


(Felix Barnsteiner) #14

I've added two issues to provide support for that:


If you are interested, you can also help implementing this. We are using Byte Buddy, a byte code manipulation framework. It works in a similar way than Spring AOP but has the advantage that it's not tied to Spring.

If you are interested in collaborating (either by coding or by providing feedback), you can follow up in any of those issues.


(Ioannis Mavroukakis) #15

Happy to contribute whichever way I can, thank you very much for following this up!


(Ioannis Mavroukakis) #16

Finally caught one

{
  "took": 0,
  "timed_out": false,
  "_shards": {
    "total": 1,
    "successful": 1,
    "skipped": 0,
    "failed": 0
  },
  "hits": {
    "total": 3,
    "max_score": 1,
    "hits": [
      {
        "_index": "apm-6.3.0-transaction-1970.01.01",
        "_type": "doc",
        "_id": "bIPl8WUBobq0Xh-lDBVi",
        "_score": 1,
        "_source": {
          "@timestamp": "1970-01-01T00:00:00.000Z",
          "processor": {
            "name": "transaction",
            "event": "transaction"
          },
          "transaction": {
            "id": "00000000-0000-0000-0000-000000000000",
            "name": "DispatcherServlet#doPost",
            "duration": {
              "us": 2806324779308
            },
            "type": "request",
            "sampled": false,
            "span_count": {
              "dropped": {
                "total": 0
              }
            }
          },
          "context": {
            "service": {
              "name": "app-search-engine",
              "agent": {
                "version": "0.7.0",
                "name": "java"
              },
              "version": "9faf8110c20d0fe72ad84f36f1cdbcccbe7a936f",
              "language": {
                "name": "Java",
                "version": "1.8.0_162"
              },
              "runtime": {
                "name": "Java",
                "version": "1.8.0_162"
              }
            },
            "process": {
              "title": "/usr/java/jdk1.8.0_162/jre/bin/java",
              "pid": 15372
            },
            "system": {
              "hostname": "Linux",
              "architecture": "amd64",
              "platform": "the.agent.server.com",
              "ip": "xxx.xx.x.xxx"
            }
          },
          "host": {
            "name": "the.apm.server.com"
          },
          "beat": {
            "version": "6.3.0",
            "name": "the.apm.server.com",
            "hostname": "the.apm.server.com"
          }
        }
      },
      {
        "_index": "apm-6.3.0-transaction-1970.01.01",
        "_type": "doc",
        "_id": "2oPn8WUBobq0Xh-ls_rM",
        "_score": 1,
        "_source": {
          "@timestamp": "1970-01-01T00:00:00.000Z",
          "processor": {
            "name": "transaction",
            "event": "transaction"
          },
          "transaction": {
            "name": "HessianServiceExporter",
            "duration": {
              "us": 2806497785353
            },
            "type": "request",
            "sampled": false,
            "span_count": {
              "dropped": {
                "total": 0
              }
            },
            "id": "00000000-0000-0000-0000-000000000000"
          },
          "context": {
            "service": {
              "language": {
                "name": "Java",
                "version": "1.8.0_162"
              },
              "runtime": {
                "name": "Java",
                "version": "1.8.0_162"
              },
              "name": "app-search-engine",
              "agent": {
                "name": "java",
                "version": "0.7.0"
              },
              "version": "9faf8110c20d0fe72ad84f36f1cdbcccbe7a936f"
            },
            "process": {
              "pid": 15372,
              "title": "/usr/java/jdk1.8.0_162/jre/bin/java"
            },
            "system": {
              "hostname": "Linux",
              "architecture": "amd64",
              "platform": "the.agent.server.com",
              "ip": "xxx.xx.x.xxx"
            }
          },
          "beat": {
            "name": "the.apm.server.com",
            "hostname": "the.apm.server.com",
            "version": "6.3.0"
          },
          "host": {
            "name": "the.apm.server.com"
          }
        }
      },
      {
        "_index": "apm-6.3.0-transaction-1970.01.01",
        "_type": "doc",
        "_id": "cYTn8WUBobq0Xh-l0wUL",
        "_score": 1,
        "_source": {
          "@timestamp": "1970-01-01T00:00:00.000Z",
          "transaction": {
            "duration": {
              "us": 2806505777235
            },
            "type": "request",
            "sampled": false,
            "span_count": {
              "dropped": {
                "total": 0
              }
            },
            "id": "00000000-0000-0000-0000-000000000000",
            "name": "DispatcherServlet#doPost"
          },
          "context": {
            "service": {
              "name": "app-search-engine",
              "agent": {
                "name": "java",
                "version": "0.7.0"
              },
              "version": "9faf8110c20d0fe72ad84f36f1cdbcccbe7a936f",
              "language": {
                "name": "Java",
                "version": "1.8.0_162"
              },
              "runtime": {
                "name": "Java",
                "version": "1.8.0_162"
              }
            },
            "process": {
              "pid": 15372,
              "title": "/usr/java/jdk1.8.0_162/jre/bin/java"
            },
            "system": {
              "ip": "xxx.xx.x.xxx",
              "hostname": "Linux",
              "architecture": "amd64",
              "platform": "the.agent.server.com"
            }
          },
          "beat": {
            "hostname": "the.apm.server.com",
            "version": "6.3.0",
            "name": "the.apm.server.com"
          },
          "host": {
            "name": "the.apm.server.com"
          },
          "processor": {
            "name": "transaction",
            "event": "transaction"
          }
        }
      }
    ]
  }
}

It occurred as soon as I reverted enable_instrumentations to its default value.


(system) #17

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.