thor0215 / hassio-xfinity-usage

Fetch Xfinity Internet Service Usage Data and publish it to Home Assistant sensor
Apache License 2.0
11 stars 3 forks source link

Stuck in login loop - high resource usage #9

Closed tankdeer closed 5 months ago

tankdeer commented 5 months ago

At some point I noticed my HA system was sluggish, and realized it was due to extremely high resource usage. After some debugging, I determined this addon was the cause.

The root of the issue appears to be us getting stuck in a login loop. I suspect Xfinity may have changed something on their end? In either case, the addon is not handling it gracefully. Below is the log from a fresh start of the addon with debug logging enabled. You'll see that it just keeps trying to enter the username. This login loop will go indefinitely. Note that this account does not have 2FA enabled & I can log into it manually without issue.

-----------------------------------------------------------
 Add-on: Xfinity Internet Usage
 Get Xfinity Internet Usage Data
-----------------------------------------------------------
 Add-on version: 0.0.8
 You are running the latest version of this add-on.
System: Home Assistant OS 12.3  (amd64 / generic-x86-64)
 Home Assistant Core: 2024.5.5
 Home Assistant Supervisor: 2024.05.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service base-addon-banner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service base-addon-timezone: starting
s6-rc: info: service base-addon-log-level: starting
s6-rc: info: service fix-attrs successfully started
[09:42:27] INFO: Configuring timezone (America/Los_Angeles)...
s6-rc: info: service base-addon-log-level successfully started
s6-rc: info: service base-addon-timezone successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
Python 3.10.12
Package            Version
------------------ -------------
blinker            1.4
certifi            2024.2.2
charset-normalizer 3.3.2
cryptography       3.4.8
dbus-python        1.2.18
distro             1.7.0
greenlet           2.0.2
httplib2           0.20.2
idna               3.7
importlib-metadata 4.6.4
jeepney            0.7.1
keyring            23.5.0
launchpadlib       1.10.16
lazr.restfulclient 0.14.4
lazr.uri           1.0.6
more-itertools     8.10.0
oauthlib           3.2.0
pip                24.0
playwright         1.34.0
pyee               9.0.4
PyGObject          3.42.1
PyJWT              2.3.0
pyparsing          2.4.7
python-apt         2.4.0+ubuntu3
requests           2.31.0
SecretStorage      3.3.1
setuptools         59.6.0
six                1.16.0
tenacity           8.2.3
typing_extensions  4.11.0
urllib3            2.2.1
wadllib            1.3.6
wheel              0.37.1
zipp               1.0.0
total 12
drwxr-xr-x 2 root root 4096 May  7 14:59 .
drwxr-xr-x 1 root root 4096 Jun  4 09:42 ..
-rw-r--r-- 1 root root 1154 Jun  3 04:17 .sensor-backup
2024-06-04T09:42:28 DEBUG: __BASHIO_LIB_DIR: /usr/lib/bashio
2024-06-04T09:42:28 DEBUG: PYTHONUNBUFFERED: 1
2024-06-04T09:42:28 DEBUG: S6_BEHAVIOUR_IF_STAGE2_FAILS: 2
2024-06-04T09:42:28 DEBUG: HOSTNAME: 989f231b-xfinity-usage
2024-06-04T09:42:28 DEBUG: POLLING_RATE: 3600
2024-06-04T09:42:28 DEBUG: S6_CMD_WAIT_FOR_SERVICES_MAXTIME: 0
2024-06-04T09:42:28 DEBUG: PAGE_TIMEOUT: 45
2024-06-04T09:42:28 DEBUG: BASHIO_SUPERVISOR_API: http://supervisor
2024-06-04T09:42:28 DEBUG: PWD: /
2024-06-04T09:42:28 DEBUG: CARGO_NET_GIT_FETCH_WITH_CLI: true
2024-06-04T09:42:28 DEBUG: BASHIO_SUPERVISOR_TOKEN: a9a86fa77d8f5b27667458209509c2b09de937fe755b9ec32ad61f3871acf4ebc24031dc14a62e574ab03e4e99ed159c0a8be8f2246b52a3
2024-06-04T09:42:28 DEBUG: YARN_HTTP_TIMEOUT: 1000000
2024-06-04T09:42:28 DEBUG: TZ: America/Los_Angeles
2024-06-04T09:42:28 DEBUG: HOME: /root
2024-06-04T09:42:28 DEBUG: XFINITY_USERNAME: [REDACTED]
2024-06-04T09:42:28 DEBUG: LANG: C.UTF-8
2024-06-04T09:42:28 DEBUG: __BASHIO_BIN: /usr/lib/bashio/bashio
2024-06-04T09:42:28 DEBUG: PIP_PREFER_BINARY: 1
2024-06-04T09:42:28 DEBUG: XFINITY_PASSWORD: [REDACTED]
2024-06-04T09:42:28 DEBUG: HASSIO_TOKEN: a9a86fa77d8f5b27667458209509c2b09de937fe755b9ec32ad61f3871acf4ebc24031dc14a62e574ab03e4e99ed159c0a8be8f2246b52a3
2024-06-04T09:42:28 DEBUG: TERM: xterm-256color
2024-06-04T09:42:28 DEBUG: PIP_DISABLE_PIP_VERSION_CHECK: 1
2024-06-04T09:42:28 DEBUG: SUPERVISOR_TOKEN: a9a86fa77d8f5b27667458209509c2b09de937fe755b9ec32ad61f3871acf4ebc24031dc14a62e574ab03e4e99ed159c0a8be8f2246b52a3
2024-06-04T09:42:28 DEBUG: SHLVL: 1
2024-06-04T09:42:28 DEBUG: PYTHONDONTWRITEBYTECODE: 1
2024-06-04T09:42:28 DEBUG: PATH: /command:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
2024-06-04T09:42:28 DEBUG: S6_CMD_WAIT_FOR_SERVICES: 1
2024-06-04T09:42:28 DEBUG: PIP_NO_CACHE_DIR: 1
2024-06-04T09:42:28 DEBUG: DEBIAN_FRONTEND: noninteractive
2024-06-04T09:42:28 DEBUG: LOGLEVEL: debug
2024-06-04T09:42:28 DEBUG: _: /usr/bin/python3
2024-06-04T09:42:28 INFO: Xfinity Internet Usage Starting
2024-06-04T09:42:28 DEBUG: Using selector: EpollSelector
2024-06-04T09:42:28 INFO: Updating Sensor: sensor.xfinity_usage
2024-06-04T09:42:28 DEBUG: Starting new HTTP connection (1): supervisor:80
2024-06-04T09:42:28 DEBUG: http://supervisor:80 "POST /core/api/states/sensor.xfinity_usage HTTP/1.1" 200 1365
2024-06-04T09:42:31 INFO: Loading Internet Usage (URL: https://customer.xfinity.com/#/devices#usage)
2024-06-04T09:42:37 DEBUG: Finished loading page (URL: https://login.xfinity.com/login?c_ds_na=c_ds_na%2Cc_ds_no%2Cc_ds_ts%2Cclient_id%2Ccontinue%2CforceAuthn%2Cr%2CreqId%2Cs&c_ds_no=7F1C9BCE056AEF761A66EBF3D7222E47&c_ds_ts=1717519355&c_ds_val=F52702F6FA6FC297B0037FC625BDE7F91BE4B3F0CAFC036FFC505CB0B043019B&client_id=my-account-web&continue=https%3A%2F%2Foauth.xfinity.com%2F%2Foauth%2Fauthorize%3Fclient_id%3Dmy-account-web%26prompt%3Dlogin%26redirect_uri%3Dhttps%253A%252F%252Fcustomer.xfinity.com%252Foauth%252Fcallback%26response_type%3Dcode%26state%3Dhttps%253A%252F%252Fcustomer.xfinity.com%252F%2523%252Fdevices%2523usage%26response%3D1%26reqId%3D634b8dd2-d145-429a-ade2-3fa0fed83f14&forceAuthn=1&r=comcast.net&reqId=488d4776-f66e-4318-99e9-26611abdd996&s=oauth)
2024-06-04T09:42:37 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:40 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:40 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:42 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:42 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:45 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:45 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:47 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:47 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:50 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:50 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:52 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:52 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:54 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:54 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:57 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:57 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:42:59 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:42:59 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:43:01 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:43:01 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:43:04 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:43:04 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T09:43:06 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T09:43:06 INFO: Entering username (URL: https://login.xfinity.com/login)

The bigger issue is that as this loop continues, it slowly eats up all my system resources, including several times forcing a reboot. This all appeared to start at ~5:15AM Pacific Time, yesterday, which is what makes me suspect they changed something on behind the scenes on the login page and pushed it around that time - nothing else has changed on my end. This might be a little tough to read, but you can see around that time memory (followed naturally by swap) & CPU usage start to climb, and the CPU temp shoots up too. Then there are sudden drops (crashes of either HA or a full reboot) & the cycle repeats.

image

The dip around 8:30AM today was when I realized the cause and stopped the addon. Then I restarted it and everything started to climb again.

The way I see it there are a couple of related issues here:

  1. Xfinity login stopped working, no data received, infinite loop
  2. Infinite loop slowly consumes all available memory & swap space of the host, until the host crashes
  3. Docker container should probably have a memory limit set to prevent future issues from crashing the host
tankdeer commented 5 months ago

Funny enough, after opening this there appears to be a slight change in behavior. We are still stuck in a loop trying to log in, but it's no longer entering the username over and over. Presumably it never gets that far:

2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T11:55:55 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)

The side effect being that it's no longer using a ton of resources, but of course still doesn't help in retrieving any data. image

tankdeer commented 5 months ago

Ok, one more. As a test I restarted the addon again, and it went back to the first pattern - trying to populate the username and eating all the memory on the host.

2024-06-04T14:25:56 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:25:56 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:25:58 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:25:58 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:01 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:01 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:04 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:04 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:08 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:08 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:10 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:10 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:13 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:13 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:15 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:15 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:18 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:18 INFO: Entering username (URL: https://login.xfinity.com/login)
2024-06-04T14:26:20 DEBUG: Finished loading page (URL: https://login.xfinity.com/login)
2024-06-04T14:26:20 INFO: Entering username (URL: https://login.xfinity.com/login)

image

LMK if there's anything else you need to me to diagnose

thor0215 commented 5 months ago

Patrick,

Hang tight I'll see what I can do. I'm also trying ti figure out a similar issue with another user. Currently in my setup things are still working but I'm curious if Xfinity is slowly making changes across customers or locations which is why I don't see the issue yet. In the meantime, you could try my new dev repo? It does have a minor change that identifies the login input tags better. Xfinity changed the username sign in button to now say "Let's Go". This new branch upgrades some of the python components and enters the username and password more slowly to replicate a user typing. And then simply presses Enter instead of clicking on the submit button.

https://github.com/thor0215/hassio-xfinity-usage-dev

Let me know if that works any better, Bryan

On Tue, Jun 4, 2024 at 4:27 PM Patrick @.***> wrote:

Ok, one more. As a test I restarted the addon again, and it went back to the first pattern - trying to populate the username and eating all the memory on the host.

2024-06-04T14:25:56 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:25:56 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:25:58 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:25:58 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:01 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:01 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:04 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:04 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:08 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:08 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:10 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:10 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:13 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:13 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:15 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:15 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:18 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:18 INFO: Entering username (URL: https://login.xfinity.com/login) 2024-06-04T14:26:20 DEBUG: Finished loading page (URL: https://login.xfinity.com/login) 2024-06-04T14:26:20 INFO: Entering username (URL: https://login.xfinity.com/login)

image.png (view on web) https://github.com/thor0215/hassio-xfinity-usage/assets/48227886/8182590b-1a62-4da6-9cab-f6e34d554c8f

LMK if there's anything else you need to me to diagnose

— Reply to this email directly, view it on GitHub https://github.com/thor0215/hassio-xfinity-usage/issues/9#issuecomment-2148443697, or unsubscribe https://github.com/notifications/unsubscribe-auth/AL7JXGLLYWNFPQITERYHKCTZFYWKZAVCNFSM6AAAAABIY5ZMGCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNBYGQ2DGNRZG4 . You are receiving this because you are subscribed to this thread.Message ID: @.***>

tankdeer commented 5 months ago

Thanks. Installed the dev branch version and so far so good. I will keep an eye on it to see how it behaves over the next couple days

thor0215 commented 5 months ago

Please upgrade to 0.0.9.4 in the dev branch and let me know the results when you can.

On Tue, Jun 4, 2024 at 9:02 PM Patrick @.***> wrote:

Thanks. Installed the dev branch version and so far so good. I will keep an eye on it to see how it behaves over the next couple days

— Reply to this email directly, view it on GitHub https://github.com/thor0215/hassio-xfinity-usage/issues/9#issuecomment-2148721568, or unsubscribe https://github.com/notifications/unsubscribe-auth/AL7JXGOLULSO2XLKCXYQU6TZFZWS7AVCNFSM6AAAAABIY5ZMGCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNBYG4ZDCNJWHA . You are receiving this because you commented.Message ID: @.***>

tankdeer commented 5 months ago

Please upgrade to 0.0.9.4 in the dev branch and let me know the results when you can.

Done! Will let you know how it goes

thor0215 commented 5 months ago

I have one more minor change to the addon that will help speed the addon build time a bit. I just pushed that to the dev branch, let me know if you have any issues once you've upgraded to 0.0.9.5.

On Wed, Jun 5, 2024 at 7:45 PM Patrick @.***> wrote:

Please upgrade to 0.0.9.4 in the dev branch and let me know the results when you can.

Done! Will let you know how it goes

— Reply to this email directly, view it on GitHub https://github.com/thor0215/hassio-xfinity-usage/issues/9#issuecomment-2151179710, or unsubscribe https://github.com/notifications/unsubscribe-auth/AL7JXGNLIZ7M3ELMIEUVPXLZF6WLRAVCNFSM6AAAAABIY5ZMGCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNJRGE3TSNZRGA . You are receiving this because you commented.Message ID: @.***>

tankdeer commented 5 months ago

Installed