5 ms·

I'm surprised the article didn't mention anything about the nuances of actual logging in a distributed architecture. In particular, when a request starts to spa

by rdli 10y ago

I'm surprised the article didn't mention anything about the nuances of actual logging in a distributed architecture. In particular, when a request starts to span multiple containers or microservices, you need a way to correlate all log data to a given request. You typically do this by propagating a trace ID through your logging system, and a vector clock-type thing for causal ordering. If you can't tell which log statements belong to which request and the order in which they occur, debugging is quite hard :-).

ktamura 10y ago
While the article does not touch on this explicitly, Docker's Log Driver for Fluentd supports tags, which can be used to pass on container name/ID and other metadata to wherever logs are sent. Since Docker Machine itself allows these metadata to be passed on via API ({{.Name}}, etc.) one can create a fairly robust system to track log lineage.
- meddlepal 10y ago
  That approach requires a lot of post processing to make it useful. Further it's pretty hard (near impossible) to do causal ordering.
  - ktamura 10y ago
    I agree on the near-impossibility of causal ordering at scale. I don't see the need for a lot of "post processing". Adding filters in Fluentd is fairly simple: http://docs.fluentd.org/articles/filter-plugin-overview http://docs.fluentd.org/articles/filter-plugin-overview
- rdli 10y ago
  How would passing on the container ID help in mapping multiple log messages to the same request? If a request is going through multiple containers, you'll get multiple container IDs. To solve this problem, you need a unique trace ID and vector clock, and this actually needs to propagated through your logging system, not through container tags.
  - ktamura 10y ago
    Ah, I completely misunderstood. Yes, you are right: Threading data together across multiple containers belonging to a single logical request is hard (and AFAIK, none of the container orchestration tools deal with it well).
  - bogomipz 10y ago
    How is the unique trace ID implemented? Vector clocks would be in use by your distributed data store for conflict resolution such as Riak does. Could you elaborate on how you've implemented such a system?
    - rdli 10y ago
      It's not about conflict resolution, it's about ordering. Imagine you have 3 services. A calls B calls C. A request goes into A. The request fails. Since there are 3 services involved, you want to be able to see the log statements of all 3 services, in order. To do this, you need a UUID that is passed from A to B to C and a vector clock that is incremented from A to B to C so you get perfect ordering. Passing the data around is not super hard (you can use HTTP headers, for example). The tricky bit is having a library that does the right thing in A and B and C. And if A is written in Java and B is written in NodeJS, that library better work on both!
      - bogomipz 10y ago
        Yes, this makes total sense. I think I completely misunderstood you post earlier. Thanks for the clarification.
manyxcxi 10y ago
I've just started down a path for us and been pretty happy with Loggly so far. Just by adding a UUID to the requests as they're initially received I'm able to follow the chain of events across 5 different services, a message queue, and reconcile with any code exception reports from Bugsnag. We don't have a lot of unique clients, but we do have a lot of requests. Loggly can be set to parse logs (or have the data sent directly to it) and then tag messages with keys/values that can let you watch your request through every server.
- ktamura 10y ago
  Now that I understand the parent comment, I don't think this quite solves the problem he's asking unless all of your services are perfectly synchronized. No?
  - manyxcxi 10y ago
    For us, messaging between services go through queues and a client request might start in a particular service and wind it's way through a few others to finish the work. You wouldn't have the same client requesting things from two different services simultaneously, though in fairly short order they come through. Our use case might be just simple enough that this wouldn't work for a lot of people. Also, if I'm looking at access logs I'm not going to have that ID unless I start putting it in request headers. Right now the application logs and other monitoring tools pick it up though. Edit: Didn't see mention of the clock on my first post, but it still stands for us that we're not in the millisecond timings between requests going in and out of services so we haven't had a problem with the timestamps from the systems they're on. Requests generally take a few seconds to process (handle a file upload of decent size, ETL some data, pump out some output document, etc) so each step through a service buys enough time before moving on to the next thing that we're not getting out of order log statements across each service.
    - vardump 10y ago
      > Edit: Didn't see mention of the clock on my first post, but it still stands for us that we're not in the millisecond timings Vector clocks don't necessarily have much to do with clocks. It's an algorithm for generating order in a distributed system. https://en.wikipedia.org/wiki/Vector_clock https://en.wikipedia.org/wiki/Vector_clock
