Re-initialise binding

Is there any way to re-initialise a binding from withing the binding code to simulate a restart of the binding?

I’m debugging a situation where I’m struggling to find out why the communication with an API fails after some time, probably related to token expiration. Restart of the binding resolves the situation.

BR,

/Janne

Restart the whole binding or a thing? For a thing you can call dispose();initialize();.

For the whole binding it is probably easier to use the bundle:restart command on the karaf console.

Restart the whole binding or a thing? For a thing you can call dispose();initialize(); .

I have a bridge that handles the API communication and a thing that models my device. The bridge implements the API communication, I’ve tried to call dispose();initialize(); on the bridge handler but for some unknown reason the re-login fails. If I do a manual restart of the binding from the karaf console the bridge manages to login again.

For the whole binding it is probably easier to use the bundle:restart command on the karaf console.

That’s what I’ve been doing but I want to be able to to that from within the binding code, not manually from the karaf console.

What I really wanna do is to understand why dispose();initialize(); does not work but until that happens a w.o. would be nice to have :slight_smile:

If you show the code someone might be able to help you.

That would be awesome! :slight_smile:
VW We Connect binding.

Looks good so far. What exactly is not working? Where does the re-connect fail and what is the error message?

As a part of the binding refresh I query the API for get-fully-loaded-cars that should return a JSON and an errorCode set to 0, but after a day or so it suddenly returns errorCode 2 and an empty JSON, unfortunately I do not now what errorCode 2 means in that case, but I will not resolve itself by just continuing with the refresh, and the next refresh will experience the same error code.

But if I then do a restart of the binding from the Karaf console, the login/refresh will start to work again.

The logs when this happens looks like below:

2020-02-29 20:11:54.105 [DEBUG] [econnect.internal.VWWeConnectSession] - VWWeConnectSession:updateStatus
2020-02-29 20:11:56.106 [DEBUG] [econnect.internal.VWWeConnectSession] - postJSONVWWeConnectAPI URL: https://www.portal.volkswagen-we.com/portal/delegate/dashboard/WVGYYZ6JZLL8767882/-/mainnavigation/get-fully-loaded-cars Fields: null Referer: https://www.portal.volkswagen-we.com/portal/delegate/dashboard/WVGYYZ6JZLL8767882 XCSRF:L2zUdcRh
2020-02-29 20:11:56.108 [DEBUG] [econnect.internal.VWWeConnectSession] - HTTP POST Request HttpRequest[POST /portal/delegate/dashboard/WVGYYZ6JZLL8767882/-/mainnavigation/get-fully-loaded-cars HTTP/1.1]@1b506f3.
2020-02-29 20:11:56.540 [TRACE] [econnect.internal.VWWeConnectSession] - HTTP Response (200) Body:{"errorCode":"2"}
2020-02-29 20:11:56.542 [DEBUG] [econnect.internal.VWWeConnectSession] - ErrorCode: 2
2020-02-29 20:11:56.546 [WARN ] [econnect.internal.VWWeConnectSession] - Failed to get fully loaded cars.
2020-02-29 20:11:56.547 [WARN ] [econnect.internal.VWWeConnectSession] - No Fully loaded vehicle(s) found on VW We Connect portal! JSON: null
2020-02-29 20:11:56.551 [WARN ] [nal.handler.VWWeConnectBridgeHandler] - Refresh failed!
2020-02-29 20:11:56.551 [DEBUG] [.internal.handler.VWWeConnectHandler] - bridgeStatusChanged bridgeStatusInfo: OFFLINE (COMMUNICATION_ERROR)
2020-02-29 20:21:56.921 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - VWWeConnectBridgeHandler - Refresh thread is up'n running! job: java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@12baac5
2020-02-29 20:21:56.923 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - VWWeConnectBridgeHandler - Refresh thread session is null, let's re-initialize!
2020-02-29 20:21:56.924 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Handler is disposed.
2020-02-29 20:21:56.925 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Stop automatic refresh for job java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@12baac5
2020-02-29 20:21:56.927 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Stop immediate refresh for job null
2020-02-29 20:21:56.928 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Initializing VWWeConnect Bridge
2020-02-29 20:21:56.934 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Start automatic refresh null
2020-02-29 20:21:56.935 [DEBUG] [.internal.handler.VWWeConnectHandler] - bridgeStatusChanged bridgeStatusInfo: UNKNOWN
2020-02-29 20:21:56.936 [TRACE] [nal.handler.VWWeConnectBridgeHandler] - refreshJobLock is locked
2020-02-29 20:21:56.937 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Scheduling at fixed delay refreshjob java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@1aa7749
2020-02-29 20:21:56.938 [TRACE] [nal.handler.VWWeConnectBridgeHandler] - refreshJobLock is unlocked
2020-02-29 20:21:56.952 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - Session is null, config change probably, then let's create a new one
2020-02-29 20:21:56.954 [DEBUG] [econnect.internal.VWWeConnectSession] - VWWeConnectSession:initialize
2020-02-29 20:21:56.956 [DEBUG] [nal.handler.VWWeConnectBridgeHandler] - VWWeConnectBridgeHandler - Refresh thread is up'n running! job: java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@1aa7749
2020-02-29 20:21:56.957 [DEBUG] [econnect.internal.VWWeConnectSession] - VWWeConnectSession:refresh
2020-02-29 20:21:56.959 [INFO ] [econnect.internal.VWWeConnectSession] - Attempting to log in to https://www.portal.volkswagen-we.com
2020-02-29 20:21:56.960 [DEBUG] [econnect.internal.VWWeConnectSession] - Login URL: https://www.portal.volkswagen-we.com//portal/en_GB/web/guest/home
2020-02-29 20:21:56.962 [DEBUG] [econnect.internal.VWWeConnectSession] - getVWWeConnectAPI: https://www.portal.volkswagen-we.com//portal/en_GB/web/guest/home
2020-02-29 20:21:57.444 [TRACE] [econnect.internal.VWWeConnectSession] - HTTP Response (302) Body:
2020-02-29 20:21:57.446 [DEBUG] [econnect.internal.VWWeConnectSession] - Failed to login, HTTP status code: 302
2020-02-29 20:21:57.447 [DEBUG] [econnect.internal.VWWeConnectSession] - Redirection to: https://www.portal.volkswagen-we.com/portal/sv_SE/web/guest/home
2020-02-29 20:21:57.447 [DEBUG] [econnect.internal.VWWeConnectSession] - getVWWeConnectAPI: https://www.portal.volkswagen-we.com/portal/sv_SE/web/guest/home
2020-02-29 20:21:57.506 [TRACE] [econnect.internal.VWWeConnectSession] - HTTP Response (302) Body:
2020-02-29 20:21:57.508 [DEBUG] [econnect.internal.VWWeConnectSession] - Failed to login, HTTP status code: 302
2020-02-29 20:21:57.509 [DEBUG] [econnect.internal.VWWeConnectSession] - Redirection to: https://www.portal.volkswagen-we.com/portal/delegate/dashboard/WVGYYZ6JZLL8767882
2020-02-29 20:21:57.510 [DEBUG] [econnect.internal.VWWeConnectSession] - getVWWeConnectAPI URL: https://www.portal.volkswagen-we.com/portal/delegate/dashboard/WVGYYZ6JZLL8767882 headers: true
2020-02-29 20:21:57.511 [DEBUG] [econnect.internal.VWWeConnectSession] - Encoded URL: https://www.portal.volkswagen-we.com/portal/delegate/dashboard/WVGYYZ6JZLL8767882
2020-02-29 20:21:57.515 [DEBUG] [econnect.internal.VWWeConnectSession] - HTTP GET Request HttpRequest[GET /portal/delegate/dashboard/WVGYYZ6JZLL8767882 HTTP/1.1]@ceecfe.
2020-02-29 20:21:57.737 [TRACE] [econnect.internal.VWWeConnectSession] - HTTP Response (200) Body:

What I have discovered is when I try to login again from within the binding, I will get another behaviour in the login sequence compared to when I do a manual binding restart.

Login sequence after binding restart:

  1. Request english landing page
  2. Get a 302 to local landing page (in my case swedish site)
  3. Request local landing page
  4. Get a 200 OK and parse csrf
  5. Request login URL using csrf
  6. Get a 200 OK and parse login URL
  7. Request login

Login sequence when binding tries to re.login after getting errorCode 2::slight_smile:

  1. Request english landing page
  2. Get a 302 to local landing page (in my case swedish site)
  3. Request local landing page
  4. Get a 302 to /portal/delegate/dashboard/WVGYYZ6JZLL8767882which is the start page that gives the impression that the session is still logged in

Since the API is reverse enginered it is not so easy to figure out what goes wrong. :frowning:

I’m trying to debug a failure in my binding poll aswell and I wonder if it’s related as I get no errors at all from my binding.
Do you happen to get any openhabcloud disconnects when your binding fails?
So far with the help of a couple of beta testers it’s not the binding itself closing the connection as it kills anything that is currently in the middle of a poll.
There is some form of bug with the core or httputil that doesn’t recover but I haven’t had time to fully investigate yet.

I didn’t check the code but from description, logs and how service behaves it seems to be expiry of access token. From what you wrote about different sequences during second login this might be due to SSO cookie set by VW ID which is retained by your browser.

But this is my rough guess. Are you using OAuth 2?

Best,
Łukasz

it seems to be expiry of access token.

That is what I think too.

From what you wrote about different sequences during second login this might be due to SSO cookie set by VW ID which is retained by your browser.

Thanks for the tip! :slight_smile: That gives me an idea that will test, one thing that differs compared a manual restart of the binding is that the httpClient is recreated. I will add a stop/start of the HttpClient instance in my binding recovery sequence and see if that helps.

No, it has nothing to do with openhabcloud.

I tried stop/start on the HttpClient but that did not do it, now I changed to actually re-creating a new instance of HttpClient and that looks promising so far.

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.