Farmbot disconnects after token refresh

Hey there,

farmbot disconnected yesterday after a „Forcing a token refresh“ entry in the log. Why did that happen? Please solve this bug as it is super annoying that the bot disconnects and one can only remote control it because being not onsite! I needed fb exactly for those two weeks and it failed again… :confused:

@Gabriel @RickCarlino @connor @roryaronson could you support pls?!

It’s hard to tell for sure without the exact log message, but it sounds to me like your device disconnected from the network.there are two settings that you can use to mitigate this. In the devices panel look for “automatic factory reset” and for “network not found timer” if using wireless.

Note that disabling factory resetting will not fix whatever is causing your network to not work.

Hey @connor thanks for the reply!!
So you would admit that it would be beneficial if the bot would spill out more logs? I do have the reconnect phase after disconnect set to 10 min. but I would really like to see:
a) why it disconnected? E.g. lost network connection, lost internet connection, lost connection to a farmbot server
b) why the reconnect failed?! WiFi not found, username wrong, no connection to farmbot services etc…

If you don’t implement those logs, no one will be able in future to debug when new problems pop up. That they pop up is no question and normal. But the question is rather when…

The log you saw has the reason inside it. It Shou say "Farmbot failed to authenticate with token: some reason" where some reason is something along the lines of nxdomain, bad password etc. Unfortunately Farmbot also logs the reason it went offline when it goes offline but that log won’t make it out because it is offline for the described reason. I’m working on a feature that will save the last 100 logs to a fat32 formatted flash drive if Farmbot goes offline, to help in these sorts of situations.

Ah I see. I thought that you anyway already would save the last 100 Logs to the sd card and then update it with the servers as soon as the bot is online again?! Sending the logs directly without temporary savings on the sd card is quite risky?!

However, please inform as when you have implemented this feature. And as you are working on the logs, could you please enable the user to save more than 100 log lines? If I have a sequence which spits out many logs than 100 lines are quickly full… thanks @connor for your support!

@connor
So I’m affected too : Token Refresh failed:

{%Sqlite.DbConnection.Error{connection_id: nil, message: "unable to open database file", sqlite: %{code: :cantopen}}, [{Ecto.Adapters.SQL, :struct, 8, [file: 'lib/ecto/adapters/sql.ex', line: 554]}, {Ecto.Repo.Schema, :apply, 4, [file: 'lib/ecto/repo/schema.ex', line: 547]}, {Ecto.Repo.Schema, :"-do_update/4-fun-0-", 14, [file: 'lib/ecto/repo/schema.ex', line: 292]}, {Ecto.Repo.Schema, :update!, 4, [file: 'lib/ecto/repo/schema.ex', line: 136]}, {Farmbot.System.ConfigStorage, :update_config_value, 4, [file: 'lib/farmbot/system/config_storage/config_storage.ex', line: 175]}, {Farmbot.Bootstrap.AuthTask, :do_refresh, 0, [file: 'lib/farmbot/bootstrap/auth_task.ex', line: 42]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 616]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 686]}]} 

But I’m not sure if this is connection related…

This is a frontend/api issue. I’ll forward this request along.

This looks to me like some sort of hardware related issue. Are you using a official Farmbot kit, or a self built one?

Hey @connor I was able today to wake up my FB again. There was no error message on the “startup” configure page, it looked like plain configuration. Therefore I strongly assume that it was a software bug that the FB disconnected rather than a wifi network problem.

Its quite frustrating if that happens during the only two weeks in the year when it needs to work autonomously so I would really really appreciate if you could look into this problem, to solve it for the future!!!

Hey All
First post! I have been piecing together farmbot and have overcome numerous trials. However my current trial seems to be what this thread is on. He disconnects after a day or so and the only thing I can figure out to get him back online is resetting my SSD card (which I’ve now done many times).

Here is my error log. Has anyone seen this before?

Same Error messages here at May 31, 9:29am and May 31, 10:59am;
then afterwards syncs and this:

uccess Interface wlan0 is up. 0, 200, 206 May 31, 1:03pm
3

Busy Waiting for interface wlan0 up. 0, 200, 206 May 31, 1:03pm
3

Success Interface wlan0 is up. 0, 200, 206 May 31, 1:03pm
3

