Skip to content
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

Fix client process for large packets #221

Open
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

mriksman
Copy link
Contributor

@mriksman mriksman commented Dec 6, 2024

Issue 1

When a large packet is received (greater than 1042), it is broken into separate parts. The calculation for decrypted_size had the incorrect value of 18 instead of 16, so decrypted size was being calculated as 1022. When client_decrypt was called, decrypted_size of 1022 was less than the calculated required_decrypted_size of 1024 causing it to fail with r = -2.

    if (*decrypted_size < required_decrypted_size) {
        *decrypted_size = required_decrypted_size;
        return -2;
    }

The error logs showed:

>>> homekit_client_process: [Client 1] Finished processing
>>> homekit_client_process: [Client 1] Got 1042 incoming data
>>> homekit_client_process: [Client 1] Decrypting data
!!! HomeKit: [Client 1] Invalid client data

It then read the remaining part of the data, but was unable to decrypt it (perhaps because the first part wasn't decrypted?)

>>> homekit_client_process: [Client 1] Got 299 incoming data
>>> homekit_client_process: [Client 1] Decrypting data
!!! HomeKit: Failed to chacha decrypt payload (code -213)
!!! HomeKit: [Client 1] Invalid client data

Adjusting the number from 18 to 16 resolved the issue.

Issue 2

I noticed that homekit_client_process was exiting before the full message was completed.

>>> homekit_client_process: [Client 1] Got 1042 incoming data
>>> homekit_client_process: [Client 1] Decrypting data
>>> client_decrypt: client_decrypt: payload_size=1042, required_decrypted_size=1024, decrypted_size=1024, block_size=1042
>>> homekit_client_process: [Client 1] Decrypted 1024 bytes, available 0
>>> homekit_client_process: [Client 1] Decrypted data (1024 bytes): PUT /characteristics HTTP/1.1\x0D\x0AHost: esp-824f29._hap._tcp.local\x0D\x0AContent-Length: 948\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":25,"ev":true},{"aid":1,"iid":26,"ev":true},{"aid":1,"iid":24,"ev":true},{"aid":1,"iid":31,"ev":true},{"aid":1,"iid":30,"ev":true},{"aid":1,"iid":32,"ev":true},{"aid":1,"iid":33,"ev":true},{"aid":1,"iid":17,"ev":true},{"aid":1,"iid":15,"ev":true},{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":18,"ev":true},{"aid":1,"iid":67,"ev":true},{"aid":1,"iid":66,"ev":true},{"aid":1,"iid":68,"ev":true},{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":9,"ev":true},{"aid":1,"iid":12,"ev":true},{"aid":1,"iid":75,"ev":true},{"aid":1,"iid":74,"ev":true},{"aid":1,"iid":73,"ev":true},{"aid":1,"iid":53,"ev":true},{"aid":1,"iid":52,"ev":true},{"aid":1,"iid":54,"ev":true},{"aid":1,"iid":39,"ev":true},{"aid":1,"iid":40,"ev":true},{"aid":1,"iid":38,"ev":true},{"aid":1,"iid":60,"ev":true},{"aid":1,"iid":59,"ev":true},{"aid":1,"iid":61,"ev":true},{"aid":1,"iid":45,"ev":true},{"aid":1,"i
>>> homekit_client_process: [Client 1] Finished processing

The JSON is incomplete, and the HTTP parser has not indicated that the response was completed. Under low loads, the function would execute again, read the remaining part of the JSON, and successfully finish the message. However, under heavy client loads, it was possible for another client to connect and be processed, with the function trying to merge Client 1 and Client 4 data.

>>> homekit_client_process: [Client 4] Got 98 incoming data
>>> homekit_client_process: [Client 4] Decrypting data
>>> client_decrypt: client_decrypt: payload_size=98, required_decrypted_size=80, decrypted_size=1024, block_size=1042
>>> homekit_client_process: [Client 4] Decrypted 80 bytes, available 0
>>> homekit_client_process: [Client 4] Decrypted data (80 bytes): GET /characteristics?id=1.21,1.23 HTTP/1.1\x0D\x0AHost: esp-824f29._hap._tcp.local\x0D\x0A\x0D\x0A
>>> HomeKit: [Client 4] Update Characteristics
>>> homekit_server_on_update_characteristics: Free heap: 143028
!!! HomeKit: [Client 4] Failed to parse request JSON
>>> send_json_response: [Client 4] Sending JSON response
>>> send_json_response: Free heap: 143028
>>> send_json_response: [Client 4] Payload: {"status": -70410}
>>> send_json_response: [Client 4] Sending HTTP response: HTTP/1.1 400 Bad Request
Content-Type: application/hap+json
Content-Length: 18
Connection: keep-alive

{"status": -70410}
>>> client_sendv: [Client 4] Sending payload: HTTP/1.1 400 Bad Request\x0D\x0AContent-Type: application/hap+json\x0D\x0AContent-Length: 18\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A{"status": -70410}
>>> homekit_client_process: [Client 4] Finished processing

It appears that in the while check, data_available is always 0 as the buffer equals the block size. I believe this loop should only exit once the HTTP parser has indicated the message is indeed complete.

    } while (!context->server->request_completed);

The logs now look correct.

>>> homekit_client_process: [Client 1] Got 1042 incoming data
>>> homekit_client_process: [Client 1] Decrypting data
>>> homekit_client_process: [Client 1] After decryption: r=1042, data_len=1042, data_available=0, decrypted_size=1024
>>> homekit_client_process: [Client 1] Decrypted data (1024 bytes): PUT /characteristics HTTP/1.1\x0D\x0AHost: esp-824f29._hap._tcp.local\x0D\x0AContent-Length: 1180\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":31,"ev":true},{"aid":1,"iid":32,"ev":true},{"aid":1,"iid":33,"ev":true},{"aid":1,"iid":30,"ev":true},{"aid":1,"iid":17,"ev":true},{"aid":1,"iid":18,"ev":true},{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":15,"ev":true},{"aid":1,"iid":26,"ev":true},{"aid":1,"iid":23,"ev":true},{"aid":1,"iid":24,"ev":true},{"aid":1,"iid":25,"ev":true},{"aid":1,"iid":67,"ev":true},{"aid":1,"iid":68,"ev":true},{"aid":1,"iid":66,"ev":true},{"aid":1,"iid":65,"ev":true},{"aid":1,"iid":9,"ev":true},{"aid":1,"iid":11,"ev":true},{"aid":1,"iid":12,"ev":true},{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":75,"ev":true},{"aid":1,"iid":74,"ev":true},{"aid":1,"iid":73,"ev":true},{"aid":1,"iid":72,"ev":true},{"aid":1,"iid":53,"ev":true},{"aid":1,"iid":52,"ev":true},{"aid":1,"iid":54,"ev":true},{"aid":1,"iid":51,"ev":true},{"aid":1,"iid":40,"ev":true},{"aid":1,"iid":37,"ev":true},{"aid":1,"
>>> homekit_client_process: [Client 1] Got 299 incoming data
>>> homekit_client_process: [Client 1] Decrypting data
>>> homekit_client_process: [Client 1] After decryption: r=299, data_len=299, data_available=0, decrypted_size=281
>>> homekit_client_process: [Client 1] Decrypted data (281 bytes): iid":39,"ev":true},{"aid":1,"iid":38,"ev":true},{"aid":1,"iid":58,"ev":true},{"aid":1,"iid":61,"ev":true},{"aid":1,"iid":59,"ev":true},{"aid":1,"iid":60,"ev":true},{"aid":1,"iid":47,"ev":true},{"aid":1,"iid":45,"ev":true},{"aid":1,"iid":46,"ev":true},{"aid":1,"iid":44,"ev":true}]}
>>> HomeKit: [Client 1] Update Characteristics

snip

>>> homekit_server_on_update_characteristics: [Client 1] There were no processing errors, sending No Content response
>>> client_sendv: [Client 1] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A
>>> homekit_client_process: [Client 1] Finished processing

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant