ZooKeeper
  1. ZooKeeper
  2. ZOOKEEPER-1400

Allow logging via callback instead of raw FILE pointer

    Details

    • Type: Improvement Improvement
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.5.0
    • Fix Version/s: 3.5.0
    • Component/s: c client
    • Labels:
      None
    • Environment:

      Linux

      Description

      The existing logging framework inside the C client uses a raw FILE*. Using a FILE* is very limiting and potentially dangerous. A safer alternative is to just provide a callback that the C client will call for each message. In our environment, we saw some really nasty issues with multiple threads all connecting to zookeeper via the C Client related to the use of a raw FILE*. Specifically, if the FILE * is closed and that file descriptor is reused by the kernel before the C client is notified then the C client will use it's static global logStream pointer for subsequent logging messages. That FILE* is now a loose cannon! In our environment, we saw zookeeper log messages ending up in other sockets and even in our core data path. Clearly this is dangerous. In our particular case, we'd omitted a call to zoo_set_log_stream(NULL) to notify C client that the FILE* has been closed. However, even with that bug fixed, there's still a race condition where log messages in flight may be sent before the C client is notified of the FILE closure, and the same problem can happen.

      Other issues we've seen involved multiple threads, wherein one would close the FILE*, and that's a global change that affects all threads connected within that process. That's a pretty nasty limitation as well.

      My proposed change is to allow setting a callback for log messages. A callback is used in preference to a raw FILE*. If no callback is set, then it will fallback to the existing FILE*. If that's not set, then it falls back to stderr as it always has.

      While refactoring this code, I removed the need for the double parens in all the LOG macros as that wasn't necessary and didn't fit with my new approach.

      1. ZOOKEEPER-1400.patch
        59 kB
        Marshall McMullen
      2. ZOOKEEPER-1400.patch
        66 kB
        Marshall McMullen
      3. ZOOKEEPER-1400.patch
        70 kB
        Marshall McMullen
      4. ZOOKEEPER-1400.patch
        70 kB
        Marshall McMullen
      5. ZOOKEEPER-1400.patch
        70 kB
        Marshall McMullen
      6. ZOOKEEPER-1400.patch
        69 kB
        Marshall McMullen
      7. ZOOKEEPER-1400.patch
        5 kB
        Michi Mutsuzaki
      8. ZOOKEEPER-1400.patch
        5 kB
        Michi Mutsuzaki

        Activity

        Hide
        Marshall McMullen added a comment -

        Please see attached path that provides my new proposed functionality.

        Show
        Marshall McMullen added a comment - Please see attached path that provides my new proposed functionality.
        Hide
        Stephen Tyree added a comment -

        This is a really great change. I've gone so far as to both create a global FILE* singleton instance to prevent race conditions from closing the handle and to create a pipe that is written to from a FILE* and read from a part of my code to deal with this interface's shortcomings. If we're going this far, might I also suggest we add logging on a per connection basis? For a large application using Zookeeper, there might be multiple consumers/connections who want to manage logs each in their own special way.

        Show
        Stephen Tyree added a comment - This is a really great change. I've gone so far as to both create a global FILE* singleton instance to prevent race conditions from closing the handle and to create a pipe that is written to from a FILE* and read from a part of my code to deal with this interface's shortcomings. If we're going this far, might I also suggest we add logging on a per connection basis? For a large application using Zookeeper, there might be multiple consumers/connections who want to manage logs each in their own special way.
        Hide
        Marshall McMullen added a comment -

        Thanks for the great feedback. I absolutely agree that the logging should be on a connection basis. I was hesitant to make an even more drastic change than I already had. Do you think changing the logging to be per-connection should be a separate JIRA or does it make sense to do it as part of this case as well?

        Show
        Marshall McMullen added a comment - Thanks for the great feedback. I absolutely agree that the logging should be on a connection basis. I was hesitant to make an even more drastic change than I already had. Do you think changing the logging to be per-connection should be a separate JIRA or does it make sense to do it as part of this case as well?
        Hide
        Stephen Tyree added a comment -

        Sorry for the delay

        I think that would make sense to be a separate JIRA. As far as your change goes it looks good, but a couple of points:

        + char* buf = get_format_log_buffer();

        This means there is now a limit on log size that wasn't there before. Have you made sure this buffer can handle all possible log messages?

        Also, you made a bunch of formatting changes that seem tangential to the change itself, like the following:

        • static const char* dbgLevelStr[]= {"ZOO_INVALID","ZOO_ERROR","ZOO_WARN", - "ZOO_INFO","ZOO_DEBUG"}

          ;
          + char* buf = get_format_log_buffer();
          + if(!buf)
          + return;
          +
          + static const char* dbgLevelStr[] =

          {"ZOO_INVALID", + "ZOO_ERROR", + "ZOO_WARN", + "ZOO_INFO", + "ZOO_DEBUG"}

          ;

        Maybe those should be reserved for a separate change just to keep things tidy?

        Show
        Stephen Tyree added a comment - Sorry for the delay I think that would make sense to be a separate JIRA. As far as your change goes it looks good, but a couple of points: + char* buf = get_format_log_buffer(); This means there is now a limit on log size that wasn't there before. Have you made sure this buffer can handle all possible log messages? Also, you made a bunch of formatting changes that seem tangential to the change itself, like the following: static const char* dbgLevelStr[]= {"ZOO_INVALID","ZOO_ERROR","ZOO_WARN", - "ZOO_INFO","ZOO_DEBUG"} ; + char* buf = get_format_log_buffer(); + if(!buf) + return; + + static const char* dbgLevelStr[] = {"ZOO_INVALID", + "ZOO_ERROR", + "ZOO_WARN", + "ZOO_INFO", + "ZOO_DEBUG"} ; Maybe those should be reserved for a separate change just to keep things tidy?
        Hide
        Michi Mutsuzaki added a comment -

        Hi Marshall,

        Sorry for the late response. This is a great patch! Here are my comments:

        • The documentation for zoo_set_log_callback() should make it clear that the callback will be invoked by multiple threads and therefore it needs to be thread-safe.
        • We probably want to log something if get_format_log_buffer() returns NULL, something similar to "format_log_message: Unable to allocate memory buffer".
        • Do you need to pass FORMAT_LOG_BUF_SIZE-1 to snprintf(), or would FORMAT_LOG_BUF_SIZE work? I thought snprintf() guarantees that the output is null-terminated.
        • This patch should be unit-tested (now that it's much easier to unit test the logging code with the callback ).
        • It would be great if you can share how you are using the callback for your logging on our wiki page. I'm pretty sure many people will find it very useful.
        • While refactoring this code, I removed the need for the double parens in all the LOG macros as that wasn't necessary and didn't fit with my new approach.

          Cool!

        Regarding Stephen's comment:

        • Yes, please put per-connection logging on a separate jira.
        • This means there is now a limit on log size that wasn't there before. Have you made sure this buffer can handle all possible log messages?

          The longest line I got from the unit test was less than 500 characters. I also eyeballed all the LOG_* calls, and they all look much less than 4096 characters. It's difficult to be absolutely sure since the log message is not fixed length, but I think it would be ok.

        • Maybe those should be reserved for a separate change just to keep things tidy?

          Yes, I generally prefer patches without cosmetic changes.

        Thanks!
        --Michi

        Show
        Michi Mutsuzaki added a comment - Hi Marshall, Sorry for the late response. This is a great patch! Here are my comments: The documentation for zoo_set_log_callback() should make it clear that the callback will be invoked by multiple threads and therefore it needs to be thread-safe. We probably want to log something if get_format_log_buffer() returns NULL, something similar to "format_log_message: Unable to allocate memory buffer". Do you need to pass FORMAT_LOG_BUF_SIZE-1 to snprintf() , or would FORMAT_LOG_BUF_SIZE work? I thought snprintf() guarantees that the output is null-terminated. This patch should be unit-tested (now that it's much easier to unit test the logging code with the callback ). It would be great if you can share how you are using the callback for your logging on our wiki page. I'm pretty sure many people will find it very useful. While refactoring this code, I removed the need for the double parens in all the LOG macros as that wasn't necessary and didn't fit with my new approach. Cool! Regarding Stephen's comment: Yes, please put per-connection logging on a separate jira. This means there is now a limit on log size that wasn't there before. Have you made sure this buffer can handle all possible log messages? The longest line I got from the unit test was less than 500 characters. I also eyeballed all the LOG_* calls, and they all look much less than 4096 characters. It's difficult to be absolutely sure since the log message is not fixed length, but I think it would be ok. Maybe those should be reserved for a separate change just to keep things tidy? Yes, I generally prefer patches without cosmetic changes. Thanks! --Michi
        Hide
        Marshall McMullen added a comment -

        This updated patch incorporates Stephen's suggestion of making the log callback per-handle. There is still a zoo_set_log_callback function, but it now takes a zhandle_t* to associate the callback with.

        I've also added a zookeeper_init2 which is the same as zookeeper_init but adds an extra argument for the log callback.

        Show
        Marshall McMullen added a comment - This updated patch incorporates Stephen's suggestion of making the log callback per-handle. There is still a zoo_set_log_callback function, but it now takes a zhandle_t* to associate the callback with. I've also added a zookeeper_init2 which is the same as zookeeper_init but adds an extra argument for the log callback.
        Hide
        Marshall McMullen added a comment -

        BTW, I haven't yet had time to address the additional very good comments from Stephen and Michi. Been super swamped at work... I'll add an updated patch which addresses their concerns when things quiet down for me a bit.

        Show
        Marshall McMullen added a comment - BTW, I haven't yet had time to address the additional very good comments from Stephen and Michi. Been super swamped at work... I'll add an updated patch which addresses their concerns when things quiet down for me a bit.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12533092/ZOOKEEPER-1400.patch
        against trunk revision 1351541.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 13 new or modified tests.

        -1 patch. The patch command could not apply the patch.

        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1108//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12533092/ZOOKEEPER-1400.patch against trunk revision 1351541. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 13 new or modified tests. -1 patch. The patch command could not apply the patch. Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1108//console This message is automatically generated.
        Hide
        Marshall McMullen added a comment -

        My patch should apply cleanly to trunk.

        Show
        Marshall McMullen added a comment - My patch should apply cleanly to trunk.
        Hide
        Marshall McMullen added a comment -

        Oops, I had other patches in my version so the patch isn't perfect. I'll get a new version updated momentarily.

        Show
        Marshall McMullen added a comment - Oops, I had other patches in my version so the patch isn't perfect. I'll get a new version updated momentarily.
        Hide
        Marshall McMullen added a comment -

        Updated patch that should apply cleanly to trunk.

        Show
        Marshall McMullen added a comment - Updated patch that should apply cleanly to trunk.
        Hide
        Hadoop QA added a comment -

        +1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12533125/ZOOKEEPER-1400-1.patch
        against trunk revision 1351541.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 13 new or modified tests.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        +1 core tests. The patch passed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12533125/ZOOKEEPER-1400-1.patch against trunk revision 1351541. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 13 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1111//console This message is automatically generated.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12533125/ZOOKEEPER-1400-1.patch
        against trunk revision 1414566.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 13 new or modified tests.

        -1 patch. The patch command could not apply the patch.

        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1275//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12533125/ZOOKEEPER-1400-1.patch against trunk revision 1414566. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 13 new or modified tests. -1 patch. The patch command could not apply the patch. Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1275//console This message is automatically generated.
        Hide
        Stephen Tyree added a comment -

        This was a great patch. Any way we could rework it so it applies cleanly and get it tested/submitted?

        Show
        Stephen Tyree added a comment - This was a great patch. Any way we could rework it so it applies cleanly and get it tested/submitted?
        Hide
        Marshall McMullen added a comment -

        Yes, agree. We use this heavily internally and maintaining this patch every time I upgrade zookeeper locally it getting to be a pain. So I'd really like to get this integrated into zookeeper proper.

        I've got some time over the next day or so. I will get this updated and think on how to do some testing against it.

        Show
        Marshall McMullen added a comment - Yes, agree. We use this heavily internally and maintaining this patch every time I upgrade zookeeper locally it getting to be a pain. So I'd really like to get this integrated into zookeeper proper. I've got some time over the next day or so. I will get this updated and think on how to do some testing against it.
        Hide
        Flavio Junqueira added a comment -

        Hi Stephen, Would you or Marshall have time to work on a new version of the patch that applies to trunk?

        Michi Mutsuzaki, Mahadev konar, would one of you guys have time to take a look at this patch?

        Show
        Flavio Junqueira added a comment - Hi Stephen, Would you or Marshall have time to work on a new version of the patch that applies to trunk? Michi Mutsuzaki , Mahadev konar , would one of you guys have time to take a look at this patch?
        Hide
        Marshall McMullen added a comment -

        I'll get an updated version of the patch ready today.

        Will take more time to add a couple unit tests around this. Shouldn't be too hard though.

        Show
        Marshall McMullen added a comment - I'll get an updated version of the patch ready today. Will take more time to add a couple unit tests around this. Shouldn't be too hard though.
        Hide
        Marshall McMullen added a comment -

        Updated patch to apply to tip of trunk 1482502 and added some unit tests.

        Show
        Marshall McMullen added a comment - Updated patch to apply to tip of trunk 1482502 and added some unit tests.
        Hide
        Marshall McMullen added a comment -

        In my latest patch in addition to updating to apply to trunk cleanly, I also added 3 tests (localized to one function for convenience) and addressed Stephen and Michi's earlier comments.

        Show
        Marshall McMullen added a comment - In my latest patch in addition to updating to apply to trunk cleanly, I also added 3 tests (localized to one function for convenience) and addressed Stephen and Michi's earlier comments.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12583204/ZOOKEEPER-1400.patch
        against trunk revision 1482318.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 16 new or modified tests.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        -1 core tests. The patch failed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12583204/ZOOKEEPER-1400.patch against trunk revision 1482318. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 16 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. -1 core tests. The patch failed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1479//console This message is automatically generated.
        Hide
        Marshall McMullen added a comment -

        This failed test is unrelated: ZOOKEEPER-1629: org.apache.zookeeper.server.TruncateCorruptionTest.testTransactionLogCorruption

        Show
        Marshall McMullen added a comment - This failed test is unrelated: ZOOKEEPER-1629 : org.apache.zookeeper.server.TruncateCorruptionTest.testTransactionLogCorruption
        Hide
        Stephen Tyree added a comment -

        Looked over your change Marshall, thanks for the extremely quick response! Some questions:

        • Why in create_completion_entry do you LOG_ERROR to LOG_STREAM instead of LOGCALLBACK? Sometimes logging to the callback and sometimes not seems like confusing behavior for an end user.
        • Why did you change resolve_hosts to be static? If it works with it being static, then it probably should be static, just curious of the reasoning.
        • You use variadic macros with log_message, and a GCC extension of them at that. Assuming you switch to the C99 way of doing them, does the Zookeeper library target C99? Would this work on Windows?
        Show
        Stephen Tyree added a comment - Looked over your change Marshall, thanks for the extremely quick response! Some questions: Why in create_completion_entry do you LOG_ERROR to LOG_STREAM instead of LOGCALLBACK? Sometimes logging to the callback and sometimes not seems like confusing behavior for an end user. Why did you change resolve_hosts to be static? If it works with it being static, then it probably should be static, just curious of the reasoning. You use variadic macros with log_message, and a GCC extension of them at that. Assuming you switch to the C99 way of doing them, does the Zookeeper library target C99? Would this work on Windows?
        Hide
        Marshall McMullen added a comment -

        Updated patch to address latest comments.

        Show
        Marshall McMullen added a comment - Updated patch to address latest comments.
        Hide
        Marshall McMullen added a comment -

        Stephen - thanks for the quick review. As to your questions:

        1.Why in create_completion_entry do you LOG_ERROR to LOG_STREAM instead of LOGCALLBACK? Sometimes logging to the callback and sometimes not seems like confusing behavior for an end user.

        That was an oversight. Didn't have a zhandle* in create_competion_entry so that was probably the easy solution at the time. I've updated the patch to pass the zhandle* through to create_completion_entry so we can use LOGCALLBACK like everywhere else consistently.

        2.Why did you change resolve_hosts to be static? If it works with it being static, then it probably should be static, just curious of the reasoning.

        It's not a publicly documented function and does not appear in zookeeper.h and is not called anywhere outside of zookeeper.c. And there's no rational reason for that to be a public function that I could think of as it's very much internal. That said, it's definitely a tangental change so I will revert that part if that's a deal breaker for anyone. But I don't think it should be.

        3.You use variadic macros with log_message, and a GCC extension of them at that. Assuming you switch to the C99 way of doing them, does the Zookeeper library target C99? Would this work on Windows?

        Not sure what you mean here... I'm not using any variadic macros. Perhaps you're referring to my use of vsnprintf? Frankly I don't do anything on windows so I often forget about it . I am far from an expert in the windows way to do this, but a quick google turned up:

        http://msdn.microsoft.com/en-us/library/w05tbk72%28VS.71%29.aspx
        _vscprintf returns the number of characters that would be generated if the string pointed to by the list of arguments was printed or sent to a file or buffer using the specified formatting codes. The value returned does not include the terminating null character.

        Wonder why they went to the trouble to implement this instead of just implementing vsnprintf and comply with C99.

        Anyhow, clarify for me if that is what you're referring to. As I don't have any access to a windows machine or compiler would need someone interested in that to assist testing out my proposed solution.

        Show
        Marshall McMullen added a comment - Stephen - thanks for the quick review. As to your questions: 1.Why in create_completion_entry do you LOG_ERROR to LOG_STREAM instead of LOGCALLBACK? Sometimes logging to the callback and sometimes not seems like confusing behavior for an end user. That was an oversight. Didn't have a zhandle* in create_competion_entry so that was probably the easy solution at the time. I've updated the patch to pass the zhandle* through to create_completion_entry so we can use LOGCALLBACK like everywhere else consistently. 2.Why did you change resolve_hosts to be static? If it works with it being static, then it probably should be static, just curious of the reasoning. It's not a publicly documented function and does not appear in zookeeper.h and is not called anywhere outside of zookeeper.c. And there's no rational reason for that to be a public function that I could think of as it's very much internal. That said, it's definitely a tangental change so I will revert that part if that's a deal breaker for anyone. But I don't think it should be. 3.You use variadic macros with log_message, and a GCC extension of them at that. Assuming you switch to the C99 way of doing them, does the Zookeeper library target C99? Would this work on Windows? Not sure what you mean here... I'm not using any variadic macros. Perhaps you're referring to my use of vsnprintf? Frankly I don't do anything on windows so I often forget about it . I am far from an expert in the windows way to do this, but a quick google turned up: http://msdn.microsoft.com/en-us/library/w05tbk72%28VS.71%29.aspx _vscprintf returns the number of characters that would be generated if the string pointed to by the list of arguments was printed or sent to a file or buffer using the specified formatting codes. The value returned does not include the terminating null character. Wonder why they went to the trouble to implement this instead of just implementing vsnprintf and comply with C99. Anyhow, clarify for me if that is what you're referring to. As I don't have any access to a windows machine or compiler would need someone interested in that to assist testing out my proposed solution.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12583269/ZOOKEEPER-1400.patch
        against trunk revision 1482318.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 16 new or modified tests.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        -1 core tests. The patch failed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12583269/ZOOKEEPER-1400.patch against trunk revision 1482318. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 16 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. -1 core tests. The patch failed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1480//console This message is automatically generated.
        Hide
        Marshall McMullen added a comment -

        One of my new tests failed after my latest refactor. I'll look at this when I get a few minutes.

        Show
        Marshall McMullen added a comment - One of my new tests failed after my latest refactor. I'll look at this when I get a few minutes.
        Hide
        Stephen Tyree added a comment -

        re: question 3, this is in your latest patch:

        +#define LOG_ERROR(_cb, _msg...) if(logLevel>=ZOO_LOG_LEVEL_ERROR) \
        + log_message(cb, ZOO_LOG_LEVEL_ERROR, __LINE, __func_, _msg)

        Specifically the line _msg... and its usage in log_message, from the GCC documentation (http://gcc.gnu.org/onlinedocs/cpp/Variadic-Macros.html):

        "If your macro is complicated, you may want a more descriptive name for the variable argument than _VA_ARGS_. CPP permits this, as an extension. You may write an argument name immediately before the ‘...’; that name is used for the variable argument."

        Does that clarify my question, or am I crazy?

        Show
        Stephen Tyree added a comment - re: question 3, this is in your latest patch: +#define LOG_ERROR(_cb, _msg...) if(logLevel>=ZOO_LOG_LEVEL_ERROR) \ + log_message( cb, ZOO_LOG_LEVEL_ERROR, __LINE , __func _, _msg) Specifically the line _msg... and its usage in log_message, from the GCC documentation ( http://gcc.gnu.org/onlinedocs/cpp/Variadic-Macros.html): "If your macro is complicated, you may want a more descriptive name for the variable argument than _ VA_ARGS _. CPP permits this, as an extension. You may write an argument name immediately before the ‘...’; that name is used for the variable argument." Does that clarify my question, or am I crazy?
        Hide
        Marshall McMullen added a comment -

        Change variadic macros to use _VA_ARGS_ instead of GCC extension of named variadic args parameter.

        Show
        Marshall McMullen added a comment - Change variadic macros to use _ VA_ARGS _ instead of GCC extension of named variadic args parameter.
        Hide
        Marshall McMullen added a comment -

        Stephen - Ah, you are absolutely correct. I thought you were referring to the function log_message not the wrapper macros that call into log_message. Yes, I was using a GCC extension (didn't actually know that wasn't standard to C99). I've revised the patch to use normal _VA_ARGS_. I think the current method should work on windows, but as I have no access to a windows machine or compiler I can't verify that. I assume the pre-commit job doesn't actually try to build this on windows and that only happens after a jira is committed... that's a shame.

        At any rate, I've updated the patch. I want to see if the unit test fails again. It did not fail for me locally on my machine. My test is probably too particular in the number of messages it expects to be logged. Other code paths may trigger a log message non deterministically and cause the test to fail. If that's the case I will loosen things up.

        Show
        Marshall McMullen added a comment - Stephen - Ah, you are absolutely correct. I thought you were referring to the function log_message not the wrapper macros that call into log_message. Yes, I was using a GCC extension (didn't actually know that wasn't standard to C99). I've revised the patch to use normal _ VA_ARGS _. I think the current method should work on windows, but as I have no access to a windows machine or compiler I can't verify that. I assume the pre-commit job doesn't actually try to build this on windows and that only happens after a jira is committed... that's a shame. At any rate, I've updated the patch. I want to see if the unit test fails again. It did not fail for me locally on my machine. My test is probably too particular in the number of messages it expects to be logged. Other code paths may trigger a log message non deterministically and cause the test to fail. If that's the case I will loosen things up.
        Hide
        Marshall McMullen added a comment -

        Trying to resubmit patch to get it to run again.

        Show
        Marshall McMullen added a comment - Trying to resubmit patch to get it to run again.
        Hide
        Marshall McMullen added a comment -

        Can anyone explain why my latest patch isn't getting test on Jenkins?

        Show
        Marshall McMullen added a comment - Can anyone explain why my latest patch isn't getting test on Jenkins?
        Hide
        Flavio Junqueira added a comment -

        Build is running but failing, check this out:

        https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1481/

        Show
        Flavio Junqueira added a comment - Build is running but failing, check this out: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1481/
        Hide
        Marshall McMullen added a comment -

        Interesting... I am used to seeing the test results show up in the jira. Has that changed?

        Show
        Marshall McMullen added a comment - Interesting... I am used to seeing the test results show up in the jira. Has that changed?
        Hide
        Flavio Junqueira added a comment -

        The build aborted, that's why it didn't report:

        Build timed out (after 62 minutes). Marking the build as aborted.
        Build was aborted

        Most likely it is not related to your patch.

        Show
        Flavio Junqueira added a comment - The build aborted, that's why it didn't report: Build timed out (after 62 minutes). Marking the build as aborted. Build was aborted Most likely it is not related to your patch.
        Hide
        Marshall McMullen added a comment -

        Is there a way to get it to run again? Very confused...

        Show
        Marshall McMullen added a comment - Is there a way to get it to run again? Very confused...
        Hide
        Flavio Junqueira added a comment -

        I haven't had a chance to do it, but perhaps you could have a look at the console output of the failed build (1481) to see if you can spot the exact problem.

        To resubmit, just cancel the patch and submit it again.

        Show
        Flavio Junqueira added a comment - I haven't had a chance to do it, but perhaps you could have a look at the console output of the failed build (1481) to see if you can spot the exact problem. To resubmit, just cancel the patch and submit it again.
        Hide
        Marshall McMullen added a comment -

        Updated patch to address failing? unit test

        Show
        Marshall McMullen added a comment - Updated patch to address failing? unit test
        Hide
        Flavio Junqueira added a comment -

        It could actually be something related to this patch, but I'm not sure:

        Build timed out (after 62 minutes). Marking the build as aborted.
             [exec]      [exec] /bin/bash: line 5: 21011 Terminated              ZKROOT=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/src/c/../.. CLASSPATH=$CLASSPATH:$CLOVER_HOME/lib/clover.jar ${dir}$tst
        Build was aborted
             [exec]      [exec] FAIL: zktest-mt
             [exec]      [exec] ==========================================
             [exec]      [exec] 1 of 2 tests failed
             [exec]      [exec] Please report to user@zookeeper.apache.org
             [exec]      [exec] ==========================================
             [exec]      [exec] make[1]: *** [check-TESTS] Error 1
        

        Note that it says that zktest-mt has failed. I have also been trying to have it running the patch of ZOOKEEPER-1642 unsuccessfully, so it might be something else.

        Show
        Flavio Junqueira added a comment - It could actually be something related to this patch, but I'm not sure: Build timed out (after 62 minutes). Marking the build as aborted. [exec] [exec] /bin/bash: line 5: 21011 Terminated ZKROOT=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/src/c/../.. CLASSPATH=$CLASSPATH:$CLOVER_HOME/lib/clover.jar ${dir}$tst Build was aborted [exec] [exec] FAIL: zktest-mt [exec] [exec] ========================================== [exec] [exec] 1 of 2 tests failed [exec] [exec] Please report to user@zookeeper.apache.org [exec] [exec] ========================================== [exec] [exec] make[1]: *** [check-TESTS] Error 1 Note that it says that zktest-mt has failed. I have also been trying to have it running the patch of ZOOKEEPER-1642 unsuccessfully, so it might be something else.
        Hide
        Marshall McMullen added a comment -

        Finally had time to look at this again. Was a problem in the new unit and how they continually started/stopped ZK server and ZK client connection. Broke things out into separate tests and problems went away.

        Show
        Marshall McMullen added a comment - Finally had time to look at this again. Was a problem in the new unit and how they continually started/stopped ZK server and ZK client connection. Broke things out into separate tests and problems went away.
        Hide
        Hadoop QA added a comment -

        +1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12583720/ZOOKEEPER-1400.patch
        against trunk revision 1483440.

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 16 new or modified tests.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        +1 core tests. The patch passed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12583720/ZOOKEEPER-1400.patch against trunk revision 1483440. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 16 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1485//console This message is automatically generated.
        Hide
        Marshall McMullen added a comment -

        I think everyone's concerns are addressed and resolved at this point. Please let me know if that's not the case.

        Would love to get this integrated into trunk sooner rather than later as it does address a very serious potential security issue. And maintaining this patch is becoming problematic as code continues to diverge... thanks!

        Show
        Marshall McMullen added a comment - I think everyone's concerns are addressed and resolved at this point. Please let me know if that's not the case. Would love to get this integrated into trunk sooner rather than later as it does address a very serious potential security issue. And maintaining this patch is becoming problematic as code continues to diverge... thanks!
        Hide
        Michi Mutsuzaki added a comment -

        +1. Thank you for the great patch, Marshall!

        Show
        Michi Mutsuzaki added a comment - +1. Thank you for the great patch, Marshall!
        Hide
        Michi Mutsuzaki added a comment -

        Merged to trunk in r1484357.

        Show
        Michi Mutsuzaki added a comment - Merged to trunk in r1484357.
        Hide
        Marshall McMullen added a comment -

        Thanks very much for getting this committed Michi. Really glad to have this off my maintenance plate .

        Show
        Marshall McMullen added a comment - Thanks very much for getting this committed Michi. Really glad to have this off my maintenance plate .
        Hide
        Hudson added a comment -

        Integrated in ZooKeeper-trunk #1932 (See https://builds.apache.org/job/ZooKeeper-trunk/1932/)
        ZOOKEEPER-1400. Allow logging via callback instead of raw FILE pointer (Marshall McMullen via michim) (Revision 1484357)

        Result = FAILURE
        michim : http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1484357
        Files :

        • /zookeeper/trunk/CHANGES.txt
        • /zookeeper/trunk/src/c/include/zookeeper.h
        • /zookeeper/trunk/src/c/include/zookeeper_log.h
        • /zookeeper/trunk/src/c/src/load_gen.c
        • /zookeeper/trunk/src/c/src/mt_adaptor.c
        • /zookeeper/trunk/src/c/src/zk_adaptor.h
        • /zookeeper/trunk/src/c/src/zk_log.c
        • /zookeeper/trunk/src/c/src/zookeeper.c
        • /zookeeper/trunk/src/c/tests/PthreadMocks.h
        • /zookeeper/trunk/src/c/tests/TestClient.cc
        • /zookeeper/trunk/src/c/tests/TestOperations.cc
        • /zookeeper/trunk/src/c/tests/Util.h
        Show
        Hudson added a comment - Integrated in ZooKeeper-trunk #1932 (See https://builds.apache.org/job/ZooKeeper-trunk/1932/ ) ZOOKEEPER-1400 . Allow logging via callback instead of raw FILE pointer (Marshall McMullen via michim) (Revision 1484357) Result = FAILURE michim : http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1484357 Files : /zookeeper/trunk/CHANGES.txt /zookeeper/trunk/src/c/include/zookeeper.h /zookeeper/trunk/src/c/include/zookeeper_log.h /zookeeper/trunk/src/c/src/load_gen.c /zookeeper/trunk/src/c/src/mt_adaptor.c /zookeeper/trunk/src/c/src/zk_adaptor.h /zookeeper/trunk/src/c/src/zk_log.c /zookeeper/trunk/src/c/src/zookeeper.c /zookeeper/trunk/src/c/tests/PthreadMocks.h /zookeeper/trunk/src/c/tests/TestClient.cc /zookeeper/trunk/src/c/tests/TestOperations.cc /zookeeper/trunk/src/c/tests/Util.h
        Hide
        Marshall McMullen added a comment -

        Was this a patch failure or a test failure? Let me know what I can do to help.

        Show
        Marshall McMullen added a comment - Was this a patch failure or a test failure? Let me know what I can do to help.
        Hide
        Flavio Junqueira added a comment -

        Apparently the failure indicated is because of this test:

        org.apache.zookeeper.server.TruncateCorruptionTest.testTransactionLogCorruption
        

        It sounds like it is due to ZOOKEEPER-1629.

        Show
        Flavio Junqueira added a comment - Apparently the failure indicated is because of this test: org.apache.zookeeper.server.TruncateCorruptionTest.testTransactionLogCorruption It sounds like it is due to ZOOKEEPER-1629 .
        Hide
        Michi Mutsuzaki added a comment -

        It looks like some functions in mt_adaptor.c uses the zh variable without defining it. Windows compiler complains about this.

         int handle_error(SOCKET sock, char* message)
         {
                LOG_ERROR(LOGCALLBACK(zh), "%s. %d",message, WSAGetLastError());
                closesocket (sock);
                return -1;
         }
        
        Show
        Michi Mutsuzaki added a comment - It looks like some functions in mt_adaptor.c uses the zh variable without defining it. Windows compiler complains about this. int handle_error(SOCKET sock, char * message) { LOG_ERROR(LOGCALLBACK(zh), "%s. %d" ,message, WSAGetLastError()); closesocket (sock); return -1; }
        Hide
        Flavio Junqueira added a comment -

        I'm observing the same when trying to compile it with VS 2012.

        Show
        Flavio Junqueira added a comment - I'm observing the same when trying to compile it with VS 2012.
        Hide
        Michi Mutsuzaki added a comment -

        This patch fixes windows compilation issues introduced by this JIRA. After applying this patch, we still need to fix https://issues.apache.org/jira/browse/ZOOKEEPER-1679

        Show
        Michi Mutsuzaki added a comment - This patch fixes windows compilation issues introduced by this JIRA. After applying this patch, we still need to fix https://issues.apache.org/jira/browse/ZOOKEEPER-1679
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12592421/ZOOKEEPER-1400.patch
        against trunk revision 1503101.

        +1 @author. The patch does not contain any @author tags.

        -1 tests included. The patch doesn't appear to include any new or modified tests.
        Please justify why no new tests are needed for this patch.
        Also please list what manual steps were performed to verify this patch.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        -1 core tests. The patch failed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12592421/ZOOKEEPER-1400.patch against trunk revision 1503101. +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. -1 core tests. The patch failed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1518//console This message is automatically generated.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12592441/ZOOKEEPER-1400.patch
        against trunk revision 1503101.

        +1 @author. The patch does not contain any @author tags.

        -1 tests included. The patch doesn't appear to include any new or modified tests.
        Please justify why no new tests are needed for this patch.
        Also please list what manual steps were performed to verify this patch.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        +1 core tests. The patch passed core unit tests.

        +1 contrib tests. The patch passed contrib unit tests.

        Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12592441/ZOOKEEPER-1400.patch against trunk revision 1503101. +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1520//console This message is automatically generated.
        Hide
        Michi Mutsuzaki added a comment -

        This patch fixes compilation errors, so there are no new tests.

        Show
        Michi Mutsuzaki added a comment - This patch fixes compilation errors, so there are no new tests.
        Hide
        Flavio Junqueira added a comment -

        I've given this patch a try along with ZOOKEEPER-1679 and it works fine, +1.

        I still get a lot of warnings on Visual Studio 2012, though.

        Show
        Flavio Junqueira added a comment - I've given this patch a try along with ZOOKEEPER-1679 and it works fine, +1. I still get a lot of warnings on Visual Studio 2012, though.
        Hide
        Flavio Junqueira added a comment -

        Committed revision 1516123.

        Show
        Flavio Junqueira added a comment - Committed revision 1516123.
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in ZooKeeper-trunk #2030 (See https://builds.apache.org/job/ZooKeeper-trunk/2030/)
        ZOOKEEPER-1400. Allow logging via callback instead of raw FILE pointer (michi via fpj) (fpj: http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1516123)

        • /zookeeper/trunk/CHANGES.txt
        • /zookeeper/trunk/src/c/src/mt_adaptor.c
        • /zookeeper/trunk/src/c/src/zk_log.c
        Show
        Hudson added a comment - SUCCESS: Integrated in ZooKeeper-trunk #2030 (See https://builds.apache.org/job/ZooKeeper-trunk/2030/ ) ZOOKEEPER-1400 . Allow logging via callback instead of raw FILE pointer (michi via fpj) (fpj: http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1516123 ) /zookeeper/trunk/CHANGES.txt /zookeeper/trunk/src/c/src/mt_adaptor.c /zookeeper/trunk/src/c/src/zk_log.c

          People

          • Assignee:
            Michi Mutsuzaki
            Reporter:
            Marshall McMullen
          • Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development