Grokbase › Groups › Go › golang-nuts › December 2012
FAQ
In the process of trying to write a logging library I got a bit stumped by
the lack of an accessible goroutine id. I'm used to logging each line with
a process and thread id to syslog such that afterwards one can reassemble
the events for each request that was processed by following the
process/thread ids. That seems to be impossible in Go without passing an id
into every function that may log something or that may call another
function that may log something. That's clearly pretty impractical. So I
must be missing something... how do you guys log things?

Yes, I get the fact that processing one request may happen using multiple
goroutines and that thread local storage (oops, there, I said it, I'm
already ducking...) is awful, etc. But not having proper logging is even
more awful in my book.

--

Search Discussions

  • Jan Mercl at Dec 31, 2012 at 12:27 pm ⇧

    On Mon, Dec 31, 2012 at 7:57 AM, wrote:
    Yes, I get the fact that processing one request may happen using multiple
    goroutines and that thread local storage (oops, there, I said it, I'm
    already ducking...) is awful, etc. But not having proper logging is even
    more awful in my book.
    There's nothing awful/wrong about a goroutine having its own/private
    context. Actually that's a common situation. So it's easy to add any
    kind of `id` to the goroutine's context - when reasonable. Then pass
    that `id` as one of the params of your logging API.

    However, I'm curious why one would ever need any kind of goroutine
    identity per se (in contrast to general context)...?

    -j

    PS: ex. http://play.golang.org/p/0LmcGYnYOv

    --
  • Bryanturley at Dec 31, 2012 at 5:13 pm ⇧

    On Monday, December 31, 2012 6:27:33 AM UTC-6, Jan Mercl wrote:
    On Mon, Dec 31, 2012 at 7:57 AM, <[email protected] <javascript:>>
    wrote:
    Yes, I get the fact that processing one request may happen using multiple
    goroutines and that thread local storage (oops, there, I said it, I'm
    already ducking...) is awful, etc. But not having proper logging is even
    more awful in my book.
    There's nothing awful/wrong about a goroutine having its own/private
    context. Actually that's a common situation. So it's easy to add any
    kind of `id` to the goroutine's context - when reasonable. Then pass
    that `id` as one of the params of your logging API.

    However, I'm curious why one would ever need any kind of goroutine
    identity per se (in contrast to general context)...?

    -j

    PS: ex. http://play.golang.org/p/0LmcGYnYOv
    http://play.golang.org/p/gkFy4d59O2 simpler

    --
  • Tve at Dec 31, 2012 at 5:43 pm ⇧
    This is what I described and is impractical: you've just essentially
    changed the language you use and forced yourself to pass the context into
    every single function call. That reminds me of all the arguments around
    global variables and pure functional languages...

    Here's a concrete example: I need to log certain events in my database
    drivers. For example, when a connection times out, when a db server refuses
    a connection, when a fail-over to another db master occurs, when a query
    takes too long or returns too much data. How do I do that with the context
    in a database/sql driver?
    On Monday, December 31, 2012 4:27:33 AM UTC-8, Jan Mercl wrote:

    On Mon, Dec 31, 2012 at 7:57 AM, <[email protected] <javascript:>>
    wrote:
    Yes, I get the fact that processing one request may happen using multiple
    goroutines and that thread local storage (oops, there, I said it, I'm
    already ducking...) is awful, etc. But not having proper logging is even
    more awful in my book.
    There's nothing awful/wrong about a goroutine having its own/private
    context. Actually that's a common situation. So it's easy to add any
    kind of `id` to the goroutine's context - when reasonable. Then pass
    that `id` as one of the params of your logging API.

    However, I'm curious why one would ever need any kind of goroutine
    identity per se (in contrast to general context)...?

    -j

    PS: ex. http://play.golang.org/p/0LmcGYnYOv
    --
  • Dustin Sallings at Dec 31, 2012 at 5:59 pm ⇧

    [email protected] writes:

    Here's a concrete example: I need to log certain events in my database
    drivers. For example, when a connection times out, when a db server
    refuses a connection, when a fail-over to another db master occurs,
    when a query takes too long or returns too much data. How do I do that
    with the context in a database/sql driver?
    By having the user supply the context?

    I wrote a database driver that will, in practice, spawn many
    goroutines to service a single request. It will also run several
    completely unrelated queries on a single goroutine and is allowed to
    reorder execution or even completely remove unnecessary operations at
    times.

    I'd rather the logging lump them together by request than by some
    arbitrary ID.

    --
    dustin

    --
  • Patrick Mylund Nielsen at Dec 31, 2012 at 6:12 pm ⇧
    To be fair, if each request is handled by a goroutine like it is in
    net/http, it's not that arbitrary. This is just something Go doesn't let
    you access (anymore) because associating stuff with a thread ID can cause
    problems in other cases.

    On Mon, Dec 31, 2012 at 12:50 PM, Dustin Sallings wrote:

    [email protected] writes:
    Here's a concrete example: I need to log certain events in my database
    drivers. For example, when a connection times out, when a db server
    refuses a connection, when a fail-over to another db master occurs,
    when a query takes too long or returns too much data. How do I do that
    with the context in a database/sql driver?
    By having the user supply the context?

    I wrote a database driver that will, in practice, spawn many
    goroutines to service a single request. It will also run several
    completely unrelated queries on a single goroutine and is allowed to
    reorder execution or even completely remove unnecessary operations at
    times.

    I'd rather the logging lump them together by request than by some
    arbitrary ID.

    --
    dustin

    --

    --
  • Dustin Sallings at Dec 31, 2012 at 6:33 pm ⇧
    Patrick Mylund Nielsen
    <[email protected]> writes:

    To be fair, if each request is handled by a goroutine like it is in
    net/http, it's not that arbitrary. This is just something Go doesn't
    let you access (anymore) because associating stuff with a thread ID
    can cause problems in other cases.
    In both DB clients and DB servers I've written in go, there's not a
    1:1 correlation of requests and goroutines.

    A single request to seriesly, for example, will be serviced by
    hundreds of short-lived goroutines in practice.

    A single HTTP request to a server to pull stats from a couchbase
    cluster will be aggregating results from all of the nodes concurrently
    and could very well reconfigure itself due to a cluster topology change
    during that request. Some of those connections may service other
    requests on the same goroutine they will be servicing mine both before
    and after mine.

    CBFS, where I've got the most benefit from logging as it's very often
    operating on more than one node at a time required me to do a lot of
    work to supply user context into log entries (most often the unique
    object ID). An incoming request pushing in a new item builds a pipe and
    has a goroutine copying the input from the HTTP socket to another
    "frames" socket targeting another node. This one connection is serviced
    by one goroutine that's moving bytes in one direction across the TCP
    socket. Another is moving bytes the other direction. Multiple
    concurrent HTTP connections are sending data across this TCP connection
    and the requests are interleaved on the TCP stream. At the end of a
    particular upload, two nodes log the arrival of a new blob of which
    they've independently calculated a SHA-1 and after successfully
    registering themselves with the metadata service, they log that that
    particular user-named file has arrived with this hash and then
    (optionally) asynchronously begins to tell a third node to ask one of
    the first two for a copy of this data for itself.

    It's not clear to me how any magic the logging decides to introduce
    will help me in any of these cases.

    --
    dustin

    --
  • Patrick Mylund Nielsen at Dec 31, 2012 at 6:35 pm ⇧
    Totally agree. Those are some of the reasons you can't do it anymore.

    On Mon, Dec 31, 2012 at 1:33 PM, Dustin Sallings wrote:

    Patrick Mylund Nielsen
    <[email protected]> writes:

    To be fair, if each request is handled by a goroutine like it is in
    net/http, it's not that arbitrary. This is just something Go doesn't
    let you access (anymore) because associating stuff with a thread ID
    can cause problems in other cases.
    In both DB clients and DB servers I've written in go, there's not a
    1:1 correlation of requests and goroutines.

    A single request to seriesly, for example, will be serviced by
    hundreds of short-lived goroutines in practice.

    A single HTTP request to a server to pull stats from a couchbase
    cluster will be aggregating results from all of the nodes concurrently
    and could very well reconfigure itself due to a cluster topology change
    during that request. Some of those connections may service other
    requests on the same goroutine they will be servicing mine both before
    and after mine.

    CBFS, where I've got the most benefit from logging as it's very often
    operating on more than one node at a time required me to do a lot of
    work to supply user context into log entries (most often the unique
    object ID). An incoming request pushing in a new item builds a pipe and
    has a goroutine copying the input from the HTTP socket to another
    "frames" socket targeting another node. This one connection is serviced
    by one goroutine that's moving bytes in one direction across the TCP
    socket. Another is moving bytes the other direction. Multiple
    concurrent HTTP connections are sending data across this TCP connection
    and the requests are interleaved on the TCP stream. At the end of a
    particular upload, two nodes log the arrival of a new blob of which
    they've independently calculated a SHA-1 and after successfully
    registering themselves with the metadata service, they log that that
    particular user-named file has arrived with this hash and then
    (optionally) asynchronously begins to tell a third node to ask one of
    the first two for a copy of this data for itself.

    It's not clear to me how any magic the logging decides to introduce
    will help me in any of these cases.

    --
    dustin

    --

    --
  • Thorsten von Eicken at Jan 1, 2013 at 2:45 am ⇧
    The fact that it doesn't help you in your use-cases doesn't mean that it
    can't help others. I'm not asking you to be forced to log the goroutine id,
    I would just like to be able to write a Logger that uses the goroutine id
    or a thread-based identifier. It might even help in your case in that you
    only would need to explicitly transfer the context id across goroutine
    hand-offs.


    On Monday, December 31, 2012 10:35:24 AM UTC-8, Patrick Mylund Nielsen
    wrote:
    Totally agree. Those are some of the reasons you can't do it anymore.


    On Mon, Dec 31, 2012 at 1:33 PM, Dustin Sallings <[email protected]<javascript:>
    wrote:
    Patrick Mylund Nielsen
    <[email protected] <javascript:>> writes:
    To be fair, if each request is handled by a goroutine like it is in
    net/http, it's not that arbitrary. This is just something Go doesn't
    let you access (anymore) because associating stuff with a thread ID
    can cause problems in other cases.
    In both DB clients and DB servers I've written in go, there's not a
    1:1 correlation of requests and goroutines.

    A single request to seriesly, for example, will be serviced by
    hundreds of short-lived goroutines in practice.

    A single HTTP request to a server to pull stats from a couchbase
    cluster will be aggregating results from all of the nodes concurrently
    and could very well reconfigure itself due to a cluster topology change
    during that request. Some of those connections may service other
    requests on the same goroutine they will be servicing mine both before
    and after mine.

    CBFS, where I've got the most benefit from logging as it's very often
    operating on more than one node at a time required me to do a lot of
    work to supply user context into log entries (most often the unique
    object ID). An incoming request pushing in a new item builds a pipe and
    has a goroutine copying the input from the HTTP socket to another
    "frames" socket targeting another node. This one connection is serviced
    by one goroutine that's moving bytes in one direction across the TCP
    socket. Another is moving bytes the other direction. Multiple
    concurrent HTTP connections are sending data across this TCP connection
    and the requests are interleaved on the TCP stream. At the end of a
    particular upload, two nodes log the arrival of a new blob of which
    they've independently calculated a SHA-1 and after successfully
    registering themselves with the metadata service, they log that that
    particular user-named file has arrived with this hash and then
    (optionally) asynchronously begins to tell a third node to ask one of
    the first two for a copy of this data for itself.

    It's not clear to me how any magic the logging decides to introduce
    will help me in any of these cases.

    --
    dustin

    --

    --
  • Patrick Mylund Nielsen at Jan 1, 2013 at 2:52 am ⇧
    I'm trying to reason about why you can't do it now. It tends to get abused.
    (A "great" way to abuse thread IDs in particular is to implement some kind
    of "thread-local storage.") Go lacks a lot of things that many users tend
    to abuse that can be very helpful and useful, e.g. list comprehensions, a
    ternary operator, named function arguments, ... It makes Go an easy
    language to use in teams where not everyone is a.. disciplined programmer,
    even if it makes some "ideal" things a little harder.

    Sometimes the reason is simply that nobody's needed it yet, but goroutine
    IDs were explicitly unexported prior to the release of Go 1.

    On Mon, Dec 31, 2012 at 9:45 PM, Thorsten von Eicken wrote:

    The fact that it doesn't help you in your use-cases doesn't mean that it
    can't help others. I'm not asking you to be forced to log the goroutine id,
    I would just like to be able to write a Logger that uses the goroutine id
    or a thread-based identifier. It might even help in your case in that you
    only would need to explicitly transfer the context id across goroutine
    hand-offs.


    On Monday, December 31, 2012 10:35:24 AM UTC-8, Patrick Mylund Nielsen
    wrote:
    Totally agree. Those are some of the reasons you can't do it anymore.

    On Mon, Dec 31, 2012 at 1:33 PM, Dustin Sallings wrote:

    Patrick Mylund Nielsen
    <[email protected]> writes:

    To be fair, if each request is handled by a goroutine like it is in
    net/http, it's not that arbitrary. This is just something Go doesn't
    let you access (anymore) because associating stuff with a thread ID
    can cause problems in other cases.
    In both DB clients and DB servers I've written in go, there's not a
    1:1 correlation of requests and goroutines.

    A single request to seriesly, for example, will be serviced by
    hundreds of short-lived goroutines in practice.

    A single HTTP request to a server to pull stats from a couchbase
    cluster will be aggregating results from all of the nodes concurrently
    and could very well reconfigure itself due to a cluster topology change
    during that request. Some of those connections may service other
    requests on the same goroutine they will be servicing mine both before
    and after mine.

    CBFS, where I've got the most benefit from logging as it's very often
    operating on more than one node at a time required me to do a lot of
    work to supply user context into log entries (most often the unique
    object ID). An incoming request pushing in a new item builds a pipe and
    has a goroutine copying the input from the HTTP socket to another
    "frames" socket targeting another node. This one connection is serviced
    by one goroutine that's moving bytes in one direction across the TCP
    socket. Another is moving bytes the other direction. Multiple
    concurrent HTTP connections are sending data across this TCP connection
    and the requests are interleaved on the TCP stream. At the end of a
    particular upload, two nodes log the arrival of a new blob of which
    they've independently calculated a SHA-1 and after successfully
    registering themselves with the metadata service, they log that that
    particular user-named file has arrived with this hash and then
    (optionally) asynchronously begins to tell a third node to ask one of
    the first two for a copy of this data for itself.

    It's not clear to me how any magic the logging decides to introduce
    will help me in any of these cases.

    --
    dustin

    --

    --
    --
  • Bryanturley at Jan 1, 2013 at 3:45 am ⇧

    On Monday, December 31, 2012 7:52:06 PM UTC-7, Patrick Mylund Nielsen wrote:
    I'm trying to reason about why you can't do it now. It tends to get
    abused. (A "great" way to abuse thread IDs in particular is to implement
    some kind of "thread-local storage.") Go lacks a lot of things that many
    users tend to abuse that can be very helpful and useful, e.g. list
    comprehensions, a ternary operator, named function arguments, ... It makes
    Go an easy language to use in teams where not everyone is a.. disciplined
    programmer, even if it makes some "ideal" things a little harder.

    Sometimes the reason is simply that nobody's needed it yet, but goroutine
    IDs were explicitly unexported prior to the release of Go 1.
    Plus the less you export the more you can change behind the scenes without
    breaking peoples apps.
    And the scheduler + related data structures will probably have many changes
    in the years to come, since it is at the heart of go.

    --
  • Dustin Sallings at Jan 1, 2013 at 8:09 pm ⇧
    Thorsten von Eicken <[email protected]>
    writes:
    The fact that it doesn't help you in your use-cases doesn't mean that
    it can't help others. I'm not asking you to be forced to log the
    goroutine id, I would just like to be able to write a Logger that uses
    the goroutine id or a thread-based identifier. It might even help in
    your case in that you only would need to explicitly transfer the
    context id across goroutine hand-offs.
    "hand off" means I sent something into a channel so that it's picked
    up by another goroutine and processed there. That other goroutine
    processes lots of requests for lots of different clients. This is a
    pretty common pattern.

    Another common pattern is spinning up short-lived goroutines in a way
    you never would with threads.

    Even in my case, building a log analyzer attempting to track user
    context to goroutine ID and then follow it across temporary and reusable
    goroutines is a lot more work than just supplying the user context.

    IMO, the goroutine ID ends up being exceedingly difficult to make any
    use of if your code contains "go" or "<-"

    --
    dustin

    --

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupgolang-nuts @
categoriesgo
postedDec 31, '12 at 11:19a
activeJan 1, '13 at 8:09p
posts12
users5
websitegolang.org

5 users in discussion

Patrick Mylund Nielsen: 3 posts Thorsten von Eicken: 3 posts Dustin Sallings: 3 posts Bryanturley: 2 posts Jan Mercl: 1 post

Content

People

Support

Translate

site design / logo © 2023 Grokbase