stuffonkeyboard 10y ago
This is false. You can also do this without microservices or containers. Or also syslog. Just my two cents!
- rdli 10y ago
  I wasn't saying you needed microservices or containers to do distributed logging. My point is that if you're building a distributed system, you need distributed logging (tracing) semantics. The actual logging mechanism (syslog, fluentd, etc) can be used -- as long as you propagate your UUID, etc.
bogomipz 10y ago
Can you elaborate on the use case you are referring to where a single request spans multiple containers? Are you referring to a "fan-out"?
- rdli 10y ago
  Really, it's when you're doing microservices, and each service is deployed to a different container. Typically your business logic is now spread across multiple containers. For example, you might have a recommendation service that looks up location in the geo service. If the geo service returns bad data, then the exception is thrown in the recommendation service. But to debug this properly, you really want to see the logging in both the geo service and the recommendation service, in order. As your topologies get deeper, the problem gets exponentially harder.
jacques_chester 10y ago
There are a number of distributed tracing tools now. I've heard good things about Zipkin[0], but not used it myself. The key is not just to have a single request ID, but also to provide hop IDs. Relying on clocks, even vector clocks, isn't ideal in a share-nothing architecture. [0] http://zipkin.io/ http://zipkin.io/
- NegatioN 10y ago
  Zipkin is great. It's pretty simple to set up, and you can instrument pretty much anything to send data to it. We made it a part of our internal httpclient and Kafka client so most teams get the tracing for free. You can even visualize the internals of Cassandra with zipkin. :) There's support for a Spark-job that generates a visual map of all your services' dependencies[0] where the strength of their relationship is represented by the thickness of the lines. [0]: http://thelastpickle.com/images/using-zipkin-graph.png http://thelastpickle.com/images/using-zipkin-graph.png

by rdli 10y ago

ktamura 10y ago

While the article does not touch on this explicitly, Docker's Log Driver for Fluentd supports tags, which can be used to pass on container name/ID and other metadata to wherever logs are sent. Since Docker Machine itself allows these metadata to be passed on via API ({{.Name}}, etc.) one can create a fairly robust system to track log lineage.

meddlepal 10y ago
That approach requires a lot of post processing to make it useful. Further it's pretty hard (near impossible) to do causal ordering.
- ktamura 10y ago
  I agree on the near-impossibility of causal ordering at scale. I don't see the need for a lot of "post processing". Adding filters in Fluentd is fairly simple: http://docs.fluentd.org/articles/filter-plugin-overview http://docs.fluentd.org/articles/filter-plugin-overview
rdli 10y ago
How would passing on the container ID help in mapping multiple log messages to the same request? If a request is going through multiple containers, you'll get multiple container IDs. To solve this problem, you need a unique trace ID and vector clock, and this actually needs to propagated through your logging system, not through container tags.
- ktamura 10y ago
  Ah, I completely misunderstood. Yes, you are right: Threading data together across multiple containers belonging to a single logical request is hard (and AFAIK, none of the container orchestration tools deal with it well).
- bogomipz 10y ago
  How is the unique trace ID implemented? Vector clocks would be in use by your distributed data store for conflict resolution such as Riak does. Could you elaborate on how you've implemented such a system?
  - rdli 10y ago
    It's not about conflict resolution, it's about ordering. Imagine you have 3 services. A calls B calls C. A request goes into A. The request fails. Since there are 3 services involved, you want to be able to see the log statements of all 3 services, in order. To do this, you need a UUID that is passed from A to B to C and a vector clock that is incremented from A to B to C so you get perfect ordering. Passing the data around is not super hard (you can use HTTP headers, for example). The tricky bit is having a library that does the right thing in A and B and C. And if A is written in Java and B is written in NodeJS, that library better work on both!
    - bogomipz 10y ago
      Yes, this makes total sense. I think I completely misunderstood you post earlier. Thanks for the clarification.

