|
1
|
================================================================================================
|
|
2
|
PROPOSAL - [MINOR] functional - WebClientProtocol.onClose
|
|
3
|
Heartbeat expiry reuses StatusCode.SHUTDOWN and is logged as a browser tab close
|
|
4
|
================================================================================================
|
|
5
|
|
|
6
|
REVIEW FINDING (abridged)
|
|
7
|
"the heartbeat teardown reuses StatusCode.SHUTDOWN (1001), which onClose already maps to the fixed
|
|
8
|
description 'SHUTDOWN (browser tab/window closed)' at Level.SEVERE [...] Every heartbeat expiry is
|
|
9
|
therefore logged as a browser tab close that did not happen, immediately after the timer task's own
|
|
10
|
LOG.severe for the same event - two SEVERE lines for one peer disconnect, one factually wrong, on
|
|
11
|
the path support engineers triage - and a heartbeat expiry becomes indistinguishable from a genuine
|
|
12
|
tab close by status code alone. [...] Behaviourally harmless [...] so a distinct code (SERVER_ERROR,
|
|
13
|
as onError already uses, or an application 4xxx code) plus a matching case would keep the
|
|
14
|
diagnostics honest at no functional cost."
|
|
15
|
|
|
16
|
FILES
|
|
17
|
src/com/goldencode/p2j/ui/client/driver/web/WebClientProtocol.java
|
|
18
|
src/com/goldencode/p2j/ui/client/driver/web/res/p2j.socket.js (log-name table only)
|
|
19
|
|
|
20
|
------------------------------------------------------------------------------------------------
|
|
21
|
1. ROOT CAUSE
|
|
22
|
------------------------------------------------------------------------------------------------
|
|
23
|
|
|
24
|
WebClientProtocol.java:1733 closes with StatusCode.SHUTDOWN, and onClose maps that code to a fixed
|
|
25
|
description at :697-702:
|
|
26
|
|
|
27
|
case StatusCode.SHUTDOWN:
|
|
28
|
// RFC 6455 7.4.1: 1001 "Going Away" - browser tab/window closed or
|
|
29
|
// navigated away, so technically not severe, however for FWD this complicates
|
|
30
|
// the business code flow, so marked as severe
|
|
31
|
codeDesc = "SHUTDOWN (browser tab/window closed)";
|
|
32
|
break;
|
|
33
|
|
|
34
|
So a heartbeat expiry produces:
|
|
35
|
|
|
36
|
SEVERE No websocket message received for 91234 ms (deadline=90000 ms), the peer is gone ...
|
|
37
|
SEVERE WebSocket session closing: statusCode=1001 SHUTDOWN (browser tab/window closed),
|
|
38
|
reason='client heartbeat stopped'.
|
|
39
|
|
|
40
|
Two SEVERE lines for one disconnect, the second one asserting an event that did not occur. 1001 is also
|
|
41
|
semantically wrong in the RFC sense: "Going Away" describes the *endpoint that sends the frame* going
|
|
42
|
away, and here the server is not going anywhere - it is evicting a peer.
|
|
43
|
|
|
44
|
------------------------------------------------------------------------------------------------
|
|
45
|
2. PROPOSED FIX
|
|
46
|
------------------------------------------------------------------------------------------------
|
|
47
|
|
|
48
|
2.1 A distinct application close code
|
|
49
|
--------------------------------------
|
|
50
|
|
|
51
|
Use the RFC 6455 4000-4999 private-use range rather than SERVER_ERROR (1011): the peer's silence is not
|
|
52
|
a server error, and 1011 is already onError's code (WebClientProtocol.java:802), so reusing it would
|
|
53
|
recreate the same ambiguity one code over. Add, next to the other keep-alive constants:
|
|
54
|
|
|
55
|
+ /**
|
|
56
|
+ * The web socket close code sent when the peer stops answering the keep-alive heartbeat.
|
|
57
|
+ * <p>
|
|
58
|
+ * A private range code (RFC 6455 7.4.2) rather than SHUTDOWN, which means "this endpoint is going
|
|
59
|
+ * away" and is already mapped to a browser tab close, or SERVER_ERROR, which onError already uses.
|
|
60
|
+ * The distinction matters operationally: a heartbeat expiry and a tab close are triaged
|
|
61
|
+ * differently, and by status code alone they would otherwise be indistinguishable.
|
|
62
|
+ */
|
|
63
|
+ private static final int SESSION_HEARTBEAT_LOST = 4001;
|
|
64
|
|
|
65
|
and at the teardown site:
|
|
66
|
|
|
67
|
- session.close(StatusCode.SHUTDOWN, "client heartbeat stopped", Callback.NOOP);
|
|
68
|
+ session.close(SESSION_HEARTBEAT_LOST, "client heartbeat stopped", Callback.NOOP);
|
|
69
|
|
|
70
|
2.2 Map it in onClose
|
|
71
|
----------------------
|
|
72
|
|
|
73
|
In the switch (WebClientProtocol.java:691-729), before the default:
|
|
74
|
|
|
75
|
+ case SESSION_HEARTBEAT_LOST:
|
|
76
|
+ codeDesc = "HEARTBEAT_LOST (the client stopped answering the keep-alive)";
|
|
77
|
+ break;
|
|
78
|
|
|
79
|
Placement note: the case labels are StatusCode constants; SESSION_HEARTBEAT_LOST is a private static
|
|
80
|
final int, which is a compile-time constant and therefore a legal case label. Verify no other case in
|
|
81
|
the switch collides with 4001 (none do - all are 10xx).
|
|
82
|
|
|
83
|
Behaviour is preserved: the only status-sensitive logic is
|
|
84
|
`long wd = statusCode == StatusCode.NORMAL ? 0 : wdtimeout;` (:753), and 4001 is not NORMAL, so the
|
|
85
|
watchdog is armed exactly as before. logLevel also stays SEVERE, as for every non-NORMAL code.
|
|
86
|
|
|
87
|
2.3 Remove the duplicate SEVERE
|
|
88
|
--------------------------------
|
|
89
|
|
|
90
|
Since onClose now logs an accurate SEVERE line for this event, the timer task's own line becomes the
|
|
91
|
*detail* rather than the alarm. Demote it so one disconnect produces one SEVERE:
|
|
92
|
|
|
93
|
- LOG.severe(String.format(
|
|
94
|
+ LOG.warning(String.format(
|
|
95
|
"No websocket message received for %d ms (deadline=%d ms, ...), the peer is gone " +
|
|
96
|
"or its page is no longer running; closing the session!",
|
|
97
|
...
|
|
98
|
|
|
99
|
If the diagnostic detail is considered important enough to keep at SEVERE, leave it - the finding's
|
|
100
|
substantive complaint is the factually wrong description, not the duplication. Pick one; do not leave
|
|
101
|
two SEVERE lines where one of them says "browser tab/window closed".
|
|
102
|
|
|
103
|
2.4 Client-side log name
|
|
104
|
-------------------------
|
|
105
|
|
|
106
|
p2j.socket.js builds its close-event log message from a name table
|
|
107
|
(`ceCodes_names[(event.code).toString(10)]`, p2j.socket.js:5638 and :5645), so an unmapped 4001 prints
|
|
108
|
`undefined`. Add to the ceCodes table (p2j.socket.js:781-...), after the standard codes:
|
|
109
|
|
|
110
|
+ /**
|
|
111
|
+ * FWD private code: the server closed the connection because this page stopped answering the
|
|
112
|
+ * keep-alive heartbeat. See WebClientProtocol.SESSION_HEARTBEAT_LOST.
|
|
113
|
+ */
|
|
114
|
+ Heartbeat_Lost : 4001,
|
|
115
|
|
|
116
|
Keep the two constants' comments pointing at each other; they are a wire contract across two languages
|
|
117
|
with nothing to enforce agreement.
|
|
118
|
|
|
119
|
------------------------------------------------------------------------------------------------
|
|
120
|
3. WHY 4001 IS SAFE ON THE WIRE
|
|
121
|
------------------------------------------------------------------------------------------------
|
|
122
|
|
|
123
|
- RFC 6455 7.4.2 reserves 4000-4999 for private use between endpoints; Jetty transmits it without
|
|
124
|
complaint (it is neither in the "not transmittable" set - 1005, 1006, 1015 - nor outside the valid
|
|
125
|
range).
|
|
126
|
- Browsers surface it verbatim as CloseEvent.code, and p2j.socket.js does not branch on the code for
|
|
127
|
anything except the log message (verified: the only uses are the two log lines above).
|
|
128
|
- No FWD code compares against StatusCode.SHUTDOWN, so nothing loses a match.
|
|
129
|
|
|
130
|
------------------------------------------------------------------------------------------------
|
|
131
|
4. RELATIONSHIP TO OTHER PROPOSALS
|
|
132
|
------------------------------------------------------------------------------------------------
|
|
133
|
|
|
134
|
proposal-issue-major-performance-1 the composed tick body uses SESSION_HEARTBEAT_LOST defined here
|
|
135
|
proposal-issue-minor-security-1 extends the same log line with the grace-limit figures
|
|
136
|
|
|
137
|
Independent of all of them in principle - 2.1 and 2.2 can land alone - but the constant is referenced by
|
|
138
|
the composed listings, so land this one first or adjust those hunks.
|
|
139
|
|
|
140
|
------------------------------------------------------------------------------------------------
|
|
141
|
5. VERIFICATION
|
|
142
|
------------------------------------------------------------------------------------------------
|
|
143
|
|
|
144
|
1. Force a heartbeat expiry (SIGSTOP the browser, or blackhole its route) and check the server log
|
|
145
|
contains exactly one SEVERE, reading "statusCode=4001 HEARTBEAT_LOST (the client stopped
|
|
146
|
answering the keep-alive), reason='client heartbeat stopped'".
|
|
147
|
2. Close a browser tab normally: still "statusCode=1001 SHUTDOWN (browser tab/window closed)".
|
|
148
|
3. Check the JS console on a forced expiry (a second tab of the same session, or the reconnect
|
|
149
|
attempt) reads "Connection closed with code = Heartbeat_Lost", not "undefined".
|
|
150
|
4. Confirm the watchdog is still armed after a 4001 close (log line "Stopping pushWorker, webWorker
|
|
151
|
and starting watchdog with timeout=120000").
|