lorawan-server icon indicating copy to clipboard operation
lorawan-server copied to clipboard

Not possible to send downlinks on class C if lastRx is undefined

Open ruipalma opened this issue 5 years ago • 9 comments

If the device joins but not send a uplink, the lastRX is undefined. On this conditions is not possible to send a downlink on class C to the device because the function try_class_c crashes on the function calendar:datetime_to_gregorian_seconds(LastRx).

Debug log:

2019-07-03 19:31:22.835 [warning] <0.4121.0>@lorawan_connector_mqtt:terminate:263 Connector mqtt terminated: {function_clause,[{calendar,datetime_to_gregorian_seconds,[undefined],[{file,"calendar.erl"},{line,137}]},{lorawan_application_backend,try_class_c,4,[{file,"/lorawan-server/src/lorawan_application_backend.erl"},{line,307}]},{lorawan_connector_mqtt,handle_info,2,[{file,"/lorawan-server/src/lorawan_connector_mqtt.erl"},{line,218}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,616}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,686}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,247}]}]} 2019-07-03 19:31:22.836 [error] <0.4121.0>@calendar:datetime_to_gregorian_seconds:137 gen_server <0.4121.0> terminated with reason: no function clause matching calendar:datetime_to_gregorian_seconds(undefined) line 137 2019-07-03 19:31:22.836 [error] <0.4121.0>@calendar:datetime_to_gregorian_seconds:137 CRASH REPORT Process <0.4121.0> with 0 neighbours crashed with reason: no function clause matching calendar:datetime_to_gregorian_seconds(undefined) line 137 2019-07-03 19:31:22.837 [error] <0.4122.0>@calendar:datetime_to_gregorian_seconds:137 gen_fsm <0.4122.0> in state connected terminated with reason: no function clause matching calendar:datetime_to_gregorian_seconds(undefined) line 137 2019-07-03 19:31:22.838 [error] <0.4122.0>@calendar:datetime_to_gregorian_seconds:137 CRASH REPORT Process <0.4122.0> with 1 neighbours exited with reason: no function clause matching calendar:datetime_to_gregorian_seconds(undefined) line 137 in gen_fsm:terminate/7 line 602 2019-07-03 19:31:22.838 [error] <0.343.0>@calendar:datetime_to_gregorian_seconds:137 Supervisor lorawan_connector_sup had child {mqtt,<<"mqtt">>} started with lorawan_connector_mqtt:start_link({connector,<<"mqtt">>,<<"test">>,<<"json">>,<<"mqtt://10.210.1.6:1884">>,undefined,<<"/lorawan/upl...">>,...}) at <0.4121.0> exit with reason no function clause matching calendar:datetime_to_gregorian_seconds(undefined) line 137 in context child_terminated

ruipalma avatar Jul 03 '19 19:07 ruipalma

Yeah, you are exactly right. Thanks for reporting it. I just made a fix. Are you able to build it on your own?

gotthardp avatar Jul 04 '19 08:07 gotthardp

I use the :latest docker container, and this problem is gone. I have some strange behaviors with this development branch but I can't do the debug now, I have to go back to :stable. Will you commit this change to the stable branch?

ruipalma avatar Jul 04 '19 12:07 ruipalma

It seems I can, so I did.

gotthardp avatar Jul 04 '19 13:07 gotthardp

I'm sorry to validate the commit, I see that the downlinks are been made, and the error is gone, so I thought that the issue is resolved, but that is not the case. It seems that the random gateway reconnects that I experience with the development branch are related to this issue also, because I'm having the same behavior with the stable. I think the lastRx are used on other function that needs it. In this case is the build_txpk on lorawan_gw_forwarder.erl.

Maybe you should revert the commit because in this conditions all the communications with the gateway are stopped.