manyxcxi 10y ago

I've just started down a path for us and been pretty happy with Loggly so far. Just by adding a UUID to the requests as they're initially received I'm able to follow the chain of events across 5 different services, a message queue, and reconcile with any code exception reports from Bugsnag. We don't have a lot of unique clients, but we do have a lot of requests. Loggly can be set to parse logs (or have the data sent directly to it) and then tag messages with keys/values that can let you watch your request through every server.

ktamura 10y ago
Now that I understand the parent comment, I don't think this quite solves the problem he's asking unless all of your services are perfectly synchronized. No?
- manyxcxi 10y ago
  For us, messaging between services go through queues and a client request might start in a particular service and wind it's way through a few others to finish the work. You wouldn't have the same client requesting things from two different services simultaneously, though in fairly short order they come through. Our use case might be just simple enough that this wouldn't work for a lot of people. Also, if I'm looking at access logs I'm not going to have that ID unless I start putting it in request headers. Right now the application logs and other monitoring tools pick it up though. Edit: Didn't see mention of the clock on my first post, but it still stands for us that we're not in the millisecond timings between requests going in and out of services so we haven't had a problem with the timestamps from the systems they're on. Requests generally take a few seconds to process (handle a file upload of decent size, ETL some data, pump out some output document, etc) so each step through a service buys enough time before moving on to the next thing that we're not getting out of order log statements across each service.
  - vardump 10y ago
    > Edit: Didn't see mention of the clock on my first post, but it still stands for us that we're not in the millisecond timings Vector clocks don't necessarily have much to do with clocks. It's an algorithm for generating order in a distributed system. https://en.wikipedia.org/wiki/Vector_clock https://en.wikipedia.org/wiki/Vector_clock

stuffonkeyboard 10y ago

This is false. You can also do this without microservices or containers. Or also syslog. Just my two cents!

rdli 10y ago
I wasn't saying you needed microservices or containers to do distributed logging. My point is that if you're building a distributed system, you need distributed logging (tracing) semantics. The actual logging mechanism (syslog, fluentd, etc) can be used -- as long as you propagate your UUID, etc.

bogomipz 10y ago

Can you elaborate on the use case you are referring to where a single request spans multiple containers? Are you referring to a "fan-out"?

rdli 10y ago
Really, it's when you're doing microservices, and each service is deployed to a different container. Typically your business logic is now spread across multiple containers. For example, you might have a recommendation service that looks up location in the geo service. If the geo service returns bad data, then the exception is thrown in the recommendation service. But to debug this properly, you really want to see the logging in both the geo service and the recommendation service, in order. As your topologies get deeper, the problem gets exponentially harder.

jacques_chester 10y ago

There are a number of distributed tracing tools now. I've heard good things about Zipkin[0], but not used it myself. The key is not just to have a single request ID, but also to provide hop IDs. Relying on clocks, even vector clocks, isn't ideal in a share-nothing architecture. [0] http://zipkin.io/ http://zipkin.io/

NegatioN 10y ago
Zipkin is great. It's pretty simple to set up, and you can instrument pretty much anything to send data to it. We made it a part of our internal httpclient and Kafka client so most teams get the tracing for free. You can even visualize the internals of Cassandra with zipkin. :) There's support for a Spark-job that generates a visual map of all your services' dependencies[0] where the strength of their relationship is represented by the thickness of the lines. [0]: http://thelastpickle.com/images/using-zipkin-graph.png http://thelastpickle.com/images/using-zipkin-graph.png