Plugin losing API key

[greghesp]

I've seen the other closed issue about the plugin losing the API key, however this is still happening to me with the latest version.

I only have 1 Pi that isn't a clone, and only 1 plugin shows in my account.

This happens probably every day, certainly multiple times a week

[CoDanny]

Please share your octoprint log

[greghesp]

octoprint.log

Log attached. I did a quick search for Astroprint. On the 27th December, you can see in the morning it was connecting fine, then in the afternoon there was no user

2019-12-27 12:27:14,970 - octoprint.plugins.astroprint - INFO - Found stored AstroPrint User: Greg Hesp
2019-12-27 12:27:15,520 - octoprint.plugins.astroprint - INFO - Getting AstroPrint user info
2019-12-27 12:27:16,048 - octoprint.plugins.astroprint - INFO - Connecting Box Router
2019-12-27 12:27:16,704 - octoprint.plugins.astroprint - INFO - Boxrouter connected to astroprint service

2019-12-27 13:50:39,216 - octoprint.plugins.astroprint - WARNING - No print files yaml found
2019-12-27 13:50:39,346 - octoprint.plugins.astroprint - INFO - No stored AstroPrint user

If you look on the 5th, you can see I readded the API key

2020-01-05 20:16:40,244 - octoprint.plugins.astroprint - INFO - Logging into AstroPrint
2020-01-05 20:16:40,829 - octoprint.plugins.astroprint - INFO - Getting AstroPrint user info
2020-01-05 20:16:41,399 - octoprint.plugins.astroprint - INFO - AstroPrint User Greg Hesp logged in and saved
2020-01-05 20:16:41,401 - octoprint.plugins.astroprint - INFO - Connecting Box Router
2020-01-05 20:16:41,991 - octoprint.plugins.astroprint - INFO - Boxrouter connected to astroprint service

However a day later, it failed to connect as it seems to have failed to refresh the token? Followed by a load of python errors

2020-01-06 00:17:31,639 - octoprint.plugins.astroprint - INFO - Found stored AstroPrint User: Greg Hesp
2020-01-06 00:17:32,181 - octoprint.plugins.astroprint - ERROR - Unable to refresh token with error [400]
2020-01-06 00:17:32,182 - octoprint.plugins.astroprint - WARNING - Unautorized token, AstroPrint user logged out.
2020-01-06 00:17:32,186 - octoprint.plugins.astroprint - INFO - Getting AstroPrint user info
2020-01-06 00:17:32,186 - octoprint.plugin - ERROR - Error while calling plugin astroprint

That last access recorded in the Astroprint Cloud dashboard was the 6th Jan at 12:49am.

[CoDanny]

Thanks for all this info. We will investigate

[greghesp]

Any joy finding the bug? This seems to happen on a daily basis still

[CoDanny]

We're working on a new version that we expect to release this week.

[greghesp]

Hi, Saw an update for Octoprint this week. Have updated but the plugin lost the API key already and the app says the printer is locked?

[Alfonsopl]

Hi @greghesp , we did an update on octopi plugin and our box router to allow the boxes to connect to a fleet of accounts that belong to this. Unfortunately there was an error in the box router and all the octoprint plugins and astroboxes were disconnected. If you can see that the printer is blocked from your app is because a different account is logged in the plugin, or you have not login it yet. For security reasons with octoprint, we dont let the app control the printer if is not logged the same astroprint account in both sides.

[greghesp]

Hi,

I dont know if that is the issue though, as I was able to view my octoprint instance from the app a few hours ago.

I've only got 1 account. The API key in octoprint is the same API key I took from my account that I logged in with

[Alfonsopl]

Have you ever seen the printer from the application after the plug-in update? The mobile/tablet needs to be in the same network than your octopi, but I'm afraid that won't be the problem. Can you see your printer from astroprint monitor page?

[greghesp]

Yeah, this morning I updated the plugin. Added the API key to the plugin and could see it in the app, and control it etc.

[greghesp]

Here you can see when they connected, and what I now see

