AIOHTTP Error in Log for Supervisor 2023.07.2 {BETA}

[jweston2112]

Describe the issue you are experiencing

I noticed an AIOHTTP Error in the log (See log message below... obfuscated due to Bearer Token information)

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Steps to reproduce the issue

1. Look in the Log

Anything in the Supervisor logs that might be useful for us?

23-07-24 02:50:15 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/aiohttp/web_protocol.py", line 332, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
                               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "aiohttp/_http_parser.pyx", line 557, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadHttpMessage: 400, message:
  Invalid header value char:
    b'Authorization: Bearer *********************************************************************************************************410939e'
                                                                                                                                            ^

### System Health information

## System Information

version | core-2023.7.3
-- | --
installation_type | Home Assistant OS
dev | false
hassio | true
docker | true
user | root
virtualenv | false
python_version | 3.11.4
os_name | Linux
os_version | 6.1.21-v8
arch | aarch64
timezone | America/New_York
config_dir | /config

<details><summary>Home Assistant Community Store</summary>

GitHub API | ok
-- | --
GitHub Content | ok
GitHub Web | ok
GitHub API Calls Remaining | 5000
Installed Version | 1.32.1
Stage | running
Available Repositories | 1273
Downloaded Repositories | 22
HACS Data | ok

</details>

<details><summary>Home Assistant Supervisor</summary>

host_os | Home Assistant OS 10.4
-- | --
update_channel | beta
supervisor_version | supervisor-2023.07.2
agent_version | 1.5.1
docker_version | 23.0.6
disk_total | 228.5 GB
disk_used | 13.6 GB
healthy | true
supported | true
board | rpi4-64
supervisor_api | ok
version_api | ok
installed_addons | HassOS I2C Configurator (0.13a), Node-RED (14.4.2), Advanced SSH & Web Terminal (15.0.5), Samba Backup (5.2.0), Samba share (10.0.2), ArgonOne Active Cooling (29c), Music Assistant BETA (2.0.0b60), ESPHome (beta) (2023.7.0), Piper (0.1.3), Whisper (0.2.1), Studio Code Server (5.9.0)

</details>

<details><summary>Dashboards</summary>

dashboards | 5
-- | --
resources | 15
views | 8
mode | storage

</details>

<details><summary>Recorder</summary>

oldest_recorder_run | July 20, 2023 at 5:51 PM
-- | --
current_recorder_run | July 24, 2023 at 2:48 AM
estimated_db_size | 58.86 MiB
database_engine | sqlite
database_version | 3.41.2

</details>

### Supervisor diagnostics

[config_entry-hassio-b20a568cb4d1e3c68d96d3ee7f3f12f1.json.txt](https://github.com/home-assistant/supervisor/files/12142739/config_entry-hassio-b20a568cb4d1e3c68d96d3ee7f3f12f1.json.txt)


### Additional information

_No response_

[jweston2112]

Problem Still Exists in Supervisor 2023.07.3

[mdegat01]

I am not seeing this error on any of my systems. What are you doing to reproduce this? I've tried restarting supervisor and the host on these systems and it doesn't happen. I have debug logging turned on as well.

[jweston2112]

Well I am seeing this in the log on my raspberry pi 4 8 gb machine running HAOS version 2023.08.bX and it started when I allowed Supervisor 2023.7.2 to install... now it seems to be effecting an addon only ... the ArgonOne Active Cooling Addon
it seems to be trying to update a sensor ( fan speed ) ... or atleast I assume this as it is the only thing I can find that stopped working at the time.... but it was working prior....

to me it looks like its trying to update via a websocket connection so I wonder if it is related to this change in 2023.07.2

#4443 Increase core websocket proxy maximum message size to 64MiB @bdraco

it seems like a possible place to start.... as far as I can see.... but I could be wrong ...

[pvizeli]

If you restart the add-on, will that change something? Because we generate a new token and it's unlike the new token will have invalid chars as well

[jweston2112]

It does get a new token but I still get the Error messages (it actually repeats 2X).... I also realized that AIOHTTP was upgraded in 2023.07.2 and I wonder if that is the issue...

the little caret character isnt actually pointing to any character in the token string.... its actually pointing to the single quote at the end.... is the token too short?

[mdegat01]

Based on the message and the location of the caret my guess would be a whitespace character is getting included at thend. One that isn't showing up in the log (since there's a lot that don't render as anything readable) but is throwing off the parsing. I'm not exactly sure how to prove that or where that could be coming from though...

[mdegat01]

It does get a new token but I still get the Error messages (it actually repeats 2X).... I also realized that AIOHTTP was upgraded in 2023.07.2 and I wonder if that is the issue...

@jweston2112 you're right. this is this issue. Since you mentioned the name of the addon I found it via googling (to confirm, it's this one right?). I saw that it was making the call here: https://github.com/adamoutler/HassOSArgonOneAddon/blob/851bad19ff5f4fdd40219a07f2a523b00bff0ba4/argonOne/run.sh#L78-L84

I made a simple script to do the same thing like this aimed at my dev system:

#!/bin/bash

SUPERVISOR_TOKEN=token_from_dev_addon
reqBody='{"state": "hi", "attributes": {"friendly_name": "argon test"}}'
nc -i 1 192.168.1.10 80 <<< unix2dos<<EOF
POST /homeassistant/api/states/sensor.test HTTP/1.1
Authorization: Bearer ${SUPERVISOR_TOKEN}
Content-Length: $( echo -ne "${reqBody}" | wc -c )

${reqBody}
EOF

This failed with the same error you see. After downgrading aiohttp to 3.8.4 inside the supervisor container and restarting, this succeeded.

I'm at a loss as to why but I will revert that PR until I can figure out why. Thanks for alerting me to this, sorry it took so long

[jweston2112]

@mdegat01 looks like the Supervisor release build bombed.... ☹️
also it looks like dependabot may have reverted your reversion... if I read it right.... but I am not a github guru such as yourself... Thanks for the Effort and Assistance

[mdegat01]

@jweston2112 Unfortunately the test to see if the SSH addon is a bit flaky in the CI pipeline and requires a manual re-run sometimes, it's something I need to fix at some point. A re-run cleaned it up though and beta went out yesterday with this fix. I just put up a PR to bump stable.

However after further digging in the linked aiohttp issue, this is not an aiohttp bug. Prior to 3.8.5 aiohttp was allowing HTTP requests that used simple carriage returns for convenience. This is not correct according to the HTTP spec and 3.8.5 hardened the rules for security reasons to strictly obey the spec and require dos line endings. The addon you referenced is not making correct HTTP calls as it is using carriage returns, this is a bug in the addon.

I created adamoutler/HassOSArgonOneAddon#60 in the repo for the author. Given this is a bug with that addon I am now going to bump aiohttp to 3.8.5 in supervisor dev. As noted in the issue that will then become beta and stable for supervisor within the next week or two. This is not an option for supervisor as 3.8.5 contains some security fixes. So you'll have to follow up with that addon author to get it fixed otherwise the addon will break next time supervisor updates.

[jweston2112]

Thats Ok... I was just trying to notify you (et. al.) before it rolled out to Production in case it was a larger issue. The loss of that one sensor and the log entries ( while an affront to my OCD) were not "extremely" critical to me... so even if it resurfaces in the future no harm no foul ... as long as it is understood and not a massive issue ...

Many Thanks for your effort and assistance!

[mdegat01]

@jweston2112 just a heads up the aiohttp bump is in 2023.08.1. That was sooner then I expected it to be but we had a showstopper in #4459 that required an immediate new release.

If you want to buy some time before the addon stops working can switch the stable channel as that won't be updated until next week at some point.