New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[1.3.10rc2] Forcelogin interferes with websocket messages sent by plugins right on UI load #2898

Closed
devildant opened this Issue Nov 16, 2018 · 26 comments

Comments

4 participants
@devildant

devildant commented Nov 16, 2018

What were you doing?

just logged in to octoprint, all the plugin are blocked on the main page

What did you expect to happen?

see the checkbox check for the plugin or specifique status

What happened instead?

nothing the plugins status on main page is not update

Did the same happen when running OctoPrint in safe mode?

Version of OctoPrint

1.3.10RC2

Operating System running OctoPrint

Printer model & used firmware incl. version

Browser and version of browser, operating system running browser

LAST CHROME, and safari on ios

Link to octoprint.log

2018-11-16 14:16:03,188 - octoprint.plugins.navbartemp - INFO - Checking SoC internal temperature
2018-11-16 14:16:18,812 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.10
2018-11-16 14:16:20,496 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.10
2018-11-16 14:16:22,082 - octoprint.plugins.sdswitchfastcopy - INFO - test mount OK
2018-11-16 14:16:22,876 - octoprint.plugins.sdswitchfastcopy - INFO - test mount OK
2018-11-16 14:16:25,693 - octoprint.server.util.sockjs - INFO - User devildant logged in on the socket from client ::ffff:192.168.1.10

Link to contents of terminal tab or serial.log

Link to contents of Javascript console in the browser

Starting dependency resolution...
packed_core.js?d307d348:15581 ... dependency resolution done
packed_core.js?d307d348:15885 Initial application setup done, connecting to server...
packed_core.js?d307d348:13640 Connected to the server
packed_core.js?d307d348:15863 Finalizing application startup
packed_core.js?d307d348:15747 Going to bind 41 view models...
packed_core.js?d307d348:15800 Did not bind view model TrackingViewModel to target #wizard_plugin_tracking since it does not exist
packed_plugins.js?8758b863:8203 checking 192.168.1.43
packed_core.js?d307d348:15800 Did not bind view model CuraViewModel to target #wizard_plugin_cura since it does not exist
packed_core.js?d307d348:15800 Did not bind view model SoftwareUpdateViewModel to target #softwareupdate_confirmation_dialog since it does not exist
packed_core.js?d307d348:15800 Did not bind view model SoftwareUpdateViewModel to target #wizard_plugin_softwareupdate since it does not exist
packed_core.js?d307d348:2409 User devildant logged in
packed_core.js?d307d348:15839 ... binding done
packed_plugins.js?8758b863:7340 check status
packed_core.js?d307d348:15859 Application startup complete
packed_core.js?d307d348:11122 ConfiguredLoggers has not changed. Not saving.

Screenshot(s)/video(s) showing the problem:

I have read the FAQ.

@foosel

This comment has been minimized.

Owner

foosel commented Nov 16, 2018

just logged in to octoprint, all the plugin are blocked on the main page
[...]
see the checkbox check for the plugin or specifique status
[...]
nothing the plugins status on main page is not update

I don't understand what you are talking about. What does "all the plugins are blocked on the main page" mean? What checkbox check? What plugin status on what main page? Please clarify and provide screenshots. Also: full octoprint.log, no snippets please.

Did the same happen when running OctoPrint in safe mode?

Need that info.

Operating System running OctoPrint

Need that too.

LAST CHROME, and safari on ios

Please give me version numbers, not "latest" - latest can change at any given moment.

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

capture

@foosel

This comment has been minimized.

Owner

foosel commented Nov 16, 2018

Where can I find these plugins to test myself?

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

you can test with shutdown printer (sd switch is still in development :))

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

i have the same result with tplink plugin, or automatique shutdown....
the ajax calls is well done but nothing is updated, i don't understand.
I am the developer of "shutdown printer", so I can make changes if necessary

@foosel

This comment has been minimized.

Owner

foosel commented Nov 16, 2018

I cannot reproduce this with shutdown printer currently. Checkbox gets populated. In general not a good way though to send settings via the push socket - that's for real time data, not for settings. Still, getting through fine here.

Can you try disabling the force login plugin (it's bundled)? I'd like to know if disabling this fixes the issue for you.

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

yes, if I disable the forced login plugin, everything works

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

Thank you for your help :)
(sorry if i'm not clear sometimes. I'm not good in english)