[CoDanny]

Could you share your octoprint.log to see if we can see some clues ?

[PM3Delta]

octoprint_AstroprintFailing.log octoprint_AstroprintFailing.log

Love your plugin, but since a week or so I am constantly loosing the API key as well. To reconnect: I delete the device in Astroprint account. Regenerate API key. Enter in Astroprint Plugin. Save. Reboot works but after Shutdown, its gone. Also tried variations of above approach to no avail. Please see today´s log attached where I even needed serveral attempts to reconnect. It has been working great for a month or so ... let me know if you need more info.

[greghesp]

Haven't had chance to get my logs yet, but as with @PM3Delta , I can confirm that it works until shutdown. Every reboot the key is wiped.

[CoDanny]

Thanks @PM3Delta for the logs. We see errors there that will help us narrow the issue

[CoDanny]

In the logs we see this:

2020-02-22 00:11:29,941 - octoprint.plugins.astroprint - ERROR - Error connecting to boxrouter: [Errno -3] Temporary failure in name resolution

This is a local DNS problem and seems to create a chain reaction that uncovered other errors. We have fixed those errors and improved logging a bit to gather more information and we'll be releasing v1.4.1 next week with this.

It appears that local network issues trigger the problem in this thread which explains why most people don't see it. We're still investigating the root cause and how to recover from it so that a temporary network problem doesn't cause this.

@greghesp it would help if you can also send your logs to see if your issue is similar. When you have a chance.

[greghesp]

@CoDanny Here you go. Looks like 404's and maybe some unhandled error when checking the token (Not familiar with how Python logs errors) octoprint.log

[PM3Delta]

Cool. Thank you so much.

[loadedsith]

I'm seeing this issue too. Login/API Connection works fine the first time but is lost on a reboot.

