fix(lwm2m): improve error logging for bad lwm2m requests

apps/emqx_lwm2m/src/emqx_lwm2m.app.src

@@ -1,6 +1,6 @@
 {application,emqx_lwm2m,
  [{description,"EMQ X LwM2M Gateway"},
-  {vsn, "4.3.7"}, % strict semver, bump manually!
+  {vsn, "4.3.8"}, % strict semver, bump manually!
   {modules,[]},
   {registered,[emqx_lwm2m_sup]},
   {applications,[kernel,stdlib,lwm2m_coap]},

apps/emqx_lwm2m/src/emqx_lwm2m.appup.src

@@ -1,29 +1,75 @@
 %% -*- mode: erlang -*-
+%% Unless you know what you are doing, DO NOT edit manually!!
 {VSN,
-  [{<<"4\\.3\\.[0-1]">>,
+  [{"4.3.7",
-    [{restart_application,emqx_lwm2m}]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[0-1]">>,[{restart_application,emqx_lwm2m}]},
    {"4.3.2",
-    [{load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
    {<<"4\\.3\\.[3-4]">>,
-    [{load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
    {"4.3.5",
-    [{load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
    {"4.3.6",
-    [ %% There are only changes to the schema file, so we don't need any
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
-      %% commands here
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
-    ]}],
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
-  [{<<"4\\.3\\.[0-1]">>,
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
-    [{restart_application,emqx_lwm2m}]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]}]}],
+  [{"4.3.7",
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]}]},
+   {<<"4\\.3\\.[0-1]">>,[{restart_application,emqx_lwm2m}]},
    {"4.3.2",
-    [{load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
    {<<"4\\.3\\.[3-4]">>,
-    [{load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_protocol,brutal_purge,soft_purge,[]},
      {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
    {"4.3.5",
-    [{load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
-   {"4.3.6", []}]}.
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_api,brutal_purge,soft_purge,[]}]},
+   {"4.3.6",
+    [{load_module,emqx_lwm2m_xml_object_db,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_xml_object,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_message,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_json,brutal_purge,soft_purge,[]},
+     {load_module,emqx_lwm2m_cmd_handler,brutal_purge,soft_purge,[]}]}]}.

apps/emqx_lwm2m/src/emqx_lwm2m_cmd_handler.erl

@@ -106,9 +106,11 @@ coap_read_to_mqtt({ok, SuccessCode}, CoapPayload, Format, Ref) ->
         Result = coap_content_to_mqtt_payload(CoapPayload, Format, Ref),
         make_response(SuccessCode, Ref, Format, Result)
     catch
-        error:not_implemented -> make_response(not_implemented, Ref);
+        throw : {bad_request, Reason} ->
+            ?LOG(error, "bad_request, reason=~p, payload=~p", [Reason, CoapPayload]),
+            make_response(bad_request, Ref);
         C:R:Stack ->
-            ?LOG(error, "~p, bad payload format: ~p, stacktrace: ~p", [{C, R}, CoapPayload, Stack]),
+            ?LOG(error, "bad_request, error=~p, stacktrace=~p~npayload=~p", [{C, R}, Stack, CoapPayload]),
             make_response(bad_request, Ref)
     end.
 

apps/emqx_lwm2m/src/emqx_lwm2m_json.erl

@@ -29,7 +29,7 @@
 tlv_to_json(BaseName, TlvData) ->
     DecodedTlv = emqx_lwm2m_tlv:parse(TlvData),
     ObjectId = object_id(BaseName),
-    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def(ObjectId, true),
+    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def_assertive(ObjectId, true),
     case DecodedTlv of
         [#{tlv_resource_with_value:=Id, value:=Value}] ->
             TrueBaseName = basename(BaseName, undefined, undefined, Id, 3),
@@ -315,7 +315,7 @@ encode_int(Int) -> binary:encode_unsigned(Int).
 
 text_to_json(BaseName, Text) ->
     {ObjectId, ResourceId} = object_resource_id(BaseName),
-    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def(ObjectId, true),
+    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def_assertive(ObjectId, true),
     {K, V} = text_value(Text, ResourceId, ObjDefinition),
     #{bn=>BaseName, e=>[#{K=>V}]}.
 

apps/emqx_lwm2m/src/emqx_lwm2m_message.erl

@@ -33,7 +33,7 @@
 tlv_to_json(BaseName, TlvData) ->
     DecodedTlv = emqx_lwm2m_tlv:parse(TlvData),
     ObjectId = object_id(BaseName),
-    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def(ObjectId, true),
+    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def_assertive(ObjectId, true),
     case DecodedTlv of
         [#{tlv_resource_with_value:=Id, value:=Value}] ->
             TrueBaseName = basename(BaseName, undefined, undefined, Id, 3),
@@ -289,7 +289,7 @@ path([H|T], Acc) ->
 
 text_to_json(BaseName, Text) ->
     {ObjectId, ResourceId} = object_resource_id(BaseName),
-    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def(ObjectId, true),
+    ObjDefinition = emqx_lwm2m_xml_object:get_obj_def_assertive(ObjectId, true),
     Val = text_value(Text, ResourceId, ObjDefinition),
     [#{path => BaseName, value => Val}].
 

apps/emqx_lwm2m/src/emqx_lwm2m_xml_object.erl

@@ -20,6 +20,7 @@
 -include_lib("xmerl/include/xmerl.hrl").
 
 -export([ get_obj_def/2
+        , get_obj_def_assertive/2
         , get_object_id/1
         , get_object_name/1
         , get_object_and_resource_id/2
@@ -31,15 +32,19 @@
 -define(LOG(Level, Format, Args),
     logger:Level("LWM2M-OBJ: " ++ Format, Args)).
 
-% This module is for future use. Disabled now.
+get_obj_def_assertive(ObjectId, IsInt) ->
+    case get_obj_def(ObjectId, IsInt) of
+        {error, no_xml_definition} ->
+            erlang:throw({bad_request, {unknown_object_id, ObjectId}});
+        Xml ->
+            Xml
+    end.
 
 get_obj_def(ObjectIdInt, true) ->
     emqx_lwm2m_xml_object_db:find_objectid(ObjectIdInt);
 get_obj_def(ObjectNameStr, false) ->
     emqx_lwm2m_xml_object_db:find_name(ObjectNameStr).
 
-
-
 get_object_id(ObjDefinition) ->
     [#xmlText{value=ObjectId}] = xmerl_xpath:string("ObjectID/text()", ObjDefinition),
     ObjectId.

apps/emqx_lwm2m/src/emqx_lwm2m_xml_object_db.erl

@@ -69,12 +69,9 @@ find_name(Name) ->
                  end,
     case ets:lookup(?LWM2M_OBJECT_NAME_TO_ID_TAB, NameBinary) of
         [] ->
-            undefined;
+            {error, no_xml_definition};
         [{NameBinary, ObjectId}] ->
-            case ets:lookup(?LWM2M_OBJECT_DEF_TAB, ObjectId) of
+            find_objectid(ObjectId)
-                [] -> undefined;
-                [{ObjectId, Xml}] -> Xml
-            end
     end.
 
 stop() ->

apps/emqx_lwm2m/test/emqx_lwm2m_SUITE.erl

@@ -689,6 +689,60 @@ case10_read(Config) ->
                              }),
     ?assertEqual(ReadResult, test_recv_mqtt_response(RespTopic)).
 
+case10_read_bad_request(Config) ->
+    UdpSock = ?config(sock, Config),
+    Epn = "urn:oma:lwm2m:oma:3",
+    MsgId1 = 15,
+    RespTopic = list_to_binary("lwm2m/"++Epn++"/up/resp"),
+    emqtt:subscribe(?config(emqx_c, Config), RespTopic, qos0),
+    timer:sleep(200),
+    % step 1, device register ...
+    test_send_coap_request( UdpSock,
+                            post,
+                            sprintf("coap://127.0.0.1:~b/rd?ep=~s&lt=345&lwm2m=1", [?PORT, Epn]),
+                            #coap_content{content_format = <<"text/plain">>,
+                            payload = <<"</lwm2m>;rt=\"oma.lwm2m\";ct=11543,</lwm2m/1/0>,</lwm2m/2/0>,</lwm2m/3/0>">>},
+                            [],
+                            MsgId1),
+    #coap_message{method = Method1} = test_recv_coap_response(UdpSock),
+    ?assertEqual({ok,created}, Method1),
+    test_recv_mqtt_response(RespTopic),
+
+    % step2,  send a READ command to device
+    CmdId = 206,
+    CommandTopic = <<"lwm2m/", (list_to_binary(Epn))/binary, "/dn/dm">>,
+    Command =   #{
+                    <<"requestID">> => CmdId, <<"cacheID">> => CmdId,
+                    <<"msgType">> => <<"read">>,
+                    <<"data">> => #{
+                        <<"path">> => <<"/3333/0/0">>
+                    }
+                },
+    CommandJson = emqx_json:encode(Command),
+    ?LOGT("CommandJson=~p", [CommandJson]),
+    test_mqtt_broker:publish(CommandTopic, CommandJson, 0),
+    timer:sleep(50),
+    Request2 = test_recv_coap_request(UdpSock),
+    #coap_message{method = Method2, payload=Payload2} = Request2,
+    ?LOGT("LwM2M client got ~p", [Request2]),
+    ?assertEqual(get, Method2),
+    ?assertEqual(<<>>, Payload2),
+    timer:sleep(50),
+
+    test_send_coap_response(UdpSock, "127.0.0.1", ?PORT, {ok, content}, #coap_content{content_format = <<"text/plain">>, payload = <<"EMQ">>}, Request2, true),
+    timer:sleep(100),
+
+    ReadResult = emqx_json:encode(#{  <<"requestID">> => CmdId, <<"cacheID">> => CmdId,
+                                <<"msgType">> => <<"read">>,
+                                <<"data">> => #{
+                                    <<"code">> => <<"4.00">>,
+                                    <<"codeMsg">> => <<"bad_request">>,
+                                    <<"reqPath">> => <<"/3333/0/0">>
+                                }
+                             }),
+    ?assertEqual(ReadResult, test_recv_mqtt_response(RespTopic)).
+
+
 case10_read_separate_ack(Config) ->
     UdpSock = ?config(sock, Config),
     Epn = "urn:oma:lwm2m:oma:3",