2019-07-04 14:03:16 =CRASH REPORT==== crasher: initial call: lorawan_gw_forwarder:init/1 pid: <0.554.0> registered_name: lorawan_gw_forwarder exception error: {function_clause,[{lorawan_gw_forwarder,build_txpk,[{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},undefined,0,<<96,4,114,180,0,0,4,0,124,83,236,194,210,46,213,3,80,84,245,164,213,208,85,219,103,0,255,159,66>>],[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,191}]},{lorawan_gw_forwarder,handle_info,2,[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,112}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,616}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,686}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,247}]}]} ancestors: [<0.549.0>,<0.320.0>,<0.288.0>] message_queue_len: 0 messages: [] links: [<0.549.0>,#Port<0.7779>] dictionary: [] trap_exit: false status: running heap_size: 1598 stack_size: 27 reductions: 11634 neighbours: 2019-07-04 14:03:16 =SUPERVISOR REPORT==== Supervisor: {<0.549.0>,lorawan_gw_sup} Context: child_terminated Reason: {function_clause,[{lorawan_gw_forwarder,build_txpk,[{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},undefined,0,<<96,4,114,180,0,0,4,0,124,83,236,194,210,46,213,3,80,84,245,164,213,208,85,219,103,0,255,159,66>>],[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,191}]},{lorawan_gw_forwarder,handle_info,2,[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,112}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,616}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,686}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,247}]}]} Offender: [{pid,<0.554.0>},{id,packet_forwarder},{mfargs,{lorawan_gw_forwarder,start_link,[[{port,1680}]]}},{restart_type,permanent},{shutdown,5000},{child_type,worker}]

ERROR LOG:

2019-07-04 14:03:15.451 [error] <0.551.0>@lorawan_gw_forwarder:build_txpk:191 CRASH REPORT Process lorawan_gw_forwarder with 0 neighbours crashed with reason: no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,242,11,47,1,1,1,0,6,122,31,11,228,28,158,194,92,75,220,61,180,225,46,165,232,25,251,241,212,...>>) line 191 2019-07-04 14:03:15.451 [error] <0.549.0>@lorawan_gw_forwarder:build_txpk:191 Supervisor {<0.549.0>,lorawan_gw_sup} had child packet_forwarder started with lorawan_gw_forwarder:start_link([{port,1680}]) at <0.551.0> exit with reason no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,242,11,47,1,1,1,0,6,122,31,11,228,28,158,194,92,75,220,61,180,225,46,165,232,25,251,241,212,...>>) line 191 in context child_terminated 2019-07-04 14:03:16.451 [error] <0.554.0>@lorawan_gw_forwarder:build_txpk:191 gen_server lorawan_gw_forwarder terminated with reason: no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,4,114,180,0,0,4,0,124,83,236,194,210,46,213,3,80,84,245,164,213,208,85,219,103,0,255,159,66>>) line 191 2019-07-04 14:03:16.451 [error] <0.554.0>@lorawan_gw_forwarder:build_txpk:191 CRASH REPORT Process lorawan_gw_forwarder with 0 neighbours crashed with reason: no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,4,114,180,0,0,4,0,124,83,236,194,210,46,213,3,80,84,245,164,213,208,85,219,103,0,255,159,66>>) line 191 2019-07-04 14:03:16.452 [error] <0.549.0>@lorawan_gw_forwarder:build_txpk:191 Supervisor {<0.549.0>,lorawan_gw_sup} had child packet_forwarder started with lorawan_gw_forwarder:start_link([{port,1680}]) at <0.554.0> exit with reason no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,4,114,180,0,0,4,0,124,83,236,194,210,46,213,3,80,84,245,164,213,208,85,219,103,0,255,159,66>>) line 191 in context child_terminated

ruipalma avatar Jul 04 '19 14:07 ruipalma

It's not the same error and it should not occur in stable, but it is a bug. Thanks! I just fixed that (on master only as it's not in stable).

gotthardp avatar Jul 04 '19 15:07 gotthardp

I can confirm that is working super ok on the docker container :latest. But on docker container :stable the reconnecting issue is happening with the above error. I pull both images before the tests.

