1. Home
  2. Categories
  3. Side Bar WTF
  4. At least, there is (sometimes) a log...

At least, there is (sometimes) a log...

  • G

    One of our application logs everything it does. But I always wondered why the log file was empty when the program crash...

    To log something, the app call LogInfos:

    private static void LogInfos(string message, string functionName)
    {
            string infos = m_info;
            m_info += infos + "[" + DateTime.Now.ToString("HH🇲🇲ss") + "] (" + nomFonction + ")\t " + message + " \r\n";
    }

     

    It took me a while to understand what this method does... I ticked when I saw the static keyword in this non-static class; and I looked for more "m_info". Bad idea.

    ~send_FTP()
     {
            FileInfo info = new FileInfo(@"..\Info_" + DateTime.Now.ToString("yyyyMMdd") + ".log");
            if (info.Exists)
            {
                m_SWLog = info.AppendText();
            }
            else
            {
                m_SWLog = info.CreateText();
            }
            m_SWLog.WriteLine(m_info);
            m_SWLog.Close();
    }


    So... When the program close normally, it writes the log. Not if it crash. Please, I want to wake up...

    0
  • C

    I'm not sure if it's irony, but the fact that they're creating a reference to an unmanaged resource (the file) in a finalizer, is just, well, bad...  Add to that that the file isn't handled in a using or try/finally is just, wow...  Also this should be in a dispose, not a finalizer.  If the original developer still works woth you, send them a link to garbage collection, finalizers, IDisposable, and using try/catch constructs, StringBuilder and don't give them their keyboard back until they have read and understand each of those concepts.

    I also love the "logger": string + string + string + "\r\n"...  Classic highschool code.  :)

    0
  • S

    Hey, this is even worse than our logging code!

    0
  • G

    @C-Octothorpe said:

    I'm not sure if it's irony, but the fact that they're creating a reference to an unmanaged resource (the file) in a finalizer, is just, well, bad...  Add to that that the file isn't handled in a using or try/finally is just, wow...  Also this should be in a dispose, not a finalizer.  If the original developer still works woth you, send them a link to garbage collection, finalizers, IDisposable, and using try/catch constructs, StringBuilder and don't give them their keyboard back until they have read and understand each of those concepts.

    I also love the "logger": string + string + string + "\r\n"...  Classic highschool code.  :)

    It seems my boss wrote this three years ago... I thought he was a good coder... I'm so disapointed...

    *headdesk*

    0
  • D

    @Sutherlands said:

    Hey, this is even worse than our logging code!

    At least you have logging code!

    0
  • N

    @C-Octothorpe said:

    I also love the "logger": string + string + string + "\r\n"...  Classic highschool code.  :)
     

    I am not a professional programmer, nor have I had any proper training, so please be gentle: but what's wrong with that?  I guess you could use a stringbuilder...

     

    0
  • D

    @Nook Schreier said:

    @C-Octothorpe said:

    I also love the "logger": string + string + string + "\r\n"...  Classic highschool code.  :)
     

    I am not a professional programmer, nor have I had any proper training, so please be gentle: but what's wrong with that?  I guess you could use a stringbuilder...

     

    I believe the WTF about that code snippet is that in Java, string concatenation would be the equivalent of each fragment instantiating a new String instance, which is a performance impact. StringBuilder, OTOH, does not suffer this impact and is preferred. If I am mistaken, I'm sure somebody would gladly correct me. :)

    0
  • blakeyrat

    @Nook Schreier said:

    I am not a professional programmer, nor have I had any proper training, so please be gentle: but what's wrong with that? I guess you could use a stringbuilder...

    Hopefully this isn't time-sensitive enough that a StringBuilder would gain you anything. The only problem I see, and it's mostly trivial, is that they're hard-coding \r\n when they should be using Environment.NewLine or equivalent.

    0
  • C

    @Nook Schreier said:

    @C-Octothorpe said:

    I also love the "logger": string + string + string + "\r\n"...  Classic highschool code.  :)
     

    I am not a professional programmer, nor have I had any proper training, so please be gentle: but what's wrong with that?  I guess you could use a stringbuilder...

    Nothing really technically "wrong" with it, but the problem is that in .Net, strings are immutable, which means once a string is created, it can't be changed.

    Imagine the following scenario:

    You have a string which contains several hundren or thousand log entries (one string, each log is \n\r delimited) because the app has been running for several hours.  Now you want to add a new log entry, which concatenates several smaller strings, but it doesn't really just append them, it has to create a new instance for each "+".  So you have a string which is quite big, and you have to create a new instance of it simply to append a bracket ("["), then the date stamp, then another bracket, then a space, etc...

    That is where the StringBuilder class comes in.  In .Net, each time you call StringBuilder.Append, it doesn't create a new string instance, but appends to an internal arrary which it maintains and resizes as appropriate.  This becomes much more handy in this situation because we know the "log" will grow to be quite large.

    Further to this is the fact that it shouldn't be holding all the logs in memory waiting until a graceful shutdown.  If I wrote this (and I've written stuff similar to this), I would keep a stream open to the file (yes, it keeps it locked, but whatever), and write to the file as the logs are created which solves the problem of missing logs during crashes and the memory overhead of maintain a huge string "log".  I'd also make sure that on dispose it flushes and closes the file stream.

    Also the string reference swapping makes it harder to follow what is going on (assigning the m_log to the local variable, then back again to the m_ global variable).

    0
  • P

    @dohpaz42 said:

    I believe the WTF about that code snippet is that in Java, string concatenation would be the equivalent of each fragment instantiating a new String instance, which is a performance impact. StringBuilder, OTOH, does not suffer this impact and is preferred. If I am mistaken, I'm sure somebody would gladly correct me. :)

    Instantiating a new String instance is not a performance impact. Object creation is cheap, in spite of what anti-GC trolls will tell you. However, copying the contents of the two strings which are being concatenated will get expensive when they get long.

    0
  • D

    @pjt33 said:

    Instantiating a new String instance is not a performance impact. Object creation is cheap, in spite of what anti-GC trolls will tell you. However, copying the contents of the two strings which are being concatenated will get expensive when they get long.

    Ah, well, that's good to know. What do you mean by "copying the contents of the two strings..."? Would this not occur for other methods (such as StringBuilder)? I ask in earnest, because I honestly don't know and I would like to understand these sort of things.

    0
  • C

    @dohpaz42 said:

    @pjt33 said:

    Instantiating a new String instance is not a performance impact. Object creation is cheap, in spite of what anti-GC trolls will tell you. However, copying the contents of the two strings which are being concatenated will get expensive when they get long.

    Ah, well, that's good to know. What do you mean by "copying the contents of the two strings..."? Would this not occur for other methods (such as StringBuilder)? I ask in earnest, because I honestly don't know and I would like to understand these sort of things.
    That's the difference between string concatenation and StringBuilder is that the SB doesn't use a string when appending.  It uses an internal arrary which it joins as a single string when you're done and you call it's overridden ToString method.  There is no string copying happening (except the reference to the string that is passed in to the SB append method).

    0
  • P

    Yeah, but outside a loop it's basically micro optimization.

    0
  • S

    @Power Troll said:

    Yeah, but outside a loop it's basically micro optimization.
    No.  In "small doses" it's a micro optimization.  The code in the OP is certainly not keeping a small string around and using it infrequently.  It's growing a very large string and probably changing it multiple times per call.

    0
  • C

    @Power Troll said:

    Yeah, but outside a loop it's basically micro optimization.
    I agree, and there are times where I'd use the "classic" string concatenation just for readability, but to make the real call, I'd have to see how often it's being called and what's the average lifespan for an instance of this app.

    Also, what I actually had the biggest problem with was that the entire "log" was in-memory, and not written in real time to the file, a la stream, or whatever, and the terrible "cleanup" code in the finalizer.

    0
  • blakeyrat

    @Sutherlands said:

    @Power Troll said:

    Yeah, but outside a loop it's basically micro optimization.
    No. In "small doses" it's a micro optimization. The code in the OP is certainly not keeping a small string around and using it infrequently. It's growing a very large string and probably changing it multiple times per call.

    Yes but that doesn't make the QUOTED LINE a WTF, the quoted line is fine. The WTF of having multi-megabyte log strings never being written to a file has nothing to do with whether the quoted line (the one we're all talking about) is a WTF or not.

    Please try to keep up.

    0
  • S

    @blakeyrat said:

    @Sutherlands said:

    @Power Troll said:

    Yeah, but outside a loop it's basically micro optimization.
    No. In "small doses" it's a micro optimization. The code in the OP is certainly not keeping a small string around and using it infrequently. It's growing a very large string and probably changing it multiple times per call.

    Yes but that doesn't make the QUOTED LINE a WTF, the quoted line is fine. The WTF of having multi-megabyte log strings never being written to a file has nothing to do with whether the quoted line (the one we're all talking about) is a WTF or not.

    Please try to keep up.

    It does make the quoted line wrong.  You know, the one that I quoted.  Please try to keep up.

    (Why are you ALWAYS a douchebag?)

    0
  • blakeyrat

    @Sutherlands said:

    It does make the quoted line wrong.  You know, the one that I quoted. Please try to keep up.

    (Why are you ALWAYS a douchebag?)

    Ok let's try this again.

    This line: m_info += infos + "[" + DateTime.Now.ToString("HH:mm:ss") + "] (" + nomFonction + ")\t " + message + " \r\n";, the line we were talking about, is not, by itself, incorrect. There is no scenario where using a StringBuilder here will speed up your application, unless your application is already an irredeemable pile of WTF. Let's call this A.

    Obviously letting the log string build up to epic proportions is a WTF, but that isn't what we were talking about. That is an entirely different WTF. Let's call this B.

    Now what you did is you entered a conversation about A, and you said it was a WTF due to B. What I was trying to explain to you is that A is not a WTF on its own; it's only a WTF when combined with B. Therefore, entering a conversation about A and saying it's a WTF due to B is (say it with me) completely missing the point.

    I'm not always a douchebag, just when the forum's boring. And before I've had my coffee. And when I feel like being a douchebag. And on alternate Tuesdays.

    0
  • S

    @blakeyrat said:

    I'm not always a douchebag

    FTFY

    @Sutherlands said:

    (Why are you ALWAYS a douchebag?)

    He was born that way but it got worse because of his daddy abandonment issues

    0
  • S

    I'm not talking about that line.  I'm talking about the line "outside of a loop [using a string builder is] a micro optimization."  That is not correct, and not what the quoted article is claiming.  A more correct statement is that in small doses, using a string builder is a micro optimization.  This is most likely not small doses.

    I did not say "this is a WTF due to <X>". 

    0
  • M

    @C-Octothorpe said:

    So you have a string which is quite big, and you have to create a new instance of it simply to append a bracket ("["), then the date stamp, then another bracket, then a space, etc...

    That would be very easy for an optimising compiler or interpreter to change, though. It doesn't make sense to allocate memory for the intermediate strings (or StringBuilder) when you're going to dump them before the end of the line anyway.

    I'm fairly sure that LogInfos has been mis-copied (as it looks like it would grow exponentially), so the function may not be as expensive as all that.

    0
  • C

    @__moz said:

    @C-Octothorpe said:
    So you have a string which is quite big, and you have to create a new instance of it simply to append a bracket ("["), then the date stamp, then another bracket, then a space, etc...

    That would be very easy for an optimising compiler or interpreter to change, though. It doesn't make sense to allocate memory for the intermediate strings (or StringBuilder) when you're going to dump them before the end of the line anyway.

    I'm fairly sure that LogInfos has been mis-copied (as it looks like it would grow exponentially), so the function may not be as expensive as all that.
    It can't optimize it because it's variable (see the timestamp and other parameters).  As I said before, it's stupid because it holds everything in memory until the last second, not necessarily because of the method of string building.  Either way, that point is moot simply because I would never keep such as huge string in-memory like that developer did.  Also, when handling strings, I personally prefer using the string.format method as I find it's more readable.  It also really pisses me off when I see string concatenation within a method call to string.Format (i.e. string.Fomat("", "asdf" + "Asdf" + "asdf") ).  WTF is the point, really?!

    0
  • P

    @dohpaz42 said:

    @pjt33 said:

    Instantiating a new String instance is not a performance impact. Object creation is cheap, in spite of what anti-GC trolls will tell you. However, copying the contents of the two strings which are being concatenated will get expensive when they get long.

    Ah, well, that's good to know. What do you mean by "copying the contents of the two strings..."? Would this not occur for other methods (such as StringBuilder)? I ask in earnest, because I honestly don't know and I would like to understand these sort of things.


    What goes on behind the scenes in languages with an immutable string is along the lines of (in a Java/C#-ish pseudocode)

    static string op+(string a, string b) {
    char[] buf = new char[a.length + b.length];
    arraycopy(a.buf, 0, buf, 0, a.length);
    arraycopy(b.buf, 0, buf, a.length, b.length);
    return new string(buf);
}

    If you have m strings each of length n and you add them using + then the first + copies 2n chars, the second copies 3n chars, etc; the last copies mn chars. Overall cost is quadratic in m.

    A string builder, on the other hand, has a backing array which it expands exponentially. So the append method would be something like

    void append(string a) {
    if (currentLength + a.length > buf.length) {
        int newLength = buf.length * 2;
        while(newLength < currentLength + a.length) newLength *= 2;

        char[] newBuf = new buf[newLength];
        arraycopy(buf, 0, newBuf, 0, currentLength);
        buf = newBuf;
    }
    arraycopy(a.buf, 0, buf, currentLength, a.length);
    currentLength += a.length;
}

    There's an absolute minimum of mn character-copies required. The number of additional copies from expanding the buffer depends on its initial size, but we can bound it. If the final length of the buffer is N, expanding it to N copied no more than N/2 characters from a buffer no longer than N/2. We can reason inductively and deduce that so the total number of additional copies is no more than N/2 + N/4 + N/8 + ... = 2N. And from that you can show that the number of character-copies is linear in m.

    0
Log in to reply