Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[fix][common] Fix issue where logs get truncated when Runtime.halt is used to terminate the process #17589

Merged
merged 4 commits into from
Sep 19, 2022

Conversation

lhotari
Copy link
Member

@lhotari lhotari commented Sep 12, 2022

Fixes #17587

Motivation

Pulsar log file might not contain the last few log lines when the Pulsar process is abnormally terminated with Runtime.halt.

Modifications

  • Add new utility method ShutdownUtil.triggerImmediateForcefulShutdown which calls Log4j2's LogManager.shutdown before terminating the process with Runtime.halt
  • Replace usages of Runtime.halt with ShutdownUtil.triggerImmediateForcefulShutdown in the Pulsar code base

Documentation

  • doc-required
    (Your PR needs to update docs and you will update later)

  • doc-not-needed
    (Please explain why)

  • doc
    (Your PR contains doc changes)

  • doc-complete
    (Docs have been already added)

…gets terminated with Runtime.halt

- call Log4j2's LogManager.shutdown before terminating the process with Runtime.halt
@lhotari lhotari added this to the 2.12.0 milestone Sep 12, 2022
@lhotari lhotari self-assigned this Sep 12, 2022
@github-actions github-actions bot added the doc-not-needed Your PR changes do not impact docs label Sep 12, 2022
Copy link
Contributor

@eolivelli eolivelli left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Copy link
Contributor

@liangyepianzhou liangyepianzhou left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

Copy link
Member

@michaeljmarshall michaeljmarshall left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree with @merlimat's comment. Otherwise, LGTM.

@lhotari
Copy link
Member Author

lhotari commented Sep 16, 2022

I agree with @merlimat's comment. Otherwise, LGTM.

@michaeljmarshall @merlimat I addressed the review feedback. PTAL

Copy link
Member

@michaeljmarshall michaeljmarshall left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@lhotari lhotari merged commit 8b771a6 into apache:master Sep 19, 2022
@gaozhangmin
Copy link
Contributor

@lhotari
With this pr, it looks weird when running pulsar-admin without full params provided.

Main parameters are required ("persistent://tenant/namespace/topic")

Get the internal stats for the topic
Usage: stats-internal [options] persistent://tenant/namespace/topic
  Options:
    -m, --metadata
      Flag to include ledger metadata
      Default: false

2022-09-21T14:18:44,043+0800 [main] WARN  org.apache.pulsar.common.util.ShutdownUtil - Triggering immediate shutdown of current process with status 1
java.lang.Exception: Stacktrace for immediate shutdown
	at org.apache.pulsar.common.util.ShutdownUtil.triggerImmediateForcefulShutdown(ShutdownUtil.java:52) ~[org.apache.pulsar-pulsar-common-2.11.0-SNAPSHOT.jar:2.11.0-SNAPSHOT]
	at org.apache.pulsar.admin.cli.PulsarAdminTool.exit(PulsarAdminTool.java:309) ~[org.apache.pulsar-pulsar-client-tools-2.11.0-SNAPSHOT.jar:2.11.0-SNAPSHOT]
	at org.apache.pulsar.admin.cli.PulsarAdminTool.main(PulsarAdminTool.java:300) ~[org.apache.pulsar-pulsar-client-tools-2.11.0-SNAPSHOT.jar:2.11.0-SNAPSHOT]

Comment on lines +52 to +53
log.warn("Triggering immediate shutdown of current process with status {}", status,
new Exception("Stacktrace for immediate shutdown"));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lhotari recently I found that this warning can be annoying or misleading. Said if we run a command ./bin/pulsar-admin schemas delete so that it gives the usage info. The user will found:

$ ./bin/pulsar-admin schemas delete 


Main parameters are required ("persistent://tenant/namespace/topic")

Delete the latest schema for a topic
Usage: delete [options] persistent://tenant/namespace/topic
  Options:
    -f, --force
      whether to delete schema completely. If true, delete all resources 
      (including metastore and ledger), otherwise only do a mark deletion and 
      not remove any resources indeed
      Default: false

2022-12-09T15:39:22,850+0800 [main] WARN  org.apache.pulsar.common.util.ShutdownUtil - Triggering immediate shutdown of current process with status 1
java.lang.Exception: Stacktrace for immediate shutdown
	at org.apache.pulsar.common.util.ShutdownUtil.triggerImmediateForcefulShutdown(ShutdownUtil.java:52) ~[pulsar-common.jar:2.11.0-SNAPSHOT]
	at org.apache.pulsar.admin.cli.PulsarAdminTool.exit(PulsarAdminTool.java:309) ~[pulsar-client-tools.jar:2.11.0-SNAPSHOT]
	at org.apache.pulsar.admin.cli.PulsarAdminTool.main(PulsarAdminTool.java:300) ~[pulsar-client-tools.jar:2.11.0-SNAPSHOT]

and confused.

Perhaps we remove this logging line or change it to debug level?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/broker doc-not-needed Your PR changes do not impact docs
Projects
None yet
7 participants