In my browser console I see an unhandled error in packed_plugins.js on line 897:

            self.loginAstroprint = function (accessCode, apAccessKey) {
            // ...
                        if (error.status && error.status == 403){
                            title = gettext("Login falied: Forbidden")
                            text = gettext(error.responseJSON.error_description)
                        // Error: Request to https://192.168.1.206/plugin/astroprint/login returned a 500, 
                        // for which error.responseJSON is undefined, so error.responseJSON.error
                        // is an exception.
                        } else if ( error.responseJSON.error ) {
                            title =  gettext("Login falied: " + error.responseJSON.error)
                            text = gettext(error.responseJSON.error_description)
            // ...

I've not noticed anything in octoprint.log or plugin_pluginmanager_console.log worth mentioning.

But I do see blocked resources in my browser console during the Astroprint login flow, after inserting the API key but before returning to OctoPi for social media logins.

That led me to reduce the amount of adblocking I had enabled for *.astroprint.com, and as of my last reboot, I seem to be ok. Fingers crossed the solution is that easy.

[CoDanny]

@loadedsith What adBlocker are you using and what settings did you have before. Let's see if we can reproduce it here.

[greghesp]

@CoDanny Assuming your plugin folder is /lib/python2.7/site-packages-octoprint_astroprint, I see no octoprint_astroprint.db file as specified here

[CoDanny]

@greghesp Using MySql was given us a lot of problems. This file is no longer in use by the latest versions. We still keep it there for a while so we can migrate older versions when they upgrade.

[greghesp]

@greghesp Using MySql was given us a lot of problems. This file is no longer in use by the latest versions. We still keep it there for a while so we can migrate older versions when they upgrade.

Are you using a yaml file? if so, my user.yaml file says user: null after a reboot. I'll add a user now and see what happens

EDIT: Added my key, yaml file is now populated.

[CoDanny]

Yes, that is what we use. The user is null because it failed to refresh your token. We're still investigating why this happen. You shouldn't edit this file. user is actually an object with token information.

[greghesp]

I wonder if this is specific to Octopi. I've just setup Octoprint in Docker on my PC, and it seems to keep the config file after a reboot

[CoDanny]

We test on OctoPi also and haven't been able to make this happen just yet

[CoDanny]

We have just released a new version (1.4.1) which includes some improved logging as well as some fixes. The root cause for this might not have been fixed but it should give us more information about the problem. Please upgrade your plugin, clear your logs and send post new log files when it happens again.

[loadedsith]

@CoDanny AdBlock Plus(1), and Adblock (2)

1) https://chrome.google.com/webstore/detail/adblock-plus-free-ad-bloc/cfhdojbkjhnklbpkdaibdccddilifddb 2) https://chrome.google.com/webstore/detail/adblock-%E2%80%94-best-ad-blocker/gighmmpiobklfepjocnamgkkbiglidom

Default settings I'm pretty sure.

Unfortunately when I went this morning to ensure that I was logged in to astroprint in octoprint, I was not.

[PM3Delta]

Ok. Just a quick heads-up. 1.4.1. installed … not yet restarted yet. iOS App works.

However experiencing the following, when logging into Astroprint account from my PC within my local network, after showing the printer it seems to disconnect as soon as I click on Control... not critical since logging into it from Home isnt the main usecase, but I thought I led you know.

As soon as the current print finishes I restart and see if it keeps the API key.

Thanks again for your quick response to the problem.

[martinbogo]

I have installed 1.4.1 ... will run it for a while and see if the API key is lost.

[CoDanny]

It appears that we have found the issue and issued a fix on v1.4.2.

For those who are curious this was caused by bad system time in OctoPi. The clock was going back in some restarts tricking the plugin into thinking that an expired token was still valid. This caused unauthorized errors when using the token which resulted in the user being logged out.

The new version refreshes the token on every new boot thus setting the baseline time to whatever it is at the time of boot.

It appears that the system clock is unreliable in OctoPi.

I'm going to close the issue now. We can re-open if people with 1.4.2 still see this.

[martinbogo]

Will update to 1.4.2 and verify.

On Tue, Feb 25, 2020 at 9:14 AM Daniel Arroyo notifications@github.com wrote:

Closed #79 https://github.com/AstroPrint/OctoPrint-AstroPrint/issues/79.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/AstroPrint/OctoPrint-AstroPrint/issues/79?email_source=notifications&email_token=AAB5KKKNVYDWDHN5XVTJF3DREUYWDA5CNFSM4KE6Z7FKYY3PNVWWK3TUL52HS4DFWZEXG43VMVCXMZLOORHG65DJMZUWGYLUNFXW5KTDN5WW2ZLOORPWSZGOW35GESQ#event-3069862474, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAB5KKJRS7YPJVQGN6YMVLTREUYWDANCNFSM4KE6Z7FA .

[PM3Delta]

Hi guys. Thank you so much… I was just downloading my log so could forward it, when I got the not that you had it fixed. 1.4.2. is already on and running. I´ll keep you posted. Again, thanx a bunch.

[PM3Delta]

Please reopen. octoprint25022020.log Hey guys…. sorry to say …. key lost again after restart. It worked after the first cold start, but didnt after the second one. Please find attached the log, maybe you can read something out of it. Thx.

[CoDanny]

@PM3Delta This isn't the same at all. You're having DNS issues. Your token failed to refresh because you couldn't reach our servers to do it. Some issues with your ISP. Perhaps try configure Google DNS servers, they're usually more stable than those of most ISPs.

https://developers.google.com/speed/public-dns/docs/using

Your log has these errors towards the end: [Errno -3] Temporary failure in name resolution'

[loadedsith]

Having just troubleshoot DNS on a separate Pi I can tell you with confidence: it is possible for the time to be wrong and for that to impact authentication. I didn't, however, see the error in the timestamps:

2020-02-25 20:04:45,908 - octoprint.server - INFO - Shutting down...
2020-02-25 20:04:46,245 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2020-02-25 20:04:46,246 - octoprint.events - INFO - Event loop shut down
2020-02-25 20:04:46,281 - octoprint.plugins.HeaterTimeout - INFO - Shutting down...
2020-02-25 20:04:46,287 - octoprint.server - INFO - Goodbye!
2020-02-25 20:04:56,917 - octoprint.startup - INFO - ******************************************************************************
2020-02-25 20:04:56,918 - octoprint.startup - INFO - Starting OctoPrint 1.3.12
2020-02-25 20:04:56,918 - octoprint.startup - INFO - ******************************************************************************

Shows 10 seconds elapsed for a reboot, which checks out to me. If this was a DNS/timing error, I'd have expected the time stamps to appear out of chronological order (or to be very wrong).

PS: If you posted a full log here, it's a good time to regenerate your API keys (Astroprint and Octoprint).

[CoDanny]

@loadedsith not sure what you mean. The date problem was from another user's log which clearly showed the time going BACK over 30 mins between reboots. Are you saying that you still have the problem with v1.4.2? If so, please upload your log file

@PM3Delta has DNS problems clearly reported as such in the last few interactions with astroprint in his log.

[loadedsith]

@CoDanny Totally. I'm just saying that DNS issues caused by incorrect times on Raspberry Pi's are a real issue. But that this log doesn't show that to be the problem: the clock doesn't fail during the reboot where @PM3Delta lost his auth.

I'll update you with my own logs/experience asap, as I'm away from my printer.

[loadedsith]

I'm happy to report that nothing I've tried has caused me to become disconnected from Astroprint. I will let you know if that changes.

Thanks for your timely replies and quick action!

[PM3Delta]

@CoDanny Hi thanks for looking into it. It is just strange that it worked for weeks before 1.4.0 and now it doesn’t. Is it necessary to loose the API key from memory just because due to a DNS problem your servers can’t be reached temporarily? I am not computer savvy enough but my wife was watching Netflix and I had been surfing the net without problems. Thx.

[CoDanny]

@loadedsith It could also a be a DNS problem specific to the Raspberry Pi. We do need to refresh access tokens and there are multiple retries before the software gives up. Have you tried installing ntp on your pi, to keep the date accurate?

[PM3Delta]

hi guys… I have switched to google dns … still losing API. I am deinstalling Astroprint for now - sorry. Be happy to try again if it is more stable. Internet is over 75Mbits and <5ms ping.. actually even better ping with ISP DNS.

[CoDanny]

@PM3Delta do you have a PiHole or some adblocker that might interfere with the DNS on your network? If you do, you can try adding astroprint.com, boxrouter.astroprint.com and api.astroprint.com to their whitelist domains.

[PM3Delta]

No I don’t. I only have the typical few plugins installed. Printer Eeprom manager, Bosrd Flash, Avrdude, LayerDisplay, Dashboard, ... The Pi connects nicely with the Octroprint plugin repository which is also via Internet.

[PM3Delta]

It is just strange that it worked flawlessly the weeks before 1.4.0. The annoying part is that one has to reenter the API everytime it has (temporary) connection problems. Can’t you just write the key to memory so it is not lost upon next startup?

[greghesp]

That's not how oauth works 😁

In Octopi, there's an internet connection tab where you can change the DNS servers. What are they set to?

[PM3Delta]

I am not sure I understand exactly what Tab you mean. I am aware of the Test tab where on can check network availability. Here Octopi pings the google dns servers. Which works fine. Secondly I am aware of the /etc/resolv.conf, which points to my routers IP adress, which gets the DNS from my ISP (or as tried yesterday from google DNS). All my other ca 10 devices in the networks also point to my router and enjoy a quick and stable internet connection (2 PCs, 1 PlayStation, 2 Netflix TVs, 5 iOS devices ...), the PI itself to the PlugIn repository. Please let me know if you refer to another Tab which I might not be aware of and I can check. Currently AstroPrint is deinstalled.

[greghesp]

octoprint.log I think this may still be bugged. I checked my printer the other day to find no key, unsure if that was since the 1.4 update to octoprint though.

Regardless, I added my key back in but now it's saying it's locked?

Edit: just checked the plugin, key has been lost again. Will get the logs..