@foosel

This comment has been minimized.

Owner

foosel commented Nov 16, 2018

All good :)

I think I have an idea what's going on here. The problem is that the plugin fires off a plugin message before the socket is authenticated. With the force login plugin disabled that doesn't matter, but if it is enabled it swallows up any messages until things are authenticated. I'll look into solving this - while it would be better if the plugin actually utilized the REST API for fetching the data in question here instead of triggering a shove of the data down the socket via REST, it is still a compatibility issue with plugins that do that and hence should be tackled.

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

ok, i am changing my plugins:) although some will need real time, but well after authentication.
the concern is the other plugins, there are many who use this method: p

@foosel

This comment has been minimized.

Owner

foosel commented Nov 16, 2018

the concern is the other plugins, there are many who use this method: p

which is why I'm looking into this. The problem is that I cannot reliably reproduce the issue yet (seems to be a race condition too), so testing the fix will be a bit tricky.

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

I can give you the plugins I use, together it produces the problem at home
tplink plugin
enclosure plugin
shutdownprinter plugin
navbar temperature plugin
automatic shutdown plugin
I have other plugin but these affect the main page

@devildant

This comment has been minimized.

devildant commented Nov 16, 2018

do you want me to wait before fixing my "shutdown printer" plugin?

@jneilliii

This comment has been minimized.

jneilliii commented Nov 16, 2018

Since one of those is my plugin I was curious if I'm not doing things right @foosel. I haven't seen any issues with the RC with them, but haven't specifically looked yet.

@foosel

This comment has been minimized.

Owner

foosel commented Nov 19, 2018

do you want me to wait before fixing my "shutdown printer" plugin?

yes

Since one of those is my plugin I was curious if I'm not doing things right @foosel.

I've so far only looked at the shutdown printer one from @devildant. The thing there is that the checkbox state gets pushed via the websocket instead of as part of a REST response during the startup of the UI. With the forcelogin plugin depending on the order of callback execution it could happen that said socket message gets eaten when the user isn't yet authed on the socket since so far the plugin didn't create a backlog of blocked messages. I'll be changing that in RC3 though. The problem is that right now it doesn't seem to solve the issue with the checkbox not populating in the plugin, so I'm debugging...

@devildant

This comment has been minimized.

devildant commented Nov 19, 2018

@foosel as needed, I can test :)

foosel added a commit that referenced this issue Nov 19, 2018

foosel added a commit that referenced this issue Nov 19, 2018

@foosel

This comment has been minimized.

Owner

foosel commented Nov 19, 2018

So I just added two commits to the staging/maintenance branch that fix the problem at least for Shutdown Printer. I actually had two issues (hence two commits) caused by the introduction of Forcelogin, the other was that the server side socket object didn't even register itself with the plugin subsystem as message forwarder if no auth had yet been received on the socket, this is now fixed as well.

To an observer it should now basically behave as before, even with forcelogin enabled. Messages will be go out on the socket in the order they were sent. If forcelogin is enabled a message backlog of max. 100 items will make sure that any messages sent (by plugins, core won't send anything yet) before the user has authed on the socket will just be delayed.

@devildant if you want to checkout staging/maintenance and give this a whirl, that would be great.

@foosel foosel changed the title from no status plugins on main view 1.3.10RC2 to [1.3.10rc2] Forcelogin interferes with websocket messages sent by plugins right on UI load Nov 19, 2018

@devildant

This comment has been minimized.

devildant commented Nov 19, 2018

@foosel I test this, tonight, as soon as I arrive at home: p

@devildant

This comment has been minimized.

devildant commented Nov 19, 2018

Re @foosel , I tested the staging / branch maintenance, for my plugin, it works, but I still have problems with the plugin tplink.
the state of the plug is not up to date (it is held in the ON position when the plug is off).
normally we use a similar technique it seems to me, it should work.
One thing I do not understand is that the problem seems to occur if multiple plugins use the WebSocket (at page load).
separately, it seems to work

@foosel

This comment has been minimized.

Owner

foosel commented Nov 19, 2018

Taking a look at the TP Smartplug plugin then. This abuse of the socket as a back channel when a perfectly fine REST request context is available and hence a regular HTTP response could just be sent really has to stop though ;)

