Refactor NIF/libvips logging: avoid logging by default

README.md

@@ -184,7 +184,11 @@ The [libvips reference manual](https://libvips.github.io/libvips/API/current/) h
 
 ### NIF Error Logging
 
-Vix NIF code writes logs to stderr on certain errors. This is disabled by default. To enable logging set `VIX_LOG_ERROR` environment variable to `true`.
+Vix NIF code writes logs to stderr on certain errors. This is disabled by default. To enable logging set `nif_logger_level` to `:error`. Defaults to `:none`
+
+```elixir
+config :vix, nif_logger_level: :error
+```
 
 
 ## Installation

c_src/utils.c

@@ -19,6 +19,24 @@ ERL_NIF_TERM ATOM_NULL_VALUE;
 ERL_NIF_TERM ATOM_UNDEFINED;
 ERL_NIF_TERM ATOM_EAGAIN;
 
+const guint VIX_LOG_LEVEL_NONE = 0;
+const guint VIX_LOG_LEVEL_WARNING = 1;
+const guint VIX_LOG_LEVEL_ERROR = 2;
+
+guint VIX_LOG_LEVEL = VIX_LOG_LEVEL_NONE;
+
+static void libvips_log_callback(char const *log_domain,
+                                 GLogLevelFlags log_level, char const *message,
+                                 void *enable) {
+  enif_fprintf(stderr, "[libvips]: %s\n", message);
+}
+
+static void libvips_log_null_callback(char const *log_domain,
+                                      GLogLevelFlags log_level,
+                                      char const *message, void *enable) {
+  // void
+}
+
 ERL_NIF_TERM make_ok(ErlNifEnv *env, ERL_NIF_TERM term) {
   return enif_make_tuple2(env, ATOM_OK, term);
 }
@@ -90,7 +108,7 @@ static void vix_binary_dtor(ErlNifEnv *env, void *ptr) {
   debug("vix_binary_resource dtor");
 }
 
-int utils_init(ErlNifEnv *env) {
+int utils_init(ErlNifEnv *env, const char *log_level) {
   ATOM_OK = make_atom(env, "ok");
   ATOM_ERROR = make_atom(env, "error");
   ATOM_NIL = make_atom(env, "nil");
@@ -104,6 +122,22 @@ int utils_init(ErlNifEnv *env) {
       env, NULL, "vix_binary_resource", (ErlNifResourceDtor *)vix_binary_dtor,
       ERL_NIF_RT_CREATE | ERL_NIF_RT_TAKEOVER, NULL);
 
+  if (strcmp(log_level, "warning") == 0) {
+    VIX_LOG_LEVEL = VIX_LOG_LEVEL_WARNING;
+  } else if (strcmp(log_level, "error") == 0) {
+    VIX_LOG_LEVEL = VIX_LOG_LEVEL_ERROR;
+  } else {
+    VIX_LOG_LEVEL = VIX_LOG_LEVEL_NONE;
+  }
+
+  if (VIX_LOG_LEVEL == VIX_LOG_LEVEL_WARNING ||
+      VIX_LOG_LEVEL == VIX_LOG_LEVEL_ERROR) {
+    g_log_set_handler("VIPS", G_LOG_LEVEL_WARNING, libvips_log_callback, NULL);
+  } else {
+    g_log_set_handler("VIPS", G_LOG_LEVEL_WARNING, libvips_log_null_callback,
+                      NULL);
+  }
+
   if (!VIX_BINARY_RT) {
     error("Failed to open vix_binary_resource");
     return 1;

c_src/utils.h

@@ -2,6 +2,7 @@
 #define VIX_UTILS_H
 
 #include "erl_nif.h"
+#include <glib-object.h>
 #include <stdbool.h>
 
 /* #define DEBUG */
@@ -24,14 +25,13 @@
 #define elapsed_microseconds() 0
 #endif
 
+extern const guint VIX_LOG_LEVEL_ERROR;
+extern guint VIX_LOG_LEVEL;
+
 #define error(...)                                                             \
   do {                                                                         \
-    char value[10] = {0};                                                      \
-    size_t value_size = 10;                                                    \
-    if (enif_getenv("VIX_LOG_ERROR", value, &value_size) == 0) {               \
-      if (strcmp(value, "true") == 0) {                                        \
-        vix_log(__VA_ARGS__);                                                  \
-      }                                                                        \
+    if (VIX_LOG_LEVEL == VIX_LOG_LEVEL_ERROR) {                                \
+      vix_log(__VA_ARGS__);                                                    \
     }                                                                          \
   } while (0)
 
@@ -115,7 +115,7 @@ bool get_binary(ErlNifEnv *env, ERL_NIF_TERM bin_term, char *str, size_t size);
 
 VixResult vix_result(ERL_NIF_TERM term);
 
-int utils_init(ErlNifEnv *env);
+int utils_init(ErlNifEnv *env, const char *log_level);
 
 int close_fd(int *fd);
 

c_src/vix.c

@@ -21,13 +21,27 @@ static int on_load(ErlNifEnv *env, void **priv, ERL_NIF_TERM load_info) {
     return 1;
   }
 
+  ERL_NIF_TERM logger_level;
+  ERL_NIF_TERM logger_level_key = enif_make_atom(env, "nif_logger_level");
+
+  if (!enif_get_map_value(env, load_info, logger_level_key, &logger_level)) {
+    error("Failed to fetch logger level config from map");
+    return 1;
+  }
+
+  char log_level[20] = {0};
+  if (enif_get_atom(env, logger_level, log_level, 19, ERL_NIF_LATIN1) < 1) {
+    error("Failed to fetch logger level atom value");
+    return 1;
+  }
+
 #ifdef DEBUG
   vips_leak_set(true);
   // when checking for leaks disable cache
   vips_cache_set_max(0);
 #endif
 
-  if (utils_init(env))
+  if (utils_init(env, log_level))
     return 1;
 
   if (nif_g_object_init(env))

lib/vix/nif.ex

@@ -4,7 +4,7 @@ defmodule Vix.Nif do
 
   def load_nifs do
     nif_path = :filename.join(:code.priv_dir(:vix), "vix")
-    :erlang.load_nif(nif_path, 0)
+    :erlang.load_nif(nif_path, load_config())
   end
 
   # GObject
@@ -207,4 +207,20 @@ defmodule Vix.Nif do
 
   def nif_target_new,
     do: :erlang.nif_error(:nif_library_not_loaded)
+
+  @spec load_config :: map
+  defp load_config do
+    %{nif_logger_level: nif_logger_level()}
+  end
+
+  @spec nif_logger_level :: :error | :warning | :none
+  defp nif_logger_level do
+    case Application.get_env(:vix, :nif_logger_level) do
+      level when level in [:error, :warning] ->
+        level
+
+      _ ->
+        :none
+    end
+  end
 end

test/vix/vips/access_test.exs

@@ -95,9 +95,13 @@ defmodule Vix.Vips.AccessTest do
   if range_has_step() do
     test "Access behaviour for Vix.Vips.Image with slicing and mixed positive/negative ranges" do
       {:ok, im} = Image.new_from_file(img_path("puppies.jpg"))
-      assert shape(im[[Map.put(0..-1, :step, 1)]]) == {518, 389, 3}
+      assert shape(im[[Map.put(0..-1//-1, :step, 1)]]) == {518, 389, 3}
+
+      im =
+        im[
+          [Map.put(0..-1//-1, :step, 1), Map.put(1..-1//-1, :step, 1), Map.put(-2..-1, :step, 1)]
+        ]
 
-      im = im[[Map.put(0..-1, :step, 1), Map.put(1..-1, :step, 1), Map.put(-2..-1, :step, 1)]]
       assert shape(im) == {518, 388, 2}
     end
 
@@ -106,7 +110,7 @@ defmodule Vix.Vips.AccessTest do
 
       # Step != 1
       assert_raise ArgumentError, "Range arguments must have a step of 1. Found 0..-3//2", fn ->
-        im[[Map.put(0..-3, :step, 2)]]
+        im[[Map.put(0..-3//-1, :step, 2)]]
       end
     end
 
@@ -115,7 +119,7 @@ defmodule Vix.Vips.AccessTest do
 
       # Index not increasing
       assert_raise ArgumentError, "Range arguments must have a step of 1. Found 0..-3//-1", fn ->
-        im[[0..-3]]
+        im[[0..-3//-1]]
       end
     end
   end

test/vix/vips/image_test.exs

@@ -229,6 +229,7 @@ defmodule Vix.Vips.ImageTest do
     assert stat.size > 0 and stat.type == :regular
   end
 
+  @tag capture_log: true
   test "new_from_enum invalid data write" do
     {:error, "Failed to create image from VipsSource"} = Image.new_from_enum(1..100)
   end