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

[ruipalma]

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

[gotthardp]

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

[ruipalma]

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?

[gotthardp]

It seems I can, so I did.

[ruipalma]

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

[gotthardp]

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).

[ruipalma]

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.

[gotthardp]

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

[ruipalma]

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

[gotthardp]

Yeah. The "latest" is broken now.