search

Hyundai-Kia-Connect / kia_uvo

A Home Assistant HACS integration that supports Kia Connect(Uvo) and Hyundai Bluelink. The integration supports the EU, Canada and the USA.
MIT License
413 stars 85 forks source link

Failed to parse headers ... MissingHeaderBodySeparatorDefect() #694

Open sbyrx opened 1 year ago

sbyrx commented 1 year ago

Region and Brand of car Canada; Tucson PHEV

Version of the integration 2.10.7

Describe the bug In the Home Assistant logs I noticed a error that appears to indicate a response with bad headers from mybluelink.ca from several API endpoints.

Debug logs if an error occurred

Logger: urllib3.connectionpool
Source: /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:488
First occurred: 8:18:53 PM (8 occurrences)
Last logged: 8:19:17 PM

Failed to parse headers (url=https://mybluelink.ca:443/tods/api/vhcllst): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Failed to parse headers (url=https://mybluelink.ca:443/tods/api/lstvhclsts): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Failed to parse headers (url=https://mybluelink.ca:443/tods/api/nxtsvc): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Failed to parse headers (url=https://mybluelink.ca:443/tods/api/vrfypin): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Failed to parse headers (url=https://mybluelink.ca:443/tods/api/fndmcr): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request
    assert_header_parsing(httplib_response.msg)
  File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing
    raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data)
urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'

To Reproduce Haven't found a way to reproduce, appears to happen periodically on its own.

Expected behavior No errors in the log.

cdnninja commented 1 year ago

How long has this been happening, how often and does it recover on its own?

sbyrx commented 1 year ago

I restarted Home Assistant yesterday and my logs only seem to go back that far.

Since 2023-07-31 20:42:43.599 its happened 98 times. The last occurrence was 20 minutes ago (2023-08-01 17:47:12.992). Looking at the timestamps I don't see much of a pattern in terms of regularity. Doesn't seem to recover on its own.

I can send more logs if that would be helpful!

Thanks for your help

cdnninja commented 1 year ago

I'm also in Canada and haven't seen this before.

What platform do you run this on?

sbyrx commented 1 year ago

Strange... I'm running HA in a Docker Container on Ubuntu 22.04.2

cdnninja commented 1 year ago

Googling this points to being server side. Since others aren't reporting it I would think something local to your install or network.

sbyrx commented 1 year ago

I'll do a bit more digging this weekend, I can't think of anything special about my install or network that might be causing issues. It's strange because some of the REST calls clearly work. I've noticed that the status of my car isn't updating some times, and service calls sometimes don't return. I assume it's related to this error.

trueppp commented 1 year ago

Same is happening to me, Kona EV, Canada. Running HAOS on RPI4.

Logger: urllib3.connectionpool Source: /usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:488 First occurred: 5:21:11 PM (32 occurrences) Last logged: 7:23:35 PM

Failed to parse headers (url=https://mybluelink.ca:443/tods/api/fndmcr): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n' Failed to parse headers (url=https://mybluelink.ca:443/tods/api/evc/selsoc): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n' Failed to parse headers (url=https://mybluelink.ca:443/tods/api/rltmvhclsts): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n' Failed to parse headers (url=https://mybluelink.ca:443/tods/api/lstvhclsts): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n' Failed to parse headers (url=https://mybluelink.ca:443/tods/api/nxtsvc): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n' Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request assert_header_parsing(httplib_response.msg) File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data) urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'

1

cdnninja commented 1 year ago

@trueppp are you also running on docker or something other than core?

sbyrx commented 1 year ago

@trueppp mentioned "Running HAOS on RPI4"

I seem to be able to reproduce it by manually calling the force_update service. I'm trying to get some better debug logs to figure out what the bad header might be. Any suggestions?

cdnninja commented 1 year ago

Have you enabled debug logs on the api? Or on the package throwing the error?

sbyrx commented 1 year ago

I enabled debug logging for urllib3.connectionpool and hyundai_kia_connect_api. I then manually called force_update and here's what I see in the logs:

2023-08-04 21:20:36.388 DEBUG (SyncWorker_7) [urllib3.connectionpool] Resetting dropped connection: mybluelink.ca
2023-08-04 21:20:59.652 DEBUG (SyncWorker_7) [urllib3.connectionpool] https://mybluelink.ca:443 "POST /tods/api/rltmvhclsts HTTP/1.1" 200 None
2023-08-04 21:20:59.653 WARNING (SyncWorker_7) [urllib3.connectionpool] Failed to parse headers (url=https://mybluelink.ca:443/tods/api/rltmvhclsts): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request
    assert_header_parsing(httplib_response.msg)
  File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing
    raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data)
urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Received forced vehicle data {'responseHeader': {'responseCode': 0, 'responseDesc': 'Success'}, 'result': {'status': {'lastStatusDate': '20230805012058', 'airCtrlOn': False, 'engine': False, 'doorLock': True, 'doorOpen': {'frontLeft': 0, 'frontRight': 0, 'backLeft': 0, 'backRight': 0}, 'trunkOpen': False, 'airTempUnit': 'C', 'airTemp': {'value': '00H', 'unit': 0}, 'defrost': False, 'lowFuelLight': False, 'acc': False, 'evStatus': {'batteryCharge': False, 'batteryStatus': 100, 'batteryPlugin': 2, 'remainTime2': {'etc1': {'value': 65535, 'unit': 1}, 'etc2': {'value': 0, 'unit': 1}, 'etc3': {'value': 0, 'unit': 1}, 'atc': {'value': 0, 'unit': 1}}, 'drvDistance': [{'rangeByFuel': {'gasModeRange': {'value': 309.0, 'unit': 1}, 'evModeRange': {'value': 53.0, 'unit': 1}, 'totalAvailableRange': {'value': 362.0, 'unit': 1}}, 'type': 2}]}, 'hoodOpen': False, 'transCond': True, 'steerWheelHeat': 0, 'sideBackWindowHeat': 0, 'dte': {}, 'tirePressureLamp': {'tirePressureLampAll': 0}, 'battery': {'batSoc': 86, 'sjbDeliveryMode': 1, 'batSignalReferenceValue': {}}, 'remoteIgnition': True, 'seatHeaterVentInfo': {'drvSeatHeatState': 2, 'astSeatHeatState': 2, 'rlSeatHeatState': 2, 'rrSeatHeatState': 2}, 'sleepModeCheck': False, 'lampWireStatus': {'headLamp': {'headLampStatus': False, 'leftLowLamp': False, 'rightLowLamp': False, 'leftHighLamp': False, 'rightHighLamp': False, 'leftBifuncLamp': False, 'rightBifuncLamp': False}, 'stopLamp': {'leftLamp': False, 'rightLamp': False}, 'turnSignalLamp': {'leftFrontLamp': False, 'rightFrontLamp': False, 'leftRearLamp': False, 'rightRearLamp': False}}, 'windowOpen': {}, 'smartKeyBatteryWarning': False, 'fuelLevel': 69, 'washerFluidStatus': False, 'breakOilStatus': False, 'engineOilStatus': False, 'engineRuntime': {}}}}
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - before 20230805012058
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - after 2023-08-05 01:20:58+00:00
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Offset between vehicle and UTC: 0 hours
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Old Vehicle Last Updated: 2023-08-05 00:56:45+00:00
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - before 20230805012058
2023-08-04 21:20:59.658 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - after 2023-08-05 01:20:58+00:00
2023-08-04 21:20:59.659 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Current Vehicle Last Updated: 2023-08-05 01:20:58+00:00
2023-08-04 21:20:59.816 DEBUG (SyncWorker_7) [urllib3.connectionpool] https://mybluelink.ca:443 "POST /tods/api/nxtsvc HTTP/1.1" 200 None
2023-08-04 21:20:59.816 WARNING (SyncWorker_7) [urllib3.connectionpool] Failed to parse headers (url=https://mybluelink.ca:443/tods/api/nxtsvc): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request
    assert_header_parsing(httplib_response.msg)
  File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing
    raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data)
urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
2023-08-04 21:20:59.820 DEBUG (SyncWorker_7) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Get Service status data {'responseHeader': {'responseCode': 0, 'responseDesc': 'Success'}, 'result': {'maintenanceInfo': {'msopServiceOdometer': 12.0, 'msopServiceOdometerUnit': 1, 'mtspServiceDate': '20230707', 'imatServiceOdometer': 12012.0, 'imatServiceOdometerUnit': 1, 'mtitServiceDate': '20240707', 'currentOdometer': 949.8, 'currentOdometerUnit': 1, 'serviceOdometerDuration': 12000.0, 'serviceDaysDuration': 366, 'serviceMonthsThreshold': 12}}}
2023-08-04 21:20:59.822 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.VehicleManager] hyundai_kia_connect_api - Time differential in seconds: 1.822655
2023-08-04 21:21:00.018 DEBUG (SyncWorker_2) [urllib3.connectionpool] https://mybluelink.ca:443 "POST /tods/api/lstvhclsts HTTP/1.1" 200 None
2023-08-04 21:21:00.019 WARNING (SyncWorker_2) [urllib3.connectionpool] Failed to parse headers (url=https://mybluelink.ca:443/tods/api/lstvhclsts): [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request
    assert_header_parsing(httplib_response.msg)
  File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing
    raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data)
urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
2023-08-04 21:21:00.025 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - get_cached_vehicle_status response {'responseHeader': {'responseCode': 0, 'responseDesc': 'Success'}, 'result': {'status': {'lastStatusDate': '20230805012058', 'airCtrlOn': False, 'engine': False, 'doorLock': True, 'doorOpen': {'frontLeft': 0, 'frontRight': 0, 'backLeft': 0, '
backRight': 0}, 'trunkOpen': False, 'airTempUnit': 'C', 'airTemp': {'value': '00H', 'unit': 0}, 'defrost': False, 'lowFuelLight': False, 'acc': False, 'evStatus': {'batteryCharge': False, 'batt
eryStatus': 100, 'batteryPlugin': 2, 'remainTime2': {'etc1': {'value': 65535, 'unit': 1}, 'etc2': {'value': 0, 'unit': 1}, 'etc3': {'value': 0, 'unit': 1}, 'atc': {'value': 0, 'unit': 1}}, 'drv
Distance': [{'rangeByFuel': {'gasModeRange': {'value': 309.0, 'unit': 1}, 'evModeRange': {'value': 53.0, 'unit': 1}, 'totalAvailableRange': {'value': 362.0, 'unit': 1}}, 'type': 2}]}, 'hoodOpen
': False, 'transCond': True, 'steerWheelHeat': 0, 'sideBackWindowHeat': 0, 'dte': {}, 'tirePressureLamp': {'tirePressureLampAll': 0}, 'battery': {'batSoc': 86, 'sjbDeliveryMode': 1, 'batSignalR
eferenceValue': {}}, 'remoteIgnition': True, 'seatHeaterVentInfo': {'drvSeatHeatState': 2, 'astSeatHeatState': 2, 'rlSeatHeatState': 2, 'rrSeatHeatState': 2}, 'sleepModeCheck': False, 'lampWire
Status': {'headLamp': {'headLampStatus': False, 'leftLowLamp': False, 'rightLowLamp': False, 'leftHighLamp': False, 'rightHighLamp': False, 'leftBifuncLamp': False, 'rightBifuncLamp': False}, '
stopLamp': {'leftLamp': False, 'rightLamp': False}, 'turnSignalLamp': {'leftFrontLamp': False, 'rightFrontLamp': False, 'leftRearLamp': False, 'rightRearLamp': False}}, 'windowOpen': {}, 'smart
KeyBatteryWarning': False, 'fuelLevel': 69, 'washerFluidStatus': False, 'breakOilStatus': False, 'engineOilStatus': False, 'engineRuntime': {}}}}
2023-08-04 21:21:00.025 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Old Vehicle Last Updated: 2023-08-05 01:20:58+00:00
2023-08-04 21:21:00.025 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - before 20230805012058
2023-08-04 21:21:00.025 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - last_updated_at - after 2023-08-05 01:20:58+00:00
2023-08-04 21:21:00.025 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Current Vehicle Last Updated: 2023-08-05 01:20:58+00:00
2023-08-04 21:21:00.170 DEBUG (SyncWorker_2) [urllib3.connectionpool] https://mybluelink.ca:443 "POST /tods/api/nxtsvc HTTP/1.1" 200 None
2023-08-04 21:21:00.170 WARNING (SyncWorker_2) [urllib3.connectionpool] Failed to parse headers (url=https://mybluelink.ca:443/tods/api/nxtsvc): [MissingHeaderBodySeparatorDefect()], unparsed d
ata: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py", line 486, in _make_request
    assert_header_parsing(httplib_response.msg)
  File "/usr/local/lib/python3.11/site-packages/urllib3/util/response.py", line 91, in assert_header_parsing
    raise HeaderParsingError(defects=defects, unparsed_data=unparsed_data)
urllib3.exceptions.HeaderParsingError: [MissingHeaderBodySeparatorDefect()], unparsed data: 'GET, POST, HEAD: always\r\nX-XSS-Protection: 1; mode=block\r\nAllow: GET, POST, HEAD\r\n\r\n'
2023-08-04 21:21:00.175 DEBUG (SyncWorker_2) [hyundai_kia_connect_api.KiaUvoApiCA] hyundai_kia_connect_api - Get Service status data {'responseHeader': {'responseCode': 0, 'responseDesc': 'Succ
ess'}, 'result': {'maintenanceInfo': {'msopServiceOdometer': 12.0, 'msopServiceOdometerUnit': 1, 'mtspServiceDate': '20230707', 'imatServiceOdometer': 12012.0, 'imatServiceOdometerUnit': 1, 'mt
itServiceDate': '20240707', 'currentOdometer': 949.8, 'currentOdometerUnit': 1, 'serviceOdometerDuration': 12000.0, 'serviceDaysDuration': 366, 'serviceMonthsThreshold': 12}}}
2023-08-04 21:21:00.178 DEBUG (SyncWorker_2) [urllib3.connectionpool] Starting new HTTPS connection (1): nominatim.openstreetmap.org:443
2023-08-04 21:21:01.384 DEBUG (SyncWorker_2) [urllib3.connectionpool] https://nominatim.openstreetmap.org:443 "GET /reverse?lat=45.45182777&lon=-75.60150277777778&format=json&addressdetails=1&z
oom=18 HTTP/1.1" 200 None
2023-08-04 21:21:01.389 DEBUG (MainThread) [custom_components.kia_uvo.coordinator] Finished fetching kia_uvo data in 1.567 seconds (success: True)
trueppp commented 1 year ago

@trueppp are you also running on docker or something other than core?

Home Assistant Operating System