I think its some other issue so this bug can be marked solved, at least on the dev branch.

Thanks.

ruipalma avatar Jul 04 '19 18:07 ruipalma

But the above error report is from :latest. I can have a look, but I need the logs from :stable to check.

gotthardp avatar Jul 04 '19 18:07 gotthardp

Today my docker container :latest updated, and I had to revert to :stable (because the mqtt connector stop working) The same errors appeared, so I can absolutely confirm that the logs are from the stable version.

Crash LOG:

2019-06-11 18:37:27 =SUPERVISOR REPORT==== Supervisor: {<0.377.0>,lorawan_gw_sup} Context: child_terminated Reason: {function_clause,[{lorawan_gw_forwarder,build_txpk,[{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},undefined,0,<<96,234,66,191,1,129,178,0,6,3,223,138,248,249,249,196>>],[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,191}]},{lorawan_gw_forwarder,handle_info,2,[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,112}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,637}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,711}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]} Offender: [{pid,<0.411.0>},{id,packet_forwarder},{mfargs,{lorawan_gw_forwarder,start_link,[[{port,1680}]]}},{restart_type,permanent},{shutdown,5000},{child_type,worker}]

2019-06-11 18:38:07 =ERROR REPORT==== ** Generic server lorawan_gw_forwarder terminating ** Last message in was {send,{{172,17,0,1},37424,2},undefined,<<1,191,66,234>>,{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},0,<<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>} ** When Server state == {state,#Port<0.24>,#{}} ** Reason for termination == ** {function_clause,[{lorawan_gw_forwarder,build_txpk,[{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},undefined,0,<<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>],[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,191}]},{lorawan_gw_forwarder,handle_info,2,[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,112}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,637}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,711}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]} 2019-06-11 18:38:07 =CRASH REPORT==== crasher: initial call: lorawan_gw_forwarder:init/1 pid: <0.413.0> registered_name: lorawan_gw_forwarder exception error: {function_clause,[{lorawan_gw_forwarder,build_txpk,[{txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16},undefined,0,<<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>],[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,191}]},{lorawan_gw_forwarder,handle_info,2,[{file,"/lorawan-server/src/lorawan_gw_forwarder.erl"},{line,112}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,637}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,711}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]} ancestors: [<0.377.0>,<0.373.0>,<0.315.0>] message_queue_len: 0 messages: [] links: [<0.377.0>,#Port<0.24>] dictionary: [] trap_exit: false status: running heap_size: 4185 stack_size: 27 reductions: 6862 neighbours:

ERROR LOG:

2019-06-11 18:38:07.810 [error] <0.413.0>@lorawan_gw_forwarder:build_txpk:191 gen_server lorawan_gw_forwarder terminated with reason: no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>) line 191 2019-06-11 18:38:07.810 [error] <0.413.0>@lorawan_gw_forwarder:build_txpk:191 CRASH REPORT Process lorawan_gw_forwarder with 0 neighbours crashed with reason: no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>) line 191 2019-06-11 18:38:07.812 [error] <0.377.0>@lorawan_gw_forwarder:build_txpk:191 Supervisor {<0.377.0>,lorawan_gw_sup} had child packet_forwarder started with lorawan_gw_forwarder:start_link([{port,1680}]) at <0.413.0> exit with reason no function clause matching lorawan_gw_forwarder:build_txpk({txq,869.525,<<"SF7BW125">>,<<"4/5">>,immediately,16}, undefined, 0, <<96,234,66,191,1,129,179,0,6,3,233,217,16,239,201,45>>) line 191 in context child_terminated

PS: I have to revert because on :latest the mqtt connector does not work, but that is a different issue. At this moment only the release 0.6.7 is working for me with the issue "Not possible to send downlinks on class C"

crash.log debug.log error.log

ruipalma avatar Oct 22 '19 18:10 ruipalma

Yeah. The "latest" is broken now.

gotthardp avatar Dec 25 '19 12:12 gotthardp