Skip to content

Commit 89ecf33

Browse files
author
Martin Littkovsky
committed
[amazonechocontrol] Buffer push stream data until a message is complete
Since mid-August 2026 Amazon delivers push messages split over several HTTP/2 DATA frames (#21426). PushStreamAdapter parsed every DATA frame as if it were a complete multipart part: the first fragment of a split message failed with "MalformedJsonException: Unterminated string", the second produced "Don't know how to handle frame starting with ...", both at WARN for every single message, and the message itself was lost. The adapter now collects the raw bytes and processes a part only once its trailing boundary marker has arrived; a single frame may equally carry several parts. Fixed in the same path because the new code depends on it: - an incomplete part was logged as discarded but processed anyway (missing return) - frame content was decoded with the platform default charset before re-assembly; parts are now decoded as UTF-8 and only when complete, so a multi-byte character split across frames survives - the DATA frame callback was never completed, so consumed bytes were never returned to the HTTP/2 flow control window (Jetty replenishes it in DataCallback.succeeded) and a busy long-lived stream would stall for good once the initial window is exhausted - a part that fails to process - a real format change, not fragmentation - is dropped and the stream re-synchronizes at the next boundary, logging one body-free WARN per failure streak, so a future API evolution can neither wedge the stream nor flood the log - the delimiter is accepted both as the bare boundary parameter and as "--" + parameter (RFC 2046), whichever Amazon actually sends Signed-off-by: Martin Littkovsky <2018turtle@proton.me> AI-assisted-by: Claude Code
1 parent 9e03945 commit 89ecf33

2 files changed

Lines changed: 403 additions & 30 deletions

File tree

bundles/org.openhab.binding.amazonechocontrol/src/main/java/org/openhab/binding/amazonechocontrol/internal/push/PushStreamAdapter.java

Lines changed: 101 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -14,10 +14,11 @@
1414

1515
import static org.eclipse.jetty.http.HttpHeader.CONTENT_TYPE;
1616

17-
import java.io.BufferedReader;
18-
import java.io.StringReader;
17+
import java.io.ByteArrayOutputStream;
18+
import java.nio.charset.StandardCharsets;
1919
import java.util.List;
2020
import java.util.Objects;
21+
import java.util.regex.Pattern;
2122

2223
import org.eclipse.jdt.annotation.NonNullByDefault;
2324
import org.eclipse.jetty.http.HttpFields;
@@ -38,14 +39,24 @@
3839
* The {@link PushStreamAdapter} handles the HTTP/2 push stream
3940
*
4041
* @author Jan N. Klug - Initial contribution
42+
* @author Martin Littkovsky - Buffer stream data until a message is complete
4143
*/
4244
@NonNullByDefault
4345
public class PushStreamAdapter extends Stream.Listener.Adapter {
46+
// real messages are a few KiB, the limit is only reached if the boundary never arrives
47+
static final int MAX_BUFFER_SIZE = 512 * 1024;
48+
private static final Pattern DASHES_ONLY = Pattern.compile("-+");
49+
4450
private final Logger logger = LoggerFactory.getLogger(PushStreamAdapter.class);
4551
private final Gson gson;
4652
private final Session session;
4753
private final Listener listener;
54+
// all mutable state is confined to the stream's serialized listener invocations
55+
private final ByteArrayOutputStream buffer = new ByteArrayOutputStream();
56+
4857
private String boundary = "";
58+
private byte[] boundaryBytes = new byte[0];
59+
private boolean failureLogged = false;
4960

5061
public PushStreamAdapter(Gson gson, Session session, Listener listener) {
5162
this.gson = gson;
@@ -65,50 +76,110 @@ public void onHeaders(@NonNullByDefault({}) Stream stream, @NonNullByDefault({})
6576
return;
6677
}
6778
int boundaryStart = contentType.indexOf("boundary=");
79+
if (boundaryStart == -1) {
80+
logger.warn("Content-type of HTTP/2 stream doesn't contain a boundary: {}", contentType);
81+
return;
82+
}
6883
int boundaryEnd = contentType.indexOf(";", boundaryStart);
69-
boundary = contentType.substring(boundaryStart + 9, boundaryEnd);
84+
boundary = contentType.substring(boundaryStart + 9, boundaryEnd == -1 ? contentType.length() : boundaryEnd);
85+
boundaryBytes = boundary.getBytes(StandardCharsets.UTF_8);
7086
}
7187

7288
@Override
7389
public void onData(@NonNullByDefault({}) Stream stream, @NonNullByDefault({}) DataFrame frame,
7490
@NonNullByDefault({}) Callback callback) {
75-
byte[] contentBuffer = new byte[frame.remaining()];
76-
frame.getData().get(contentBuffer);
77-
String contentString = new String(contentBuffer);
78-
logger.trace("Received raw data {}", contentString);
79-
80-
// process
8191
try {
92+
byte[] contentBuffer = new byte[frame.remaining()];
93+
frame.getData().get(contentBuffer);
94+
if (logger.isTraceEnabled()) {
95+
logger.trace("Received raw data {}", new String(contentBuffer, StandardCharsets.UTF_8));
96+
}
8297
if (boundary.isBlank()) {
83-
logger.debug("Discarding message because boundary is not set");
98+
logger.debug("Discarding data because boundary is not set");
8499
return;
85100
}
86-
BufferedReader contentReader = new BufferedReader(new StringReader(contentString));
87-
List<String> content = contentReader.lines().filter(line -> !line.isBlank()).toList();
101+
// a message can be split over several DATA frames and a frame can contain several messages,
102+
// so bytes are collected until the trailing boundary marker completes a part
103+
buffer.write(contentBuffer, 0, contentBuffer.length);
104+
processBuffer();
105+
} catch (RuntimeException e) {
106+
logger.warn("Exception while processing message", e);
107+
} finally {
108+
// completing the callback replenishes the HTTP/2 flow control window,
109+
// without that the server can't send further data on this long-lived stream
110+
callback.succeeded();
111+
}
112+
}
88113

89-
if (content.isEmpty()) {
90-
return;
114+
private void processBuffer() {
115+
byte[] data = buffer.toByteArray();
116+
int consumed = 0;
117+
int boundaryPos;
118+
while ((boundaryPos = indexOf(data, boundaryBytes, consumed)) != -1) {
119+
String part = new String(data, consumed, boundaryPos - consumed, StandardCharsets.UTF_8);
120+
// the part counts as consumed even if it fails, a bad message must not wedge the stream
121+
consumed = boundaryPos + boundaryBytes.length;
122+
try {
123+
handlePart(part);
124+
} catch (RuntimeException e) {
125+
// the content was already logged at TRACE when the frame arrived
126+
logFailure("Failed to process a message part of {} characters: {}", part.length(), e.toString());
127+
logger.debug("Processing failure", e);
91128
}
129+
}
130+
if (consumed > 0) {
131+
buffer.reset();
132+
buffer.write(data, consumed, data.length - consumed);
133+
}
134+
if (buffer.size() > MAX_BUFFER_SIZE) {
135+
logger.warn("Discarding {} bytes of buffered data that don't contain a message boundary", buffer.size());
136+
buffer.reset();
137+
}
138+
}
92139

93-
if (!content.get(content.size() - 1).endsWith(boundary)) {
94-
logger.debug("Discarding incomplete message, boundary not found");
95-
}
140+
private void handlePart(String part) {
141+
// the delimiter on the wire may be the boundary parameter itself or "--" + parameter (RFC 2046),
142+
// splitting at the parameter leaves the extra dashes behind as a line of their own
143+
List<String> content = part.lines()
144+
.filter(line -> !line.isBlank() && !DASHES_ONLY.matcher(line.strip()).matches()).toList();
145+
if (content.isEmpty()) {
146+
// a bare boundary is a keep-alive that requires a PING response
147+
logger.debug("Sending ping");
148+
session.ping(new PingFrame(false), Callback.NOOP);
149+
return;
150+
}
151+
if (content.get(0).equals("Content-Type: application/json")) {
152+
String json = String.join("", content.subList(1, content.size()));
153+
PushMessageTO parsedMessage = Objects.requireNonNullElse(gson.fromJson(json, PushMessageTO.class),
154+
new PushMessageTO());
155+
parsedMessage.directive.payload.renderingUpdates.forEach(listener::onPushMessageReceived);
156+
failureLogged = false;
157+
} else {
158+
logFailure("Don't know how to handle a message part of {} characters", part.length());
159+
}
160+
}
96161

97-
if (content.size() == 1) {
98-
// only boundary requires a PING response
99-
logger.debug("Sending ping");
100-
session.ping(new PingFrame(false), Callback.NOOP);
101-
} else if (content.get(0).equals("Content-Type: application/json")) {
102-
// parse the message
103-
PushMessageTO parsedMessage = Objects
104-
.requireNonNullElse(gson.fromJson(content.get(1), PushMessageTO.class), new PushMessageTO());
105-
parsedMessage.directive.payload.renderingUpdates.forEach(listener::onPushMessageReceived);
106-
} else {
107-
logger.warn("Don't know how to handle frame starting with {}", content.get(0));
162+
// the first failure of a streak is a WARN, repetitions only DEBUG to keep a format change from flooding the log
163+
private void logFailure(String message, Object... arguments) {
164+
if (failureLogged) {
165+
logger.debug(message, arguments);
166+
} else {
167+
logger.warn(message, arguments);
168+
failureLogged = true;
169+
}
170+
}
171+
172+
private static int indexOf(byte[] data, byte[] pattern, int fromIndex) {
173+
for (int i = fromIndex; i <= data.length - pattern.length; i++) {
174+
int j = 0;
175+
while (j < pattern.length && data[i + j] == pattern[j]) {
176+
j++;
177+
}
178+
if (j == pattern.length) {
179+
return i;
108180
}
109-
} catch (RuntimeException e) {
110-
logger.warn("Exception while processing message", e);
111181
}
182+
return -1;
112183
}
113184

114185
public interface Listener {

0 commit comments

Comments
 (0)