Busy Waiting for interface wlan0 up. 0, 200, 206 May 31, 1:03pm
2

Busy Syncing 0, 200, 206 May 31, 1:02pm
3

Success Farmbot was reconnected to the internet: [‘my.farmbot.io’] 0, 200, 206 May 31, 1:02pm
2

Busy Syncing 0, 200, 206 May 31, 12:58pm
2

Busy Syncing 0, 200, 206 May 31, 12:58pm
2

Busy Syncing 0, 200, 206 May 31, 12:58pm
2

Busy Syncing 0, 200, 206 May 31, 12:29pm
2

Busy Syncing 0, 200, 206 May 31, 12:28pm
2

Busy Syncing 0, 200, 206 May 31, 12:28pm
2

Busy Syncing 0, 200, 206 May 31, 11:59am
2

Busy Syncing 0, 200, 206 May 31, 11:59am
2

Busy Syncing 0, 200, 206 May 31, 11:58am
2

Busy Syncing 0, 200, 206 May 31, 11:29am
2

Busy Syncing 0, 200, 206 May 31, 11:29am
2

Busy Syncing 0, 200, 206 May 31, 11:28am
2

Busy Syncing 0, 200, 206 May 31, 10:59am
2

Busy Syncing 0, 200, 206 May 31, 10:59am

@connor @Gabriel could you please support!?

It’s self built (v1.2), but i must say this started to occur since 6.4.1 OS, and only happened twice.

Your bot seems to be unable to reach my.farm.bot. This is likely due to a network disconnect of some sort. Are you using wifi?

Yes I am, the connection isn’t great, but everything works reliably except for the disconnects.

I do have the same, it just says connect timeout and not timeout.

Any idea @Gabriel @connor @roryaronson?

Hey Everyone. I just wanted to let you know I’d found a solution.
I bought a new router, a Netgear Nighthawk, no more issues.

Initially I could not discover my router in the farmbot-xxxx network list, but updating the router firmware solved that problem.

I took a break from farmbot for a few months as frosts in this region of Aussie are a bit much for a garden I imagine, but now its spring and farmbot just sowed my first plants! :slight_smile:

Thanks for your help.

2 Likes

@connor @Gabriel:

After switching to the new firmware 6.4.11 the bot is connected except for the connection webApp <-> FarmBot which is red in the status menu in “devices” but the sync tab is green and I can control the bot.

It constantly says in the logs:

Failed to resolve https://my.farm.bot: {:error, :timeout}
Token failed to reauthorize:xxx@yyy.zz - https://my.farm.bot :nxdomain
Authorization failed: {:error, :nxdomain}

WebApp version is VERSION: 76606073.

Moreover I noticed, that I am not able anylonger to ping the bot in my local network. Did you change anything that the ping request is refused in any way? :confused:

Please fix…

Thanks, Best
Klim

Not very much changed in .11 at all. It was mostly a bug fix for an unrelated issue to do with disk usage. The logs are telling you what is happening: nxdomain. FarmBot can’t reach our servers, and since you can’t ping it on your local network, i’d say FarmBot disconnected from your network.

But how come then that I can still control it and it does not say it is offline? :confused:

@connor: Very interesting, wanted to reboot the bot within the webapp, but it did not come online again, opened the config wifi, I joined and read that it wasn´t able to reach the farmbot networks earlier. Now I configured it again and the log says:

Success Synced 0, 0, 0 Sep 24, 10:14pm
3

Busy|Read peripheral (8 - digital)|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Read peripheral (9 - digital)|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Read peripheral (10 - digital)|0, 0, 0|Sep 24, 10:14pm|
|1

Debug|Synced Farmbot OS and Firmware settings with API|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating: sequence_complete_log => false|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating: os_auto_update => false|0, 0, 0|Sep 24, 10:14pm|
|1

Busy|Syncing|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating: network_not_found_timer => 30|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating: auto_sync => true|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating: arduino_debug_messages => false|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_missed_steps_max_x: 5.0 => 10|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_axis_nr_steps_z: 0.0 => 3355|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_home_y: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_missed_steps_max_y: 5.0 => 10|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_use_for_pos_y: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_max_y: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_5_time_out: 0.0 => 60|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_enabled_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_step_per_mm_z: 25.0 => 6.0|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_5_active_state: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_use_for_pos_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_invert_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_max_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_axis_nr_steps_x: 0.0 => 6334|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_max_x: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_secondary_motor_invert_x: 1.0 => 0|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_max_spd_z: 400.0 => 1500|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_keep_active_z: 1.0 => 0|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_3_active_state: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_enabled_y: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_min_spd_z: 50.0 => 200|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_missed_steps_max_z: 5.0 => 10|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_3_time_out: 0.0 => 60|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_4_active_state: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_home_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: param_mov_nr_retry: 3.0 => 10|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_home_up_z: 1.0 => 0|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_2_active_state: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_enabled_x: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: param_e_stop_on_mov_err: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: encoder_scaling_z: 5556.0 => 1389|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_home_at_boot_x: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: pin_guard_1_time_out: 0.0 => 60|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_axis_nr_steps_y: 0.0 => 6386|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_stop_at_home_x: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_max_spd_x: 400.0 => 700|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_invert_motor_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_steps_acc_dec_z: 300.0 => 100|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Updating FW param: movement_home_at_boot_z: 0.0 => 1|0, 0, 0|Sep 24, 10:14pm|
|3

Success|Downloaded Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Downloading Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Finishing install for #Farmware<camera-calibration(0.0.1)>|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Checking directories for camera-calibration - 0.0.1|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Starting preflight checks for #Farmware<camera-calibration(0.0.1)>|0, 0, 0|Sep 24, 10:14pm|
|2

Busy|Installing farmware from https://raw.githubusercontent.com/FarmBot-Labs/farmware_manifests/master/packages/camera-calibration/manifest.json.|0, 0, 0|Sep 24, 10:14pm|
|3

Success|Downloaded Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Downloading Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Finishing install for #Farmware<plant-detection(0.0.4)>|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Checking directories for plant-detection - 0.0.4|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Starting preflight checks for #Farmware<plant-detection(0.0.4)>|0, 0, 0|Sep 24, 10:14pm|
|2

Busy|Installing farmware from https://raw.githubusercontent.com/FarmBot-Labs/farmware_manifests/master/packages/plant-detection/manifest.json.|0, 0, 0|Sep 24, 10:14pm|
|3

Success|Downloaded Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Downloading Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|2

Success|Finishing install for #Farmware<historical-camera-calibration(0.0.1)>|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Checking directories for historical-camera-calibration - 0.0.1|0, 0, 0|Sep 24, 10:14pm|
|2

Info|Starting preflight checks for #Farmware<historical-camera-calibration(0.0.1)>|0, 0, 0|Sep 24, 10:14pm|
|2

Busy|Installing farmware from https://raw.githubusercontent.com/FarmBot-Labs/farmware_manifests/master/packages/historical-camera-calibration/manifest.json.|0, 0, 0|Sep 24, 10:14pm|
|3

Success|Downloaded Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|3

Busy|Downloading Farmware tools: https://api.github.com/repos/FarmBot-Labs/farmware-tools/releases/latest|0, 0, 0|Sep 24, 10:14pm|
|1

Busy|Initializing Firmware.|0, 0, 0|Sep 24, 10:14pm|
|1

Busy|Firmware not initialized yet. Waiting for R88 message.|Unknown|Sep 24, 10:14pm|
|2

Success|Finishing install for #Farmware<historical-plant-detection(0.0.1)>|Unknown|Sep 24, 10:14pm|
|2

Info|Checking directories for historical-plant-detection - 0.0.1|Unknown|Sep 24, 10:14pm|
|2

Info|Starting preflight checks for #Farmware<historical-plant-detection(0.0.1)>|Unknown|Sep 24, 10:14pm|
|2

Busy|Installing farmware from https://raw.githubusercontent.com/FarmBot-Labs/farmware_manifests/master/packages/historical-plant-detection/manifest.json.|Unknown|Sep 24, 10:14pm|
|2

Busy|Syncing all Farmware repos. This may take a while.|Unknown|Sep 24, 10:14pm|
|1

Success|Farmbot is up and running!|Unknown|Sep 24, 10:13pm|
|3

Success|Got ARDUINO STARTUP COMPLETE. UART is up.|Unknown|Sep 24, 10:13pm|
|2

Success|Successful Bootstrap authorization: bla@bla.de - https://my.farm.bot|Unknown|Sep 24, 10:12pm|
|1

