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

Add support for strftime() builtin #1387

Merged
merged 3 commits into from
Jul 16, 2020
Merged

Conversation

suyuee
Copy link
Contributor

@suyuee suyuee commented Jun 16, 2020

This PR introduces a new builtin function strftime. This function makes it possible to print the current time with printf:

bpftrace -e 'i:s:1 { printf("%s\n", strftime("%H:%M:%S", nsecs)); }'

Although time can print current time on its own, printing timestamp with printf can produce more concise and more readable output. Resolves #1337 .

Checklist
  • Language changes are updated in docs/reference_guide.md
  • User-visible and non-trivial changes updated in CHANGELOG.md

@suyuee suyuee changed the title Add semantic analysis support for 2-arg time() builtin Add support for 2-arg time() builtin Jun 16, 2020
src/ast/semantic_analyser.cpp Outdated Show resolved Hide resolved
src/ast/semantic_analyser.cpp Outdated Show resolved Hide resolved
src/ast/semantic_analyser.cpp Outdated Show resolved Hide resolved
src/ast/semantic_analyser.cpp Outdated Show resolved Hide resolved
tests/semantic_analyser.cpp Outdated Show resolved Hide resolved
@brendangregg
Copy link
Contributor

What is this?

TEST(semantic_analyser, call_timestamp_warnings)
{
  test_for_warning("kprobe:f { time(); }", "deprecated");
  test_for_warning("kprobe:f { time(\"%M:%S\"); }", "deprecated");
  test_for_warning("kprobe:f { time(\"%M:%S\", nsecs); }", "deprecated", true);
}

Does this deprecate/break the old behavior? I don't see a compelling reason why we should. It's in ~10k printed copies of the BPF book that we cannot update, so no.

I also saw this (there's no reference docs, so it's not clear what you're doing):

          warning("Using time() to implicitly print time is deprecated. Print "
                  "the returned value instead.",

I called it time() because it was not strftime(). This sounds like you're turning it into strftime(). If you want strftime(), add a new thing called strftime() and leave time() alone.

@suyuee suyuee changed the title Add support for 2-arg time() builtin Add support for strftime() builtin Jun 17, 2020
@suyuee suyuee changed the title Add support for strftime() builtin Add support for strftime() builtin Jun 17, 2020
@suyuee suyuee changed the title Add support for strftime() builtin Add support for strftime() builtin Jun 17, 2020
@brendangregg
Copy link
Contributor

Why create a new printf() format character? Why not "%s"?

See printf.cpp: we convert a lot of types to String when printed.

    if (arg_type == Type::ksym || arg_type == Type::usym || arg_type == Type::probe ||
        arg_type == Type::username || arg_type == Type::kstack || arg_type == Type::ustack ||
        arg_type == Type::inet)
      arg_type = Type::string; // Symbols should be printed as strings

@suyuee
Copy link
Contributor Author

suyuee commented Jun 22, 2020

@brendangregg The reason we hesitated to use "%s" was that we were afraid it would send a message to user that strftime() returns a string and might cause some confusion. It's tempting to link "strftime()" with "string()". For example, people may end up using 'strncmp()` on the return value, which doesn't make sense.

Using "%ts" doesn't have that issue. But the problem with it is that creating a new specifier for the old friend printf() is not actually user-friendly either. It's hard to remember and lacks simplicity.

I think the async nature of strftime() makes it hard to make perfect decisions for users, since people might not always be aware that BPF programs come with many limitations.

@brendangregg
Copy link
Contributor

A) If it's called strftime() then people will use it with %s. (Where did %ts come from anyway? POSIX? I'm not familiar with it.)

B) I don't really see the use case other than with printf().

C) That ship has sailed anyway: we have things like kstack() and username() that use %s, but you can't use with strcmp().

It's a tracing language, not an application language. It only needs to support enough for common case tools -- anything more complex can be deferred to BCC. The existence of BCC allows us to keep bpftrace simple.

@suyuee suyuee force-pushed the enhance_time_call branch 3 times, most recently from 86fb9ff to ea2bb2d Compare June 29, 2020 23:06
@suyuee suyuee marked this pull request as ready for review June 30, 2020 01:17
@fbs fbs added this to the 0.11.0 milestone Jul 2, 2020
src/types.cpp Outdated Show resolved Hide resolved
src/types.h Outdated Show resolved Hide resolved
docs/reference_guide.md Outdated Show resolved Hide resolved
src/ast/async_event_types.h Outdated Show resolved Hide resolved
src/ast/codegen_llvm.cpp Show resolved Hide resolved
src/ast/codegen_llvm.cpp Outdated Show resolved Hide resolved
docs/reference_guide.md Show resolved Hide resolved
src/bpftrace.cpp Outdated Show resolved Hide resolved
@suyuee suyuee marked this pull request as draft July 3, 2020 05:04
@suyuee suyuee force-pushed the enhance_time_call branch 5 times, most recently from 1bb53e9 to c29983b Compare July 7, 2020 16:05
@suyuee suyuee marked this pull request as ready for review July 7, 2020 16:32
@suyuee
Copy link
Contributor Author

suyuee commented Jul 7, 2020

Ready for review.

Copy link
Member

@fbs fbs left a comment

Choose a reason for hiding this comment

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

Some small things but looks good overal :)

@@ -273,7 +273,7 @@ Value *IRBuilderBPF::CreateMapLookupElem(Value *ctx,
CreateCondBr(condition, lookup_success_block, lookup_failure_block);

SetInsertPoint(lookup_success_block);
if (type.IsAggregate())
if (type.IsAggregate() || type.IsTimestampTy())
Copy link
Member

Choose a reason for hiding this comment

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

I think we should either put timestamp in IsAggregate or find a new name to describe them both (and all future async events which should be handled like this).

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I'd agree. I think IsCompound could be a nice name here since C++ seems to use similar term: std::is_compound and it includes array, tuple, class and so on (Type::timestamp seems like a class type to me). Btw there could be some other options like IsCollectionTy, IsComposite and IsCombined though I'm not sure if there are as good.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Discussed with @danobi and thought that it might be good to add a helper function instead.

@@ -1673,6 +1686,52 @@ std::string BPFtrace::resolve_uid(uintptr_t addr) const
return username;
}

std::string BPFtrace::resolve_timestamp(uint32_t strftime_id,
Copy link
Member

Choose a reason for hiding this comment

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

Looks like this currently gives us 1s accuracy right? I was hoping for to get closer to 100us but that should probably go in a follow up ticket.

Copy link
Contributor Author

@suyuee suyuee Jul 8, 2020

Choose a reason for hiding this comment

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

Yes. If we want someting better, we may have to choose something more accurate than btime. clock_gettime(CLOCK_REALTIME) might help though I'm not so sure if that's what we want; and if we use it, it wouldn't make sense to use nsecs as the second argument of strftime since it means 'nsecs since boot time'.

src/bpftrace.cpp Show resolved Hide resolved
src/ast/async_event_types.h Show resolved Hide resolved
docs/reference_guide.md Outdated Show resolved Hide resolved
docs/reference_guide.md Outdated Show resolved Hide resolved
@suyuee suyuee force-pushed the enhance_time_call branch 2 times, most recently from e9f83b2 to 84adc3d Compare July 8, 2020 23:51
@suyuee suyuee force-pushed the enhance_time_call branch 2 times, most recently from 8d2b3d1 to 5800d4b Compare July 9, 2020 00:15
docs/reference_guide.md Outdated Show resolved Hide resolved
src/ast/codegen_llvm.cpp Outdated Show resolved Hide resolved
docs/reference_guide.md Show resolved Hide resolved
@fbs fbs modified the milestones: 0.11.0, 0.12.0 Jul 15, 2020
CHANGELOG.md Outdated Show resolved Hide resolved
This introduces a new builtin function `strftime`. This function makes it
possible to print the current time with `printf`:

``` bpftrace -e 'i:s:1 { printf("%s\n", strftime("%H:%M:%S", nsecs)); }' ```

Although `time` can print current time on its own, printing timestamp with
`printf` can produce more concise and more readable output. Resolves bpftrace#1337 .
@fbs fbs merged commit 5bb653c into bpftrace:master Jul 16, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add a way for users to get current time
4 participants