print tracebacks and line numbers for Lua runtime errors

CHANGELOG.md

@@ -18,6 +18,7 @@
       - CHANGED: Make edge metrics strongly typed [#6420](https://github.com/Project-OSRM/osrm-backend/pull/6420)
       - FIXED: Typo in file name src/util/timed_historgram.cpp -> src/util/timed_histogram.cpp [#6428](https://github.com/Project-OSRM/osrm-backend/issues/6428)
       - CHANGED: Replace boost::string_ref with std::string_view [#6433](https://github.com/Project-OSRM/osrm-backend/pull/6433)
+      - ADDED: Print tracebacks for Lua runtime errors [#6564](https://github.com/Project-OSRM/osrm-backend/pull/6564)
     - Routing:
       - FIXED: Fix adding traffic signal penalties during compression [#6419](https://github.com/Project-OSRM/osrm-backend/pull/6419)
 # 5.27.1

include/extractor/scripting_environment_lua.hpp

@@ -41,10 +41,10 @@ struct LuaScriptingContext final
     bool has_way_function = false;
     bool has_segment_function = false;
 
-    sol::function turn_function;
-    sol::function way_function;
-    sol::function node_function;
-    sol::function segment_function;
+    sol::protected_function turn_function;
+    sol::protected_function way_function;
+    sol::protected_function node_function;
+    sol::protected_function segment_function;
 
     int api_version = 4;
     sol::table profile_table;

scripts/ci/leaksanitizer.conf

@@ -6,3 +6,12 @@
 #     #1 0x7f7ae595d13e  (/usr/lib/x86_64-linux-gnu/libtbb.so.2+0x2213e)
 
 leak:libtbb.so
+
+# The extract-tests leak some memory in the tests to confirm that
+# lua errors print tracebacks.
+# This appears to be because when these tests throw exceptions, the
+# osmium objects being processed are not freed. In production this doesn't
+# matter, as the exceptions bring down the entire osrm-extract process. In the
+# tests, we catch the error to make sure it occurs, which is why the
+# leaksanitizer flags it.
+leak:extract-tests

src/extractor/scripting_environment_lua.cpp

@@ -91,6 +91,19 @@ struct to_lua_object : public boost::static_visitor<sol::object>
 };
 } // namespace
 
+// Handle a lua error thrown in a protected function by printing the traceback and bubbling
+// exception up to caller. Lua errors are generally unrecoverable, so this exception should not be
+// caught but instead should terminate the process. The point of having this error handler rather
+// than just using unprotected Lua functions which terminate the process automatically is that this
+// function provides more useful error messages including Lua tracebacks and line numbers.
+void handle_lua_error(sol::protected_function_result &luares)
+{
+    sol::error luaerr = luares;
+    std::string msg = luaerr.what();
+    std::cerr << msg << std::endl;
+    throw util::exception("Lua error (see stderr for traceback)");
+}
+
 Sol2ScriptingEnvironment::Sol2ScriptingEnvironment(
     const std::string &file_name,
     const std::vector<boost::filesystem::path> &location_dependent_data_paths)
@@ -550,10 +563,16 @@ void Sol2ScriptingEnvironment::InitContext(LuaScriptingContext &context)
                                std::numeric_limits<TurnPenalty::value_type>::max());
 
         // call initialize function
-        sol::function setup_function = function_table.value()["setup"];
+        sol::protected_function setup_function = function_table.value()["setup"];
         if (!setup_function.valid())
             throw util::exception("Profile must have an setup() function.");
-        sol::optional<sol::table> profile_table = setup_function();
+
+        auto setup_result = setup_function();
+
+        if (!setup_result.valid())
+            handle_lua_error(setup_result);
+
+        sol::optional<sol::table> profile_table = setup_result;
         if (profile_table == sol::nullopt)
             throw util::exception("Profile setup() must return a table.");
         else
@@ -1123,7 +1142,9 @@ void Sol2ScriptingEnvironment::ProcessTurn(ExtractionTurn &turn)
     case 2:
         if (context.has_turn_penalty_function)
         {
-            context.turn_function(context.profile_table, std::ref(turn));
+            auto luares = context.turn_function(context.profile_table, std::ref(turn));
+            if (!luares.valid())
+                handle_lua_error(luares);
 
             // Turn weight falls back to the duration value in deciseconds
             // or uses the extracted unit-less weight value
@@ -1138,7 +1159,9 @@ void Sol2ScriptingEnvironment::ProcessTurn(ExtractionTurn &turn)
     case 1:
         if (context.has_turn_penalty_function)
         {
-            context.turn_function(std::ref(turn));
+            auto luares = context.turn_function(std::ref(turn));
+            if (!luares.valid())
+                handle_lua_error(luares);
 
             // Turn weight falls back to the duration value in deciseconds
             // or uses the extracted unit-less weight value
@@ -1184,24 +1207,28 @@ void Sol2ScriptingEnvironment::ProcessSegment(ExtractionSegment &segment)
 
     if (context.has_segment_function)
     {
+        sol::protected_function_result luares;
         switch (context.api_version)
         {
         case 4:
         case 3:
         case 2:
-            context.segment_function(context.profile_table, std::ref(segment));
+            luares = context.segment_function(context.profile_table, std::ref(segment));
             break;
         case 1:
-            context.segment_function(std::ref(segment));
+            luares = context.segment_function(std::ref(segment));
             break;
         case 0:
-            context.segment_function(std::ref(segment.source),
-                                     std::ref(segment.target),
-                                     segment.distance,
-                                     segment.duration);
+            luares = context.segment_function(std::ref(segment.source),
+                                              std::ref(segment.target),
+                                              segment.distance,
+                                              segment.duration);
             segment.weight = segment.duration; // back-compatibility fallback to duration
             break;
         }
+
+        if (!luares.valid())
+            handle_lua_error(luares);
     }
 }
 
@@ -1211,20 +1238,27 @@ void LuaScriptingContext::ProcessNode(const osmium::Node &node,
 {
     BOOST_ASSERT(state.lua_state() != nullptr);
 
+    sol::protected_function_result luares;
+
+    // TODO check for api version, make sure luares is always set
     switch (api_version)
     {
     case 4:
     case 3:
-        node_function(profile_table, std::cref(node), std::ref(result), std::cref(relations));
+        luares =
+            node_function(profile_table, std::cref(node), std::ref(result), std::cref(relations));
         break;
     case 2:
-        node_function(profile_table, std::cref(node), std::ref(result));
+        luares = node_function(profile_table, std::cref(node), std::ref(result));
         break;
     case 1:
     case 0:
-        node_function(std::cref(node), std::ref(result));
+        luares = node_function(std::cref(node), std::ref(result));
         break;
     }
+
+    if (!luares.valid())
+        handle_lua_error(luares);
 }
 
 void LuaScriptingContext::ProcessWay(const osmium::Way &way,
@@ -1233,20 +1267,27 @@ void LuaScriptingContext::ProcessWay(const osmium::Way &way,
 {
     BOOST_ASSERT(state.lua_state() != nullptr);
 
+    sol::protected_function_result luares;
+
+    // TODO check for api version, make sure luares is always set
     switch (api_version)
     {
     case 4:
     case 3:
-        way_function(profile_table, std::cref(way), std::ref(result), std::cref(relations));
+        luares =
+            way_function(profile_table, std::cref(way), std::ref(result), std::cref(relations));
         break;
     case 2:
-        way_function(profile_table, std::cref(way), std::ref(result));
+        luares = way_function(profile_table, std::cref(way), std::ref(result));
         break;
     case 1:
     case 0:
-        way_function(std::cref(way), std::ref(result));
+        luares = way_function(std::cref(way), std::ref(result));
         break;
     }
+
+    if (!luares.valid())
+        handle_lua_error(luares);
 }
 
 } // namespace osrm::extractor

test/data/profiles/bad_node.lua

@@ -0,0 +1,140 @@
+-- copy of testbot with process_node throwing a runtime error
+
+api_version = 4
+
+function setup()
+  return {
+    properties = {
+      continue_straight_at_waypoint = true,
+      max_speed_for_map_matching    = 30/3.6, --km -> m/s
+      weight_name                   = 'duration',
+      process_call_tagless_node     = false,
+      u_turn_penalty                 = 20,
+      traffic_light_penalty         = 7,     -- seconds
+      use_turn_restrictions         = true
+    },
+
+    classes = {"motorway", "toll", "TooWords2"},
+
+    excludable = {
+        {["motorway"] = true},
+        {["toll"] = true},
+        {["motorway"] = true, ["toll"] = true}
+    },
+
+    default_speed  = 24,
+    speeds = {
+      primary = 36,
+      secondary = 18,
+      tertiary = 12,
+      steps = 6
+    }
+  }
+end
+
+function process_node (profile, node, result)
+  if (2 < nil) then
+    print("2 is less than nil")
+  end
+
+  -- check if node is a traffic light
+  -- TODO: a way to set the penalty value
+end
+
+function process_way (profile, way, result)
+  local highway = way:get_value_by_key("highway")
+  local toll = way:get_value_by_key("toll")
+  local name = way:get_value_by_key("name")
+  local oneway = way:get_value_by_key("oneway")
+  local route = way:get_value_by_key("route")
+  local duration = way:get_value_by_key("duration")
+  local maxspeed = tonumber(way:get_value_by_key ( "maxspeed"))
+  local maxspeed_forward = tonumber(way:get_value_by_key( "maxspeed:forward"))
+  local maxspeed_backward = tonumber(way:get_value_by_key( "maxspeed:backward"))
+  local junction = way:get_value_by_key("junction")
+
+  if name then
+    result.name = name
+  end
+
+  result.forward_mode = mode.driving
+  result.backward_mode = mode.driving
+
+  if duration and durationIsValid(duration) then
+    result.duration = math.max( 1, parseDuration(duration) )
+    result.forward_mode = mode.route
+    result.backward_mode = mode.route
+  else
+    local speed_forw = profile.speeds[highway] or profile.default_speed
+    local speed_back = speed_forw
+
+    if highway == "river" then
+      local temp_speed = speed_forw
+      result.forward_mode = mode.river_down
+      result.backward_mode = mode.river_up
+      speed_forw = temp_speed*1.5
+      speed_back = temp_speed/1.5
+    elseif highway == "steps" then
+      result.forward_mode = mode.steps_down
+      result.backward_mode = mode.steps_up
+    end
+
+    if maxspeed_forward ~= nil and maxspeed_forward > 0 then
+      speed_forw = maxspeed_forward
+    else
+      if maxspeed ~= nil and maxspeed > 0 and speed_forw > maxspeed then
+        speed_forw = maxspeed
+      end
+    end
+
+    if maxspeed_backward ~= nil and maxspeed_backward > 0 then
+      speed_back = maxspeed_backward
+    else
+      if maxspeed ~=nil and maxspeed > 0 and speed_back > maxspeed then
+        speed_back = maxspeed
+      end
+    end
+
+    result.forward_speed = speed_forw
+    result.backward_speed = speed_back
+  end
+
+  if oneway == "no" or oneway == "0" or oneway == "false" then
+    -- nothing to do
+  elseif oneway == "-1" then
+    result.forward_mode = mode.inaccessible
+  elseif oneway == "yes" or oneway == "1" or oneway == "true" or junction == "roundabout" then
+    result.backward_mode = mode.inaccessible
+  end
+
+  if highway == 'motorway' then
+      result.forward_classes["motorway"] = true
+      result.backward_classes["motorway"] = true
+  end
+
+  if toll == "yes" then
+      result.forward_classes["toll"] = true
+      result.backward_classes["toll"] = true
+  end
+
+  if junction == 'roundabout' then
+    result.roundabout = true
+  end
+end
+
+function process_turn (profile, turn)
+  if turn.is_u_turn then
+    turn.duration = turn.duration + profile.properties.u_turn_penalty
+    turn.weight = turn.weight + profile.properties.u_turn_penalty
+  end
+  if turn.has_traffic_light then
+     turn.duration = turn.duration + profile.properties.traffic_light_penalty
+  end
+end
+
+return {
+  setup = setup,
+  process_way = process_way,
+  process_node = process_node,
+  process_turn = process_turn
+}