Success|Connected to access point.|Unknown|Sep 24, 10:12pm|
|1

Warn|AuthTask not running yet|Unknown|Sep 24, 10:12pm|
|2

Busy|Beginning Bootstrap authorization: bla@bla.de - https://my.farm.bot|Unknown|Sep 24, 10:12pm|
|1

Error|Trying to resolve https://my.farm.bot 9 more times.|Unknown|Sep 24, 10:12pm|
|1

Success|Connected to access point.|Unknown|Sep 24, 10:12pm|
|1

Warn|AuthTask not running yet|Unknown|Sep 24, 10:12pm|
|3

Success|Time seems to be set. Moving on.|Unknown|Sep 24, 10:12pm|
|3

Success|Interface wlan0 is up.|Unknown|Sep 24, 10:12pm|
|3

Busy|Waiting for interface wlan0 up.|Unknown|Sep 24, 10:12pm|
|3

Error|Error stopping dnsmasq: argument error|Unknown|Sep 24, 10:12pm|
|3

Busy|Killing dnsmasq PID.|Unknown|Sep 24, 10:12pm|
|3

Busy|Stopping dnsmasq|Unknown|Sep 24, 10:12pm|
|3

Busy|Stopping DHCP GenServer.|Unknown|Sep 24, 10:12pm|
|3

Busy|Stopping mDNS.|Unknown|Sep 24, 10:12pm|
|3

Busy|Stopping captive portal GenServer.|Unknown|Sep 24, 10:12pm|
|2

Success|Configuration finished.|Unknown|Sep 24, 10:12pm|
|1

Success|Firmware flashed! /srv/erlang/lib/farmbot-6.4.11/priv/arduino_firmware.hex|Unknown|Sep 24, 10:12pm|
|3

Busy|Starting avrdude: /srv/erlang/lib/farmbot-6.4.11/priv/arduino_firmware.hex|Unknown|Sep 24, 10:12pm|
|1

Success|Firmware flashed! /srv/erlang/lib/farmbot-6.4.11/priv/eeprom_clear.ino.hex|Unknown|Sep 24, 10:12pm|
|3

Busy|Starting avrdude: /srv/erlang/lib/farmbot-6.4.11/priv/eeprom_clear.ino.hex|Unknown|Sep 24, 10:12pm|
|1

Warn|Updating arduino firmware.|Unknown|Sep 24, 10:12pm|
|3

Busy|Starting captive portal.|Unknown|Sep 24, 10:08pm|
|3

Busy|Configuring Farmbot.|Unknown|Sep 24, 10:08pm|
|3

Success|detected target UART: /dev/ttyACM0|Unknown|Sep 24, 10:08pm|
|3

Busy|Checking /root/boot|Unknown|Sep 24, 10:07pm|
|1

Info|Loading kernel module: snd-bcm2835|Unknown|Sep 24, 10:07pm|
|1

Warn|Trying to emergency lock firmware before powerdown|0, 0, 0.67|Sep 24, 10:06pm|
|1

Warn|Going down for a reboot!|

Could you tell me what happened here? Why were I still able to control the bot but it seemed to be disconnected to the farmbot servers? There are too many strange things happening with these connectivity issues, really…

@connor?
Newest error today:

{“message”:“Loading chunk 12 failed.\n(error: https://my.farm.bot/webpack/12.12.e275d337ff69f8bab2e8.js)”,“stack”:“Error: Loading chunk 12 failed.\n(error: https://my.farm.bot/webpack/12.12.e275d337ff69f8bab2e8.js)\n at HTMLScriptElement.a (https://my.farm.bot/webpack/app_bundle-d9c139726e39743658a3.js:1:1622)”}

And the log says after triggering a sequence with MLH:

Beginning execution of #Farmware<MLH(2.4.15)> 0, 0, 0.33 Sep 26, 7:59pm

[MLH] Something went wrong: HTTPSConnectionPool(host=‘my.farmbot.io’, port=443): Max retries exceeded with url: /api/device (Caused by NewConnectionError(’<urllib3.connection.VerifiedHTTPSConnection object at 0x76022270>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution’,))

@Gabriel @roryaronson please support now quick, the bot is more or less unusable since a long while now again!