Where am I?

Discussion in 'Java' started by Roedy Green, Oct 13, 2011.

  1. Roedy Green

    Roedy Green Guest

    It would be nice for debugging to include the line number of where the
    code is when printing out the error message. Is there a simple way to
    get it, or do you need to create a Throwable then analyse the
    stacktrace?
    --
    Roedy Green Canadian Mind Products
    http://mindprod.com
    It should not be considered an error when the user starts something
    already started or stops something already stopped. This applies
    to browsers, services, editors... It is inexcusable to
    punish the user by requiring some elaborate sequence to atone,
    e.g. open the task editor, find and kill some processes.
     
    Roedy Green, Oct 13, 2011
    #1
    1. Advertising

  2. Roedy Green

    Daniel Pitts Guest

    On 10/12/11 5:04 PM, Roedy Green wrote:
    > It would be nice for debugging to include the line number of where the
    > code is when printing out the error message. Is there a simple way to
    > get it, or do you need to create a Throwable then analyse the
    > stacktrace?

    Most logging frameworks support that, and many of those frameworks are
    open-source. log4j for instance. Perhaps it would be worthwhile
    looking at how that approach that problem.
     
    Daniel Pitts, Oct 13, 2011
    #2
    1. Advertising

  3. Wed, 12 Oct 2011 17:04:50 -0700, /Roedy Green/:

    > It would be nice for debugging to include the line number of where the
    > code is when printing out the error message. Is there a simple way to
    > get it, or do you need to create a Throwable then analyse the
    > stacktrace?


    I guess one could also use Thread.currentThread().getStackTrace():

    http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#getStackTrace()

    But how's the current code line useful in such a log? If you see
    the exact message you probably already know (or could easily find)
    where in the source it is produced. If the same message is logged
    from different locations, probably the message should be revised to
    be more specific as appropriate?

    I also don't think the source line (the last stack frame) alone is
    any useful without the full stack trace to see where the call is
    originating:

    http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#dumpStack()

    --
    Stanimir
     
    Stanimir Stamenkov, Oct 13, 2011
    #3
  4. Roedy Green

    Ian Shef Guest

    Roedy Green <> wrote in
    news::

    > It would be nice for debugging to include the line number of where the
    > code is when printing out the error message. Is there a simple way to
    > get it, or do you need to create a Throwable then analyse the
    > stacktrace?


    I don't know an easy way. I have a utility class with this method:

    public static String getCallerLineNumber() {
    StackTraceElement [] stArray = new Throwable().getStackTrace() ;
    StackTraceElement st ;
    if ((null!=stArray)&&(stArray.length>1)&&(null!=stArray[1])) {
    st = stArray[1] ;
    } else {
    st = UNAVAILABLE ;
    }
    return String.valueOf(st.getLineNumber()) ;
    }

    where I have defined:

    private static final StackTraceElement UNAVAILABLE =
    new StackTraceElement(
    "unavailable", "unavailable", "unavailable", -1) ;

    Notes:
    1) The "if" statement may be excessive (especially null!=stArray ) but is
    intended to deal with
    the documented possibility that the stack trace is incomplete.

    2) "Line number" is a hazy concept where optimization and JIT compiling is
    taking place.

    3) This could be optimized, but it is intended for clarity and not for speed.

    Good Luck!
     
    Ian Shef, Oct 13, 2011
    #4
  5. Roedy Green

    markspace Guest

    On 10/12/2011 5:04 PM, Roedy Green wrote:
    > It would be nice for debugging to include the line number of where the
    > code is when printing out the error message. Is there a simple way to
    > get it, or do you need to create a Throwable then analyse the
    > stacktrace?



    If project coin (the "simple" Java changes project) ever happens again,
    I would suggest line numbers and method names, at least. Even the old C
    preprocessor stile macros like __LINE__ would be ok. Just have the
    compiler interpret that for the line number of the source file.

    __LINE__
    __METHOD__
    __CLASS__
    __PARAMS__

    __CLASS__ for the class name (less urgent due to Clazz.class.getName(),
    but handy for code templates and such), and __PARAMS__ for an anonymous
    array of the parameters of a method or constructor.

    I guess you could add __LOCAL__ and __FIELDS__ for an array of in-scope
    local variables and fields respectively. It might be desirable to also
    allow access to the names of parameters, local variables and fields too.

    Hmm, this got complicated fast. :)
     
    markspace, Oct 13, 2011
    #5
  6. On 11-10-12 09:23 PM, Stanimir Stamenkov wrote:
    > Wed, 12 Oct 2011 17:04:50 -0700, /Roedy Green/:
    >
    >> It would be nice for debugging to include the line number of where the
    >> code is when printing out the error message. Is there a simple way to
    >> get it, or do you need to create a Throwable then analyse the
    >> stacktrace?

    >
    > I guess one could also use Thread.currentThread().getStackTrace():
    >
    > http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#getStackTrace()
    >
    >
    > But how's the current code line useful in such a log? If you see the
    > exact message you probably already know (or could easily find) where in
    > the source it is produced. If the same message is logged from different
    > locations, probably the message should be revised to be more specific as
    > appropriate?

    [ SNIP ]

    I agree 100%. In production Java applications that I help maintain or
    write, line numbers only feature in the error logs, and that's because
    we dump the full stack trace into the error log if there was a serious
    enough exception. For logging at any other level (info, warn, debug etc)
    the message format we have devised, and simply having a descriptive
    enough message, always pinpoints the location in the source. At worst
    you might have to do an indirect search in a properties file for a
    message key, then grep the source for that key, but that's like 10 extra
    seconds.

    We (I) happen to usually use log4j, and in the API docs for log4j
    PatternLayout, there are warnings about using the conversion specifiers
    for class name, file name, method name and line number, because they are
    slow or extremely slow. Since you don't actually need to compute any of
    these if you do what Stanimir suggests, why take the hit?

    This observation - about making the debugging message descriptive
    enough, without using computed source location information, to identify
    the location of the message - is applicable not just to use of a logger
    like log4j, but also quick and dirty println's or printf's. For example,
    if doing some throwaway printf's, I usually include a string of form
    "classname.methodname: " in the message.

    AHS
    --
    I tend to watch a little TV... Court TV, once in a while. Some of the
    cases I get interested in.
    -- O. J. Simpson
     
    Arved Sandstrom, Oct 13, 2011
    #6
  7. Roedy Green

    Roedy Green Guest

    On Thu, 13 Oct 2011 03:23:25 +0300, Stanimir Stamenkov
    <> wrote, quoted or indirectly quoted someone who
    said :

    >But how's the current code line useful in such a log?


    In the olden days when such was easily available, you could arrange
    that the number got fed to your editor and it took you right to the
    problem.

    Otherwise you must scan your entire project for the text of the error
    message. It might well not be there because it was composed out of
    pieces. You then have to search for pieces and guess where they might
    have been put together to give the string you observed. That is a
    waste of time.

    I wanted to put together an entry in the Java glossary on locating the
    code the produced a given error message. I wanted a technique that
    would be easy for newbies to use. Log4J is a bit much for them, though
    I will certainly mention it as the grown up solution.

    A long time ago before we had rapid text scanners, error message
    always came with a number you could look up.
    --
    Roedy Green Canadian Mind Products
    http://mindprod.com
    It should not be considered an error when the user starts something
    already started or stops something already stopped. This applies
    to browsers, services, editors... It is inexcusable to
    punish the user by requiring some elaborate sequence to atone,
    e.g. open the task editor, find and kill some processes.
     
    Roedy Green, Oct 13, 2011
    #7
  8. Roedy Green

    Arne Vajhøj Guest

    On 10/13/2011 4:36 AM, bugbear wrote:
    > Daniel Pitts wrote:
    >> On 10/12/11 5:04 PM, Roedy Green wrote:
    >>> It would be nice for debugging to include the line number of where the
    >>> code is when printing out the error message. Is there a simple way to
    >>> get it, or do you need to create a Throwable then analyse the
    >>> stacktrace?

    >> Most logging frameworks support that, and many of those frameworks are
    >> open-source. log4j for instance. Perhaps it would be worthwhile looking
    >> at how that approach that problem.

    >
    > Or just *use* log4j.


    That would be next step after looking.

    :)

    Arne
     
    Arne Vajhøj, Oct 13, 2011
    #8
  9. Roedy Green

    Arne Vajhøj Guest

    On 10/13/2011 6:16 AM, Arved Sandstrom wrote:
    > On 11-10-12 09:23 PM, Stanimir Stamenkov wrote:
    >> Wed, 12 Oct 2011 17:04:50 -0700, /Roedy Green/:
    >>> It would be nice for debugging to include the line number of where the
    >>> code is when printing out the error message. Is there a simple way to
    >>> get it, or do you need to create a Throwable then analyse the
    >>> stacktrace?

    >>
    >> I guess one could also use Thread.currentThread().getStackTrace():
    >>
    >> http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#getStackTrace()
    >>
    >>
    >> But how's the current code line useful in such a log? If you see the
    >> exact message you probably already know (or could easily find) where in
    >> the source it is produced. If the same message is logged from different
    >> locations, probably the message should be revised to be more specific as
    >> appropriate?

    > [ SNIP ]
    >
    > I agree 100%. In production Java applications that I help maintain or
    > write, line numbers only feature in the error logs, and that's because
    > we dump the full stack trace into the error log if there was a serious
    > enough exception. For logging at any other level (info, warn, debug etc)
    > the message format we have devised, and simply having a descriptive
    > enough message, always pinpoints the location in the source. At worst
    > you might have to do an indirect search in a properties file for a
    > message key, then grep the source for that key, but that's like 10 extra
    > seconds.
    >
    > We (I) happen to usually use log4j, and in the API docs for log4j
    > PatternLayout, there are warnings about using the conversion specifiers
    > for class name, file name, method name and line number, because they are
    > slow or extremely slow. Since you don't actually need to compute any of
    > these if you do what Stanimir suggests, why take the hit?
    >
    > This observation - about making the debugging message descriptive
    > enough, without using computed source location information, to identify
    > the location of the message - is applicable not just to use of a logger
    > like log4j, but also quick and dirty println's or printf's. For example,
    > if doing some throwaway printf's, I usually include a string of form
    > "classname.methodname: " in the message.


    The problem with that approach is that it is designing the
    logging based on an assumption that developers will do what they
    are supposed to do. That assumption is not always true.

    Arne
     
    Arne Vajhøj, Oct 14, 2011
    #9
  10. On 11-10-14 12:27 AM, Patricia Shanahan wrote:
    > Arne Vajhøj wrote:
    >> On 10/13/2011 6:16 AM, Arved Sandstrom wrote:
    >>> On 11-10-12 09:23 PM, Stanimir Stamenkov wrote:
    >>>> Wed, 12 Oct 2011 17:04:50 -0700, /Roedy Green/:
    >>>>> It would be nice for debugging to include the line number of where the
    >>>>> code is when printing out the error message. Is there a simple way to
    >>>>> get it, or do you need to create a Throwable then analyse the
    >>>>> stacktrace?
    >>>>
    >>>> I guess one could also use Thread.currentThread().getStackTrace():
    >>>>
    >>>> http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#getStackTrace()
    >>>>
    >>>>
    >>>>
    >>>> But how's the current code line useful in such a log? If you see the
    >>>> exact message you probably already know (or could easily find) where in
    >>>> the source it is produced. If the same message is logged from
    >>>> different
    >>>> locations, probably the message should be revised to be more
    >>>> specific as
    >>>> appropriate?
    >>> [ SNIP ]
    >>>
    >>> I agree 100%. In production Java applications that I help maintain or
    >>> write, line numbers only feature in the error logs, and that's because
    >>> we dump the full stack trace into the error log if there was a serious
    >>> enough exception. For logging at any other level (info, warn, debug etc)
    >>> the message format we have devised, and simply having a descriptive
    >>> enough message, always pinpoints the location in the source. At worst
    >>> you might have to do an indirect search in a properties file for a
    >>> message key, then grep the source for that key, but that's like 10 extra
    >>> seconds.
    >>>
    >>> We (I) happen to usually use log4j, and in the API docs for log4j
    >>> PatternLayout, there are warnings about using the conversion specifiers
    >>> for class name, file name, method name and line number, because they are
    >>> slow or extremely slow. Since you don't actually need to compute any of
    >>> these if you do what Stanimir suggests, why take the hit?
    >>>
    >>> This observation - about making the debugging message descriptive
    >>> enough, without using computed source location information, to identify
    >>> the location of the message - is applicable not just to use of a logger
    >>> like log4j, but also quick and dirty println's or printf's. For example,
    >>> if doing some throwaway printf's, I usually include a string of form
    >>> "classname.methodname: " in the message.

    >>
    >> The problem with that approach is that it is designing the
    >> logging based on an assumption that developers will do what they
    >> are supposed to do. That assumption is not always true.

    >
    > Another way of looking at this is as a matter of where to put the burden
    > of making sure the message can always be tracked back to the code that
    > logged it, on the programmer or on the logging infrastructure.


    I understand the point you and Arne are making, but I see this issue
    differently. Stanimir, and I, have advanced the notion that if the
    message is sufficiently descriptive that one can locate the source of it
    without difficulty. To answer your criticism, I'd simply say that if one
    is so unsure about the quality of their programmers that they can't rely
    on the messages being sufficiently descriptive for this purpose, all
    that you've really got with the logging infrastructure supplying
    location information is _tracing_.

    Personally, if I wanted tracing I'd use dtrace if I had it, or use
    aspects, or both.

    Sure there is a burden on the programmer. Unless one assumes that the
    single or main purpose of the log statements _is_ to trace, that burden
    is to ensure that the log statements are descriptive and useful. That is
    the prime directive. I actually don't see the point in assuming that the
    log statements might not be sufficiently descriptive: sure, you can put
    in the location specifiers but then you've simply got useless log
    statements that you can accurately source.

    > In general, the more of the routine work that has to be done all over
    > the place the infrastructure can manage the better. At a minimum, it
    > saves programmer time and thinking for things the infrastructure cannot
    > handle. It is especially important for code that may not be heavily
    > tested - some log messages result from conditions that should never happen.
    >
    > Patricia


    But in this case all we are asking the programmers to do is to put in a
    sufficiently descriptive log message. That's it. Not requiring them to
    at least do that is to defeat the purpose of logging.

    I've had the opportunity to gather requirements for, design, and
    implement major logging initiatives for a number of large J2EE/JEE
    applications. In fact logging improvement, along with error handling
    revamp, was the purpose of these mid-life projects. Requirements input
    came from both operations support staff (who typically use Splunk to see
    logs), and from production support developers (who get tasked with
    fixing production defects and who work with the app logs also). I still
    do other maintenance and new projects for these clients, so over the
    past few years I've gotten useful feedback on how the new logging is
    working. It's been quite positive: not only are the logs much better for
    their intended purpose, but all the developers like the new system.
    _They_ don't think it's a burden.

    I'll add that in these work environments that I describe, that logging
    is taken seriously enough that log statements (whether existing or new)
    are also the subject of code reviews. This isn't 100% coverage, of
    course, but there is enough review process that the quality of log
    messages stays high.

    The only time with these applications, in a production support
    situation, that statements could not be unambiguously pinpointed in the
    source is because the statements themselves - the meat of the message -
    were useless (maybe the work slipped review). Personally I believe that
    the answer there is to improve the message.

    Again, based on the actual experiment, and observations thereafter, I
    simply don't see that assuming that programmers cannot be counted on to
    write sufficiently descriptive log messages is a valid concern. Not if
    there are at least moderate processes in place. Sure, in a completely
    undisciplined shop you may as well put in location specifiers with your
    logger of choice, but ultimately all you've got then is tracing.

    AHS
    --
    I tend to watch a little TV... Court TV, once in a while. Some of the
    cases I get interested in.
    -- O. J. Simpson
     
    Arved Sandstrom, Oct 14, 2011
    #10
  11. Roedy Green

    Arne Vajhøj Guest

    On 10/14/2011 6:26 AM, Arved Sandstrom wrote:
    > On 11-10-14 12:27 AM, Patricia Shanahan wrote:
    >> Arne Vajhøj wrote:
    >>> On 10/13/2011 6:16 AM, Arved Sandstrom wrote:
    >>>> On 11-10-12 09:23 PM, Stanimir Stamenkov wrote:
    >>>>> Wed, 12 Oct 2011 17:04:50 -0700, /Roedy Green/:
    >>>>>> It would be nice for debugging to include the line number of where the
    >>>>>> code is when printing out the error message. Is there a simple way to
    >>>>>> get it, or do you need to create a Throwable then analyse the
    >>>>>> stacktrace?
    >>>>>
    >>>>> I guess one could also use Thread.currentThread().getStackTrace():
    >>>>>
    >>>>> http://download.oracle.com/javase/6/docs/api/java/lang/Thread.html#getStackTrace()
    >>>>>
    >>>>> But how's the current code line useful in such a log? If you see the
    >>>>> exact message you probably already know (or could easily find) where in
    >>>>> the source it is produced. If the same message is logged from
    >>>>> different
    >>>>> locations, probably the message should be revised to be more
    >>>>> specific as
    >>>>> appropriate?
    >>>> [ SNIP ]
    >>>>
    >>>> I agree 100%. In production Java applications that I help maintain or
    >>>> write, line numbers only feature in the error logs, and that's because
    >>>> we dump the full stack trace into the error log if there was a serious
    >>>> enough exception. For logging at any other level (info, warn, debug etc)
    >>>> the message format we have devised, and simply having a descriptive
    >>>> enough message, always pinpoints the location in the source. At worst
    >>>> you might have to do an indirect search in a properties file for a
    >>>> message key, then grep the source for that key, but that's like 10 extra
    >>>> seconds.
    >>>>
    >>>> We (I) happen to usually use log4j, and in the API docs for log4j
    >>>> PatternLayout, there are warnings about using the conversion specifiers
    >>>> for class name, file name, method name and line number, because they are
    >>>> slow or extremely slow. Since you don't actually need to compute any of
    >>>> these if you do what Stanimir suggests, why take the hit?
    >>>>
    >>>> This observation - about making the debugging message descriptive
    >>>> enough, without using computed source location information, to identify
    >>>> the location of the message - is applicable not just to use of a logger
    >>>> like log4j, but also quick and dirty println's or printf's. For example,
    >>>> if doing some throwaway printf's, I usually include a string of form
    >>>> "classname.methodname: " in the message.
    >>>
    >>> The problem with that approach is that it is designing the
    >>> logging based on an assumption that developers will do what they
    >>> are supposed to do. That assumption is not always true.

    >>
    >> Another way of looking at this is as a matter of where to put the burden
    >> of making sure the message can always be tracked back to the code that
    >> logged it, on the programmer or on the logging infrastructure.

    >
    > I understand the point you and Arne are making, but I see this issue
    > differently. Stanimir, and I, have advanced the notion that if the
    > message is sufficiently descriptive that one can locate the source of it
    > without difficulty. To answer your criticism, I'd simply say that if one
    > is so unsure about the quality of their programmers that they can't rely
    > on the messages being sufficiently descriptive for this purpose, all
    > that you've really got with the logging infrastructure supplying
    > location information is _tracing_.
    >
    > Personally, if I wanted tracing I'd use dtrace if I had it, or use
    > aspects, or both.
    >
    > Sure there is a burden on the programmer. Unless one assumes that the
    > single or main purpose of the log statements _is_ to trace, that burden
    > is to ensure that the log statements are descriptive and useful. That is
    > the prime directive. I actually don't see the point in assuming that the
    > log statements might not be sufficiently descriptive: sure, you can put
    > in the location specifiers but then you've simply got useless log
    > statements that you can accurately source.
    >
    >> In general, the more of the routine work that has to be done all over
    >> the place the infrastructure can manage the better. At a minimum, it
    >> saves programmer time and thinking for things the infrastructure cannot
    >> handle. It is especially important for code that may not be heavily
    >> tested - some log messages result from conditions that should never happen.

    >
    > But in this case all we are asking the programmers to do is to put in a
    > sufficiently descriptive log message. That's it. Not requiring them to
    > at least do that is to defeat the purpose of logging.
    >
    > I've had the opportunity to gather requirements for, design, and
    > implement major logging initiatives for a number of large J2EE/JEE
    > applications. In fact logging improvement, along with error handling
    > revamp, was the purpose of these mid-life projects. Requirements input
    > came from both operations support staff (who typically use Splunk to see
    > logs), and from production support developers (who get tasked with
    > fixing production defects and who work with the app logs also). I still
    > do other maintenance and new projects for these clients, so over the
    > past few years I've gotten useful feedback on how the new logging is
    > working. It's been quite positive: not only are the logs much better for
    > their intended purpose, but all the developers like the new system.
    > _They_ don't think it's a burden.


    It is probably easier to get logging right if adding logging is half
    the content of the project.

    > I'll add that in these work environments that I describe, that logging
    > is taken seriously enough that log statements (whether existing or new)
    > are also the subject of code reviews. This isn't 100% coverage, of
    > course, but there is enough review process that the quality of log
    > messages stays high.
    >
    > The only time with these applications, in a production support
    > situation, that statements could not be unambiguously pinpointed in the
    > source is because the statements themselves - the meat of the message -
    > were useless (maybe the work slipped review). Personally I believe that
    > the answer there is to improve the message.
    >
    > Again, based on the actual experiment, and observations thereafter, I
    > simply don't see that assuming that programmers cannot be counted on to
    > write sufficiently descriptive log messages is a valid concern. Not if
    > there are at least moderate processes in place. Sure, in a completely
    > undisciplined shop you may as well put in location specifiers with your
    > logger of choice, but ultimately all you've got then is tracing.


    If something requires humans to do it right, then it will sometimes
    go wrong.

    You can catch most with code reviews, but code reviews are not free.

    It could easily cost more than the resource usage of having the logging
    framework put in stuff.

    Arne
     
    Arne Vajhøj, Oct 14, 2011
    #11
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.

Share This Page