Actually thinking about how to detect this and log about this code smell :P

@devildant

This comment has been minimized.

devildant commented Nov 19, 2018

yes i see.
after I admit that it is tempting to use the websocket it avoids polling :p
on my side I fixed my two plugin, I use the websocket only when the realtime is necessary (during updates via API, or when it is information recovered server side)
I do not have push yet for shutdown printer, if you still want to test.
I remain available for tests, I run just a little print of 1 day tonight: p

@foosel

This comment has been minimized.

Owner

foosel commented Nov 19, 2018

@devildant

I admit that it is tempting to use the websocket it avoids polling :p

Yes, but if you have a request on startup anyhow, it's just wrong on so many levels to not actually reply to that request but instead push the response to every connected client via the socket - which is what is happening here.


short mini rant incoming

General rule of thumb: If you want to query data from the frontend, use REST. If you need to push data to the frontend when you don't have a request running, or want to trigger the frontend to do some request you use the socket. Do not use the socket as a replacement back channel for REST requests. Not only does that lead to a non functional API on your end that makes it incredibly difficult for third party clients to integrate with your plugins, it's also horribly to debug and way more fragile than just using the API for what it was made.

Also: Don't send commands to query data, that's what the GET endpoint is for. Commands on the SimpleApi should only be used for things that change state (e.g. to toggle some switch, abort an auto shutdown, ...), if you need to query data use the GET endpoint and do not modify internal state when replying to it.

that's it, you can open your eyes again


RE that TPLink issue, can confirm, seems to be a bug in the frontend component of the plugin though - the "off" state gets pushed through the socket just fine, the icon briefly switches to red, then immediately switches back. I haven't yet found the source for this switch back but my money would be with the view model having a bug. Speaking of which...

@jneilliii as I just went through your code to try to figure out why that happens, you have a couple of issues in your viewmodel. If you declare something as observable, you need to make 100% sure to never compare it but rather the result of calling it (e.g. not plug.emeter != data.emeter but rather plug.emeter() != data.emeter or even better plug.emeter() !== data.emeter to avoid JS's attempts at type conversion). Also you never must set it but rather call it with the value to set (e.g. not plug.emeter = data.emeter but rather plug.emeter(data.emeter)). Otherwise you'll kill the observable, or compare a value with the function that is the observable, not the value stored in the observable.

edit And internal state (e.g. something like the current switch state or power consumption or whatnot) really doesn't belong in config.yaml 😲

That is btw also the reason why the icon switches right back to "on". A settings update is received (not yet sure why, but irrelevant), the settings contain the "on" state that is stored in config.yaml (do not do this, it's a dynamic state, you should be retrieving stuff like that via your own GET endpoint, not via the settings API!), and thus the current "off" state received from the socket is overwritten again with the stale data in the settings right away. So.. bug in TPLink, unrelated to this ticket.

@jneilliii

This comment has been minimized.

jneilliii commented Nov 19, 2018

Thanks @foosel. I've been trying to transition the state out of settings, just haven't had the time to do so. The other part you mention about observables relative to comparing and setting was initially done the way you mention but the knockout started complaining about it not being a function and couldn't bind the view model.

@jneilliii

This comment has been minimized.

jneilliii commented Nov 20, 2018

Figured out the not a function error. It was because the item.emeter is an object, had to iterate over the keys to get down to the functions.

Thinking about the logic further though it makes sense to use the websocket to send current status so that all clients get updated not just the person toggling the device right? Websocket notifies all connected while API GET only notifies one? So makes sense to use API GET for initial load, and socket for subsequent updates.

@foosel

This comment has been minimized.

Owner

foosel commented Nov 20, 2018

So makes sense to use API GET for initial load, and socket for subsequent updates.

Exactly. At least if you are doing an GET request anyhow and hence have a "free" back channel. Or - depending on message size - it can also make sense to have a message on the socket trigger a GET request, this if for example how the SettingsUpdate handling works in OctoPrint.

@foosel

This comment has been minimized.

Owner

foosel commented Nov 28, 2018

1.3.10rc3 was just released.

@foosel foosel closed this Nov 28, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment