diff --git a/docs/Logger.md b/docs/Logger.md new file mode 100644 index 0000000..cf9f4f8 --- /dev/null +++ b/docs/Logger.md @@ -0,0 +1,137 @@ +# Logger Support in Honey Potion + +Honey Potion now supports Elixir's standard `Logger` module for logging in eBPF programs. This provides a more familiar and organized way to handle logging compared to raw `bpf_printk` calls. + +## Current Status + +**Fully Supported**: +- All Logger levels with automatic prefixes +- Simple string messages +- Logger.warn/warning compatibility + +**Planned for Future**: +- Multiple arguments to Logger functions + +## Supported Logger Functions + +The following Logger functions are supported: + +- `Logger.debug/1` and `Logger.debug/2` +- `Logger.info/1` and `Logger.info/2` +- `Logger.warn/1` and `Logger.warn/2` (deprecated, use `warning`) +- `Logger.warning/1` and `Logger.warning/2` +- `Logger.error/1` and `Logger.error/2` + +**Note**: Both `Logger.warn` and `Logger.warning` are supported for compatibility, but `Logger.warning` is preferred as `Logger.warn` is deprecated in newer Elixir versions. + +## Usage Examples + +### Basic Logging + +```elixir +defmodule MyBPF do + def main(ctx) do + Logger.info("Program started") + Logger.debug("Debug information") + Logger.warning("Warning message") # Preferred + Logger.warn("Warning message") # Deprecated but supported + Logger.error("Error occurred") + + Honey.XDP.pass() + end +end +``` + +### Logging with Variables + +```elixir +defmodule MyBPF do + def main(ctx) do + pid = Honey.BpfHelpers.bpf_get_current_pid_tgid() + + Logger.info("Processing PID: #{pid}") + Logger.debug("Current context: #{ctx}") + + if pid > 1000 do + Logger.warning("High PID detected: #{pid}") + end + + Honey.XDP.pass() + end +end +``` + +### Log Levels and Prefixes + +Each Logger function automatically adds an appropriate prefix to the output: + +- `Logger.debug("message")` → `"[DEBUG] message"` +- `Logger.info("message")` → `"[INFO] message"` +- `Logger.warn("message")` → `"[WARN] message"` (deprecated) +- `Logger.warning("message")` → `"[WARN] message"` (preferred) +- `Logger.error("message")` → `"[ERROR] message"` + +### Generated C Code + +The Logger calls are translated to `bpf_printk` calls with prefixes. For example: + +```elixir +Logger.info("Processing packet") +``` + +Becomes: + +```c +bpf_printk("[INFO] Processing packet"); +``` + +### String Interpolation (Future) + +Currently, string interpolation like `"PID: #{pid}"` is not supported. This feature is planned for future releases. For now, use descriptive messages without variables: + +```elixir +# urrent approach +pid = Honey.BpfHelpers.bpf_get_current_pid_tgid() +if pid > 1000 do + Logger.warning("High PID detected") +end + +# Future feature (not yet supported) +Logger.warning("High PID detected: #{pid}") +``` + +## Advantages over bpf_printk + +1. **Familiar Syntax**: Uses Elixir's standard Logger, familiar to Elixir developers +2. **Automatic Prefixes**: Log levels are automatically prefixed to messages +3. **Better Organization**: Different log levels help categorize output +4. **Code Clarity**: Intent is clearer than raw bpf_printk calls + +### Migration from bpf_printk + +Old code: +```elixir +Honey.BpfHelpers.bpf_printk("Debug: PID = %d", pid) +Honey.BpfHelpers.bpf_printk("Error: Invalid packet") +``` + +New code: +```elixir +Logger.debug("PID = #{pid}") +Logger.error("Invalid packet") +``` + +## Limitations + +1. **String Interpolation**: String interpolation (`"PID: #{pid}"`) is partially supported. For now, it's recommended to use simple string messages without interpolation. Full interpolation support is planned for future releases. + +2. **Complex Data Structures**: Only basic types (integers, strings) are supported as arguments. + +3. **Logger Configuration**: eBPF context doesn't support Logger backends, filters, or other configuration options. + +4. **Metadata**: Logger metadata and structured logging features are not available in eBPF context. + + +## Complete Example + +See `examples/logger_example.ex` for a complete working example demonstrating Logger usage in an eBPF program. \ No newline at end of file diff --git a/examples/lib/logger_example.ex b/examples/lib/logger_example.ex new file mode 100644 index 0000000..8dd24cc --- /dev/null +++ b/examples/lib/logger_example.ex @@ -0,0 +1,36 @@ +defmodule Examples.LoggerExample do + @moduledoc """ + Example demonstrating Logger usage in Honey Potion eBPF programs. + + This example shows how to use Elixir's Logger instead of raw bpf_printk calls. + The Logger calls are automatically translated to bpf_printk with appropriate + log level prefixes. + """ + require Logger + + def main(ctx) do + Logger.info("Starting packet processing") + + # Get current process PID + pid = Honey.BpfHelpers.bpf_get_current_pid_tgid() + Logger.debug("Processing packet for current PID #{pid}") + + # Decision logic with different log levels + cond do + pid < 100 -> + Logger.warning("Suspicious low PID detected") + Logger.error("Dropping packet due to security policy") + Honey.XDP.drop() + + pid > 50000 -> + Logger.warning("Very high PID detected") + Logger.info("Allowing packet but flagging for review") + Honey.XDP.pass() + + true -> + Logger.debug("Normal PID range, allowing packet") + Logger.info("Packet processed successfully") + Honey.XDP.pass() + end + end +end \ No newline at end of file diff --git a/lib/honey/compiler/translator.ex b/lib/honey/compiler/translator.ex index 153ab04..9d7f2b6 100644 --- a/lib/honey/compiler/translator.ex +++ b/lib/honey/compiler/translator.ex @@ -1,11 +1,3 @@ -defmodule Honey.Compiler.TranslatorContext do - defstruct [:maps] - - def new(maps) do - %__MODULE__{maps: maps} - end -end - defmodule Honey.Compiler.Translator do @moduledoc """ Translates the elixir AST into eBPF readable C code. @@ -19,7 +11,7 @@ defmodule Honey.Compiler.Translator do import Honey.Utils.Core, only: [gen: 1, var_to_string: 1, is_var: 1] @doc """ - #Translates the main function. + Translates the main function. """ def translate(func_name, ast, sec, license, requires, elixir_maps) do case func_name do @@ -53,14 +45,26 @@ defmodule Honey.Compiler.Translator do """ def to_c(tree, context \\ {}) - # Variables def to_c(var, _context) when is_var(var) do c_var_name = var_to_string(var) c_var_type = TypeSet.get_typeset_from_var_ast(var) TranslatedCode.new("", c_var_name, c_var_type) end - # Blocks + def to_c({:<<>>, _, parts}, context) do + {_format_string, variables} = process_string_interpolation(parts, context) + code_vars = Enum.map(variables, &to_c(&1, context)) + code = Enum.reduce(code_vars, "", fn %{code: code}, so_far -> so_far <> code end) + result_var = unique_helper_var() + + """ + #{code} + char #{result_var}[256]; + """ + |> gen() + |> TranslatedCode.new(result_var, TypeSet.new(ElixirTypes.type_bitstring())) + end + def to_c({:__block__, _, [expr]}, context) do to_c(expr, context) end @@ -70,7 +74,6 @@ defmodule Honey.Compiler.Translator do %TranslatedCode{block | code: "\n" <> block.code <> "\n"} end - # Erlang functions def to_c({{:., _, [:erlang, function]}, _, [constant]}, _context) when is_integer(constant) do case function do @@ -137,6 +140,17 @@ defmodule Honey.Compiler.Translator do |> TranslatedCode.new(c_var.return_var_name, c_var.return_var_type) end + # Logger support + def to_c({{:., _, [Logger, function]}, _, params}, context) do + case function do + level when level in [:debug, :info, :warn, :warning, :error] -> + translate_logger_call(level, params, context) + + _ -> + raise "Logger.#{function} not supported in eBPF context. Supported levels: debug, info, warn, warning, error" + end + end + # C libraries def to_c({{:., _, [Honey.BpfHelpers, function]}, _, params}, context) do case function do @@ -784,6 +798,125 @@ defmodule Honey.Compiler.Translator do |> TranslatedCode.new(return_rhs.return_var_name) end + defp translate_logger_call(level, params, context) do + case params do + [message | args] when is_bitstring(message) -> + level_prefix = get_log_level_prefix(level) + prefixed_message = "#{level_prefix} #{message}" + translate_bpf_printk_with_message(prefixed_message, args, context) + + [{:<<>>, _, parts} | _args] -> + level_prefix = get_log_level_prefix(level) + {format_string, variables} = process_string_interpolation(parts, context) + prefixed_format = "#{level_prefix} #{format_string}" + translate_bpf_printk_with_message(prefixed_format, variables, context) + + [message | _args] -> + level_prefix = get_log_level_prefix(level) + message_translated = to_c(message, context) + + case TypeSet.is_string?(message_translated.return_var_type) do + true -> + result_var = unique_helper_var() + + """ + #{message_translated.code} + bpf_printk(\"#{level_prefix} %s\", #{message_translated.return_var_name}); + int #{result_var} = 0; + """ + |> gen() + |> TranslatedCode.new(result_var, TypeSet.new(ElixirTypes.type_integer())) + + false -> + result_var = unique_helper_var() + + """ + #{message_translated.code} + bpf_printk(\"#{level_prefix} (dynamic message)\"); + int #{result_var} = 0; + """ + |> gen() + |> TranslatedCode.new(result_var, TypeSet.new(ElixirTypes.type_integer())) + end + + [] -> + level_prefix = get_log_level_prefix(level) + result_var = unique_helper_var() + + """ + bpf_printk(\"#{level_prefix}\"); + int #{result_var} = 0; + """ + |> gen() + |> TranslatedCode.new(result_var, TypeSet.new(ElixirTypes.type_integer())) + end + end + + defp get_log_level_prefix(level) do + case level do + :debug -> "[DEBUG]" + :info -> "[INFO]" + :warn -> "[WARN]" + :warning -> "[WARN]" + :error -> "[ERROR]" + _ -> "[LOG]" + end + end + + defp translate_bpf_printk_with_message(string, other_params, context) do + if !is_bitstring(string) do + raise "Logger message must be a string. Received: #{inspect(string)}" + end + + string = String.replace(string, "\n", "\\n") + code_vars = Enum.map(other_params, &to_c(&1, context)) + code = Enum.reduce(code_vars, "", fn %{code: code}, so_far -> so_far <> code end) + + vars = + Enum.reduce(code_vars, "", fn translated, so_far -> + if TypeSet.is_generic?(translated.return_var_type) do + so_far <> ", " <> translated.return_var_name <> ".value.integer" + else + if TypeSet.is_integer?(translated.return_var_type) do + so_far <> ", " <> translated.return_var_name + else + so_far <> ", " <> translated.return_var_name <> ".value.integer" + end + end + end) + + result_var = unique_helper_var() + + """ + #{code} + bpf_printk(\"#{string}\"#{vars}); + int #{result_var} = 0; + """ + |> gen() + |> TranslatedCode.new(result_var, TypeSet.new(ElixirTypes.type_integer())) + end + + defp process_string_interpolation(parts, _context) do + {format_string, variables} = + Enum.reduce(parts, {"", []}, fn part, {str_acc, vars_acc} -> + case part do + string when is_binary(string) -> + {str_acc <> string, vars_acc} + + {:"::", _, [{{:., _, [Kernel, :to_string]}, _, [expr]}, _type]} -> + {str_acc <> "%d", vars_acc ++ [expr]} + + {variable, _, _} when is_atom(variable) -> + {str_acc <> "%d", vars_acc ++ [part]} + + _other -> + {str_acc <> "%d", vars_acc ++ [part]} + end + end) + + {format_string, variables} + end + defp allocate_tuple_in_heap([], index) do code = """ *heap_index += #{index}; diff --git a/lib/honey/compiler/translator_context.ex b/lib/honey/compiler/translator_context.ex new file mode 100644 index 0000000..4fe58ae --- /dev/null +++ b/lib/honey/compiler/translator_context.ex @@ -0,0 +1,7 @@ +defmodule Honey.Compiler.TranslatorContext do + defstruct [:maps] + + def new(maps) do + %__MODULE__{maps: maps} + end +end \ No newline at end of file diff --git a/mix.exs b/mix.exs index 60f5318..6da5e46 100644 --- a/mix.exs +++ b/mix.exs @@ -38,7 +38,7 @@ defmodule Honey.MixProject do [ # The Honey.Mix.Tasks.CompileBPF.run function currently has no use. It has been left as a reference of # where code can be added for it to be executed before the compilation step of Elixir. - #compile: ["compile", &Honey.Mix.Tasks.CompileBPF.run/1] + # compile: ["compile", &Honey.Mix.Tasks.CompileBPF.run/1] ] end diff --git a/test/logger_interpolation_simple_test.exs b/test/logger_interpolation_simple_test.exs new file mode 100644 index 0000000..1d6bf04 --- /dev/null +++ b/test/logger_interpolation_simple_test.exs @@ -0,0 +1,21 @@ +defmodule LoggerInterpolationSimpleTest do + use ExUnit.Case + alias Honey.Compiler.Translator + + test "string interpolation through to_c function" do + interpolation_ast = {:<<>>, [], ["PID: ", {:pid, [], nil}]} + + result = Translator.to_c(interpolation_ast, {}) + + assert is_binary(result.code) + assert String.contains?(result.code, "char") + end + + test "simple string without interpolation" do + string_ast = "Hello World" + + result = Translator.to_c(string_ast, {}) + + assert is_binary(result.code) + end +end diff --git a/test/logger_interpolation_working_test.exs b/test/logger_interpolation_working_test.exs new file mode 100644 index 0000000..1b560bd --- /dev/null +++ b/test/logger_interpolation_working_test.exs @@ -0,0 +1,36 @@ +defmodule LoggerInterpolationTest do + use ExUnit.Case + alias Honey.Compiler.Translator + + test "Logger.info with string interpolation" do + ast = {{:., [], [Logger, :info]}, [], [{:<<>>, [], ["PID: ", {:pid, [], nil}]}]} + + result = Translator.to_c(ast, {}) + + assert String.contains?(result.code, "bpf_printk") + assert String.contains?(result.code, "[INFO] PID: %d") + assert String.contains?(result.code, "pid") + end + + test "Logger.debug with multiple interpolations" do + ast = + {{:., [], [Logger, :debug]}, [], + [{:<<>>, [], ["User ", {:user, [], nil}, " has PID ", {:pid, [], nil}]}]} + + result = Translator.to_c(ast, {}) + + assert String.contains?(result.code, "bpf_printk") + assert String.contains?(result.code, "[DEBUG] User %d has PID %d") + assert String.contains?(result.code, "user") + assert String.contains?(result.code, "pid") + end + + test "Logger.error without interpolation still works" do + ast = {{:., [], [Logger, :error]}, [], ["Simple message"]} + + result = Translator.to_c(ast, {}) + + assert String.contains?(result.code, "bpf_printk") + assert String.contains?(result.code, "[ERROR] Simple message") + end +end diff --git a/test/logger_output_test.exs b/test/logger_output_test.exs new file mode 100644 index 0000000..579672f --- /dev/null +++ b/test/logger_output_test.exs @@ -0,0 +1,46 @@ +defmodule TestLoggerOutput do + use ExUnit.Case + alias Honey.Compiler.Translator + + test "complete Logger example generates correct C code" do + ast = + {:__block__, [], + [ + {{:., [], [Logger, :info]}, [], ["Starting program"]}, + {:=, [], + [ + {:pid, [types: Honey.TypeSet.new(Honey.Analysis.ElixirTypes.type_integer())], nil}, + {{:., [], [Honey.BpfHelpers, :bpf_get_current_pid_tgid]}, [], []} + ]}, + {{:., [], [Logger, :debug]}, [], + [ + "PID: %d", + {:pid, [types: Honey.TypeSet.new(Honey.Analysis.ElixirTypes.type_integer())], nil} + ]}, + {{:., [], [Logger, :warn]}, [], ["Warning message (deprecated)"]}, + {{:., [], [Logger, :warning]}, [], ["Warning message (preferred)"]}, + {{:., [], [Logger, :error]}, [], ["Error occurred"]} + ]} + + context = Honey.Compiler.TranslatorContext.new([]) + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[INFO] Starting program") + assert String.contains?(result.code, "[DEBUG] PID: %d") + assert String.contains?(result.code, "[WARN] Warning message (deprecated)") + assert String.contains?(result.code, "[WARN] Warning message (preferred)") + assert String.contains?(result.code, "[ERROR] Error occurred") + + bpf_printk_count = + result.code + |> String.split("bpf_printk") + |> length() + |> Kernel.-(1) + + assert bpf_printk_count == 5 + + IO.puts("\n=== Generated C Code ===") + IO.puts(result.code) + IO.puts("========================\n") + end +end diff --git a/test/logger_support_test.exs b/test/logger_support_test.exs new file mode 100644 index 0000000..8606684 --- /dev/null +++ b/test/logger_support_test.exs @@ -0,0 +1,101 @@ +defmodule LoggerSupportTest do + use ExUnit.Case + alias Honey.Compiler.Translator + + describe "Logger support" do + test "translates Logger.info with string message" do + ast = {{:., [], [Logger, :info]}, [], ["Hello world"]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[INFO] Hello world") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.debug with string message and variables" do + pid_ast = {:pid, [types: Honey.TypeSet.new(Honey.Analysis.ElixirTypes.type_integer())], nil} + ast = {{:., [], [Logger, :debug]}, [], ["PID: %d", pid_ast]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[DEBUG] PID: %d") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.warn with string message" do + ast = {{:., [], [Logger, :warn]}, [], ["Warning message"]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[WARN] Warning message") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.warning with string message" do + ast = {{:., [], [Logger, :warning]}, [], ["Warning message"]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[WARN] Warning message") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.warning with variables" do + pid_ast = {:pid, [types: Honey.TypeSet.new(Honey.Analysis.ElixirTypes.type_integer())], nil} + ast = {{:., [], [Logger, :warning]}, [], ["PID too high: %d", pid_ast]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[WARN] PID too high: %d") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.error with string message" do + ast = {{:., [], [Logger, :error]}, [], ["Error occurred"]} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[ERROR] Error occurred") + assert String.contains?(result.code, "bpf_printk") + end + + test "translates Logger.info without message" do + ast = {{:., [], [Logger, :info]}, [], []} + context = Honey.Compiler.TranslatorContext.new([]) + + result = Translator.to_c(ast, context) + + assert String.contains?(result.code, "[INFO]") + assert String.contains?(result.code, "bpf_printk") + end + + test "raises error for unsupported Logger function" do + ast = {{:., [], [Logger, :unsupported]}, [], ["message"]} + context = Honey.Compiler.TranslatorContext.new([]) + + assert_raise RuntimeError, ~r/Logger.unsupported not supported/, fn -> + Translator.to_c(ast, context) + end + end + + test "both warn and warning produce the same output" do + context = Honey.Compiler.TranslatorContext.new([]) + + warn_ast = {{:., [], [Logger, :warn]}, [], ["Test message"]} + warning_ast = {{:., [], [Logger, :warning]}, [], ["Test message"]} + + warn_result = Translator.to_c(warn_ast, context) + warning_result = Translator.to_c(warning_ast, context) + + # Both should generate the same prefix + assert String.contains?(warn_result.code, "[WARN] Test message") + assert String.contains?(warning_result.code, "[WARN] Test message") + end + end +end