i2p: fix and improve logs #29833

pull brunoerg wants to merge 2 commits into bitcoin:master from brunoerg:2024-04-i2p-log changing 2 files +13 −23
  1. brunoerg commented at 7:55 am on April 9, 2024: contributor

    This PR improves and fixes i2p logs (joint work with vasild).

    • It replaces LogPrint to LogPrintLevel so we can log according to the severity.
    • Fix log when interruption happens during Accept. Before this PR, when an interruption happens, it just logs “Error accepting:”, no reason is logged as it does for other situations. This PR changes it to log “Accept interrupted”.
    • Log errors according to the severity. Stuff like creating SAM session, destroying SAM session, etc… are logged as ‘debug’.
  2. DrahtBot commented at 7:55 am on April 9, 2024: contributor

    The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

    Code Coverage

    For detailed information about the code coverage, see the test coverage report.

    Reviews

    See the guideline for information on the review process.

    Type Reviewers
    ACK marcofleon, vasild, achow101
    Concept ACK jonatack
    Stale ACK kevkevinpal, laanwj

    If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

    Conflicts

    Reviewers, this pull request conflicts with the following ones:

    • #30338 (RFC: Instanced logs by theuni)
    • #29641 (scripted-diff: Use LogInfo/LogDebug over LogPrintf/LogPrint by maflcko)

    If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

  3. laanwj added the label P2P on Apr 9, 2024
  4. laanwj requested review from laanwj on Apr 9, 2024
  5. kevkevinpal commented at 2:17 am on April 10, 2024: contributor
    lgtm ACK 64d3296
  6. in src/i2p.cpp:206 in 64d3296489 outdated
    201@@ -202,7 +202,11 @@ bool Session::Accept(Connection& conn)
    202         return true;
    203     }
    204 
    205-    Log("Error accepting%s: %s", disconnect ? " (will close the session)" : "", errmsg);
    206+    if (m_interrupt) {
    207+        LogPrintLevel(BCLog::I2P, BCLog::Level::Debug, "Accept interrupted\n");
    


    laanwj commented at 7:13 am on April 11, 2024:
    maybe “Accept was interrupted”

    brunoerg commented at 12:46 pm on April 11, 2024:
    Sounds good, I will change it.
  7. brunoerg force-pushed on Apr 12, 2024
  8. brunoerg commented at 9:22 am on April 12, 2024: contributor
    Force-pushed addressing #29833 (review). Thanks, @laanwj.
  9. laanwj commented at 9:31 am on April 12, 2024: member
    Thanks! Code review ACK 9fa50338c115f0286637142fd887b212fddfb27d
  10. DrahtBot requested review from kevkevinpal on Apr 12, 2024
  11. brunoerg commented at 4:44 pm on April 12, 2024: contributor
    CI failure is unrelated to these changes.
  12. brunoerg force-pushed on Apr 26, 2024
  13. brunoerg commented at 1:38 pm on April 26, 2024: contributor
    Rebased to re-run CI.
  14. laanwj commented at 11:18 am on April 27, 2024: member

    Rebased to re-run CI.

    Better to ask someone in the IRC channel to re-run the CI, as that won’t invalidate ACKs 😄

    re-ACK 469e4834bad295f6d9fbf8048a8db23aa758bac9

  15. vasild approved
  16. vasild commented at 11:40 am on May 10, 2024: contributor
    ACK 469e4834bad295f6d9fbf8048a8db23aa758bac9
  17. jonatack commented at 10:07 pm on May 10, 2024: contributor
    Concept/approach ACK, this is the same or very similar to the changes in fc0a50e (#25203) and 43315a0 (#25203) from two years ago, in case you’d like to compare/check against them.
  18. DrahtBot requested review from jonatack on May 10, 2024
  19. in src/i2p.cpp:452 in 469e4834ba outdated
    448@@ -451,7 +449,7 @@ void Session::CreateIfNotCreatedAlready()
    449     m_session_id = session_id;
    450     m_control_sock = std::move(sock);
    451 
    452-    Log("%s SAM session %s created, my address=%s",
    453+    LogPrintLevel(BCLog::I2P, BCLog::Level::Debug, "%s SAM session %s created, my address=%s\n",
    


    jonatack commented at 8:46 pm on May 13, 2024:

    Commit 48dc2ff8e7819e810d2436219268f220b39c14f

    in fc0a50e92aaaf3b049fcfcd0873dadc7150cfecf I made this one info (default) level here. It seems important, when the user turns i2p logging on, to see if the session was successfully created. I look for this logging when launching a node or restarting the I2P router.


    vasild commented at 9:35 am on May 23, 2024:
    Makes sense (also for session destroy).

    vasild commented at 9:42 am on May 23, 2024:
    Note that for transient I2P sessions (when -i2pacceptincoming=0) this would be printed for every I2P peer connect and disconnect even if I2P logging is switched off.

    brunoerg commented at 4:33 pm on May 23, 2024:
    I agree. I will address it.

    brunoerg commented at 7:02 pm on May 23, 2024:
    done

    jonatack commented at 9:16 pm on May 23, 2024:

    Note that for transient I2P sessions (when -i2pacceptincoming=0) this would be printed for every I2P peer connect and disconnect even if I2P logging is switched off.

    Good point. At the same time, I2P connections are intended to be long-running ones, as the tunnels are one-way and more time/resource intensive to launch than other networks. When i2pacceptincoming is off (which we discourage in doc/i2p.md), I’m unsure whether it’s best for this to remain verbose, or to set it as a less-frequent log level (debug) in that case.

  20. DrahtBot requested review from jonatack on May 13, 2024
  21. in src/i2p.cpp:485 in 469e4834ba outdated
    479@@ -482,9 +480,9 @@ void Session::Disconnect()
    480 {
    481     if (m_control_sock) {
    482         if (m_session_id.empty()) {
    483-            Log("Destroying incomplete SAM session");
    484+            LogPrintLevel(BCLog::I2P, BCLog::Level::Debug, "Destroying incomplete SAM session\n");
    485         } else {
    486-            Log("Destroying SAM session %s", m_session_id);
    487+            LogPrintLevel(BCLog::I2P, BCLog::Level::Debug, "Destroying SAM session %s\n", m_session_id);
    


    jonatack commented at 8:47 pm on May 13, 2024:
    same comment here as https://github.com/bitcoin/bitcoin/pull/29833/files#r1599061492, it seems important to log a destroyed session by default when the user turns i2p logging on
  22. DrahtBot requested review from jonatack on May 13, 2024
  23. in src/i2p.cpp:483 in 469e4834ba outdated
    479@@ -482,9 +480,9 @@ void Session::Disconnect()
    480 {
    481     if (m_control_sock) {
    482         if (m_session_id.empty()) {
    483-            Log("Destroying incomplete SAM session");
    484+            LogPrintLevel(BCLog::I2P, BCLog::Level::Debug, "Destroying incomplete SAM session\n");
    


    jonatack commented at 8:48 pm on May 13, 2024:

    brunoerg commented at 7:03 pm on May 23, 2024:
    done
  24. DrahtBot requested review from jonatack on May 13, 2024
  25. DrahtBot requested review from jonatack on May 13, 2024
  26. jonatack commented at 9:04 pm on May 13, 2024: contributor

    (reposting using the “review changes” button to appease the bot, it sent me several “request review” notifications in the last ten minutes :)

    ACK modulo comments above. If the third commit is re-changing lines that are already changed in the first commit, would suggest combining them.

  27. maflcko commented at 9:59 am on May 23, 2024: member

    (reposting using the “review changes” button to appease the bot, it sent me several “request review” notifications in the last ten minutes :)

    Not sure why that would happen. The bot should not react on new review comments after someone else’s A C K. (c.f. https://github.com/maflcko/DrahtBot/blob/main/webhook_features/src/features/summary_comment.rs#L308) Looking at other pull requests, this seems to be working correctly, so my guess is that this is another GitHub metatdata corruption bug, which are common?

  28. brunoerg force-pushed on May 23, 2024
  29. brunoerg commented at 7:03 pm on May 23, 2024: contributor
    Force-pushed addressing #29833 (review).
  30. i2p: log errors properly according to their severity
    Co-authored-by: Vasil Dimov <vd@FreeBSD.org>
    3d3a83fab2
  31. i2p: fix log when an interruption happens during `Accept`
    Before, interruption was printed as an error. Also,
    it did not log the reason when an interruption happened,
    e.g. "Error accepting:".
    
    Co-authored-by: Vasil Dimov <vd@FreeBSD.org>
    7d3662fbe3
  32. in src/i2p.cpp:205 in 0c6384865b outdated
    201@@ -202,7 +202,11 @@ bool Session::Accept(Connection& conn)
    202         return true;
    203     }
    204 
    205-    Log("Error accepting%s: %s", disconnect ? " (will close the session)" : "", errmsg);
    206+    if (m_interrupt) {
    


    marcofleon commented at 1:49 pm on June 12, 2024:
    Should this not be *m_interrupt?

    brunoerg commented at 7:41 pm on June 12, 2024:
    Yes, you’re right. Since i2p is CThreadInterrupt*. Thanks.

    vasild commented at 8:13 am on June 21, 2024:

    Good catch! The implicit cast to bool of CThreadInterrupt makes it easy to get such mistakes if the variable is a pointer to CThreadInterrupt or std::optional<CThreadInterrupt>. If CThreadInterrupt had an explicit method like IsInterrupted() then it would be more clear to call that one, but unfortunately it does not have such a method.

    To be explicit we can do if (m_interrupt->operator bool()) { :laughing: :robot: :rofl:

    Or, more seriously, because m_interrupt can never be nullptr, change it to a reference.

  33. brunoerg force-pushed on Jun 12, 2024
  34. brunoerg commented at 7:41 pm on June 12, 2024: contributor
    Force-pushed addressing #29833 (review)
  35. marcofleon commented at 10:27 am on June 13, 2024: contributor
    ACK 7d3662fbe35032178c5a5e27e73c592268f6e41b.
  36. DrahtBot requested review from laanwj on Jun 13, 2024
  37. DrahtBot requested review from vasild on Jun 13, 2024
  38. DrahtBot requested review from maflcko on Jun 13, 2024
  39. vasild approved
  40. vasild commented at 7:59 am on June 21, 2024: contributor
    ACK 7d3662fbe35032178c5a5e27e73c592268f6e41b
  41. maflcko removed review request from maflcko on Jun 21, 2024
  42. maflcko removed review request from kevkevinpal on Jun 21, 2024
  43. DrahtBot requested review from kevkevinpal on Jun 21, 2024
  44. achow101 commented at 7:19 pm on June 26, 2024: member
    ACK 7d3662fbe35032178c5a5e27e73c592268f6e41b
  45. achow101 merged this on Jun 26, 2024
  46. achow101 closed this on Jun 26, 2024


github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-12-21 15:12 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me