Closed kshep92 closed 3 months ago
The above code works as expected in embedded Tomcat.
I can't reproduce, at least not in head of 12.0.x. I added the following to ServerTest
:
static Logger LOG = LoggerFactory.getLogger(ServletTest.class);
class AppServlet extends HttpServlet
{
@Override
protected void service(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException
{
LOG.info("Service " + req);
ScheduledExecutorService scheduler = Executors.newSingleThreadScheduledExecutor();
resp.setContentType("text/event-stream");
resp.setCharacterEncoding("UTF-8");
resp.flushBuffer();
AsyncContext async = req.startAsync(req, resp);
var out = async.getResponse().getWriter();
async.addListener(new AsyncListener()
{
@Override
public void onComplete(AsyncEvent asyncEvent) throws IOException
{
LOG.info("Async context completed");
}
@Override
public void onTimeout(AsyncEvent asyncEvent) throws IOException
{
}
@Override
public void onError(AsyncEvent asyncEvent) throws IOException
{
LOG.info("There was an error: %s\n", asyncEvent.getThrowable().getMessage());
}
@Override
public void onStartAsync(AsyncEvent asyncEvent) throws IOException
{
LOG.info("Started async context");
}
});
AtomicInteger c = new AtomicInteger(0);
scheduler.scheduleAtFixedRate(() ->
{
try
{
out.println("Hello, world! %d\n".formatted(c.incrementAndGet()));
async.getResponse().flushBuffer();
}
catch (IOException e)
{
LOG.warn("Got an exception", e);
async.complete();
scheduler.shutdown();
}
}, 0, 2, TimeUnit.SECONDS);
}
}
@Test
public void testIssue() throws Exception
{
_context.addServlet(new AppServlet(), "/*");
ServerConnector connector = new ServerConnector(_server);
_server.addConnector(connector);
_server.start();
LOG.info("listening on {}", connector);
int port = connector.getLocalPort();
Socket socket = new Socket("localhost", port);
InputStream in = socket.getInputStream();
OutputStream out = socket.getOutputStream();
out.write("""
GET /ctx/test HTTP/1.1\r
Host: localhost\r
""".getBytes(StandardCharsets.US_ASCII));
for (int i = 0; i < 4; i++)
{
byte[] buf = new byte[1024];
int l = in.read(buf, 0, buf.length);
LOG.info("client read {}", l);
if (l > 0)
LOG.info("read '{}'", new String(buf, 0, l));
}
socket.close();
Thread.sleep(10000);
LOG.info("Test over");
}
which produces the following output:
[2024-07-08T09:18:54.241+1000][info][gc] Using G1
WARNING: Unknown module: org.eclipse.jetty.logging specified to --add-reads
java version "17.0.10" 2024-01-16 LTS
Java(TM) SE Runtime Environment (build 17.0.10+11-LTS-240)
Java HotSpot(TM) 64-Bit Server VM (build 17.0.10+11-LTS-240, mixed mode)
2024-07-08 09:18:54.968:INFO :oejs.Server:main: jetty-12.0.12-SNAPSHOT; built: unknown; git: ; jvm 17.0.10+11-LTS-240
2024-07-08 09:18:55.003:INFO :oejsh.ContextHandler:main: Started oeje10s.ServletContextHandler@302c971f{/ctx,/ctx,b=null,a=AVAILABLE,h=oeje10s.ServletHandler@1972e513{STARTED}}
2024-07-08 09:18:55.007:INFO :oejes.ServletContextHandler:main: Started oeje10s.ServletContextHandler@302c971f{/ctx,/ctx,b=null,a=AVAILABLE,h=oeje10s.ServletHandler@1972e513{STARTED}}
2024-07-08 09:18:55.008:INFO :oejs.AbstractConnector:main: Started LocalConnector@52f27fbd{HTTP/1.1, (http/1.1)}
2024-07-08 09:18:55.015:INFO :oejs.AbstractConnector:main: Started ServerConnector@6cb107fd{HTTP/1.1, (http/1.1)}{0.0.0.0:36121}
2024-07-08 09:18:55.024:INFO :oejs.Server:main: Started oejs.Server@53fe15ff{STARTING}[12.0.12-SNAPSHOT,sto=0] @798ms
2024-07-08 09:18:55.024:INFO :oejes.ServletTest:main: listening on ServerConnector@6cb107fd{HTTP/1.1, (http/1.1)}{0.0.0.0:36121}
2024-07-08 09:18:55.078:INFO :oejes.ServletTest:qtp198499365-38: Service org.eclipse.jetty.ee10.servlet.ServletApiRequest@71a327ca
2024-07-08 09:18:55.080:INFO :oejes.ServletTest:main: client read 164
2024-07-08 09:18:55.080:INFO :oejes.ServletTest:main: read 'HTTP/1.1 200 OK<|Server: Jetty(12.0.12-SNAPSHOT)<|Date: Sun, 07 Jul 2024 23:18:55 GMT<|Content-Type: text/event-stream;charset=utf-8<|Transfer-Encoding: chunked<|<|'
2024-07-08 09:18:55.083:INFO :oejes.ServletTest:main: client read 21
2024-07-08 09:18:55.083:INFO :oejes.ServletTest:main: read '11<|Hello, world! 1||'
2024-07-08 09:18:57.083:INFO :oejes.ServletTest:main: client read 23
2024-07-08 09:18:57.084:INFO :oejes.ServletTest:main: read '<|11<|Hello, world! 2||'
2024-07-08 09:18:59.083:INFO :oejes.ServletTest:main: client read 23
2024-07-08 09:18:59.083:INFO :oejes.ServletTest:main: read '<|11<|Hello, world! 3||'
2024-07-08 09:19:03.087:WARN :oejes.ServletTest:pool-1-thread-1: Got an exception
org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.SocketChannelEndPoint.flush(SocketChannelEndPoint.java:117)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:275)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:254)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:368)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpConnection$SendCallback.process(HttpConnection.java:840)
at org.eclipse.jetty.util@12.0.12-SNAPSHOT/org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
at org.eclipse.jetty.util@12.0.12-SNAPSHOT/org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpConnection$HttpStreamOverHTTP1.send(HttpConnection.java:1421)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.HttpStream$Wrapper.send(HttpStream.java:179)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpChannelState$ChannelResponse.write(HttpChannelState.java:1292)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.Response$Wrapper.write(Response.java:751)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.handler.ContextResponse.write(ContextResponse.java:56)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletContextResponse.write(ServletContextResponse.java:288)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:206)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:191)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.flush(HttpOutput.java:685)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletApiResponse.flushBuffer(ServletApiResponse.java:405)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletTest$AppServlet.lambda$service$0(ServletTest.java:299)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:842)
Caused by:
java.io.IOException: Broken pipe
at java.base/sun.nio.ch.FileDispatcherImpl.writev0(Native Method)
at java.base/sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:66)
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:217)
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:153)
at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:563)
at java.base/java.nio.channels.SocketChannel.write(SocketChannel.java:642)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.SocketChannelEndPoint.flush(SocketChannelEndPoint.java:111)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:275)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:254)
at org.eclipse.jetty.io@12.0.12-SNAPSHOT/org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:368)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpConnection$SendCallback.process(HttpConnection.java:840)
at org.eclipse.jetty.util@12.0.12-SNAPSHOT/org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:262)
at org.eclipse.jetty.util@12.0.12-SNAPSHOT/org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpConnection$HttpStreamOverHTTP1.send(HttpConnection.java:1421)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.HttpStream$Wrapper.send(HttpStream.java:179)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.internal.HttpChannelState$ChannelResponse.write(HttpChannelState.java:1292)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.Response$Wrapper.write(Response.java:751)
at org.eclipse.jetty.server@12.0.12-SNAPSHOT/org.eclipse.jetty.server.handler.ContextResponse.write(ContextResponse.java:56)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletContextResponse.write(ServletContextResponse.java:288)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:206)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:191)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.HttpOutput.flush(HttpOutput.java:685)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletApiResponse.flushBuffer(ServletApiResponse.java:405)
at org.eclipse.jetty.ee10.servlet@12.0.12-SNAPSHOT/org.eclipse.jetty.ee10.servlet.ServletTest$AppServlet.lambda$service$0(ServletTest.java:299)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:842)
2024-07-08 09:19:03.093:INFO :oejes.ServletTest:pool-1-thread-1: Async context completed
2024-07-08 09:19:09.085:INFO :oejes.ServletTest:main: Test over
2024-07-08 09:19:09.091:INFO :oejs.Server:main: Stopped oejs.Server@53fe15ff{STOPPING}[12.0.12-SNAPSHOT,sto=0]
2024-07-08 09:19:09.091:INFO :oejs.AbstractConnector:main: Stopped LocalConnector@52f27fbd{HTTP/1.1, (http/1.1)}
2024-07-08 09:19:09.096:INFO :oejs.AbstractConnector:main: Stopped ServerConnector@6cb107fd{HTTP/1.1, (http/1.1)}{0.0.0.0:0}
2024-07-08 09:19:09.098:INFO :oejes.ServletContextHandler:main: Stopped oeje10s.ServletContextHandler@302c971f{/ctx,/ctx,b=null,a=AVAILABLE,h=oeje10s.ServletHandler@1972e513{STOPPED}}
@kshep92 Can you turn your code into a stand-alone test that I can run? I can't see anything wrong with the code that you shared, and I think I've reproduced it faithfully enough. So either the difference is in how you set it up, or something in your network environment (but why does tomcat work then?).
Ok, so here's the servlet code once again:
public class SSEServlet extends HttpServlet {
@Override
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws ServletException, IOException {
ScheduledExecutorService scheduler = Executors.newSingleThreadScheduledExecutor();
resp.setContentType("text/event-stream");
resp.setCharacterEncoding("UTF-8");
resp.flushBuffer();
AsyncContext async = req.startAsync(req, resp);
async.setTimeout(0);
var out = async.getResponse().getWriter();
async.addListener(new AsyncListener() {
@Override
public void onComplete(AsyncEvent event) throws IOException {
System.out.println("Async Event Done!");
}
@Override
public void onTimeout(AsyncEvent event) throws IOException {
}
@Override
public void onError(AsyncEvent event) throws IOException {
System.out.println("Received an onError event: " + event.getThrowable().getMessage());
}
@Override
public void onStartAsync(AsyncEvent event) throws IOException {
}
});
String currentThreadName = Thread.currentThread().getName();
scheduler.scheduleAtFixedRate(() -> {
try {
out.println("data: Hello, from "+currentThreadName+"\n");
async.getResponse().flushBuffer();
} catch (IOException e) {
System.err.println("We caught an error: " + e.getMessage());
async.complete();
scheduler.shutdown();
}
}, 0, 2, TimeUnit.SECONDS);
}
}
And here's the main class:
public class SimpleJettyApplication {
public static void main(String[] args) throws Exception {
Logger log = LoggerFactory.getLogger(SimpleJettyApplication.class);
// Create and configure a ThreadPool.
QueuedThreadPool threadPool = new QueuedThreadPool();
threadPool.setName("server");
// Create a Server instance.
Server server = new Server(threadPool);
HttpConnectionFactory httpConnectionFactory = new HttpConnectionFactory();
// Create a ServerConnector to accept connections from clients. 1 acceptor, 1 selector listening on http://0.0.0.0:8080
ServerConnector connector = new ServerConnector(server, 1, 1, httpConnectionFactory);
connector.setPort(8080);
connector.setHost("0.0.0.0");
server.addConnector(connector);
ServletContextHandler servletContextHandler = new ServletContextHandler("");
final var servletHolder = servletContextHandler.addServlet(new SSEServlet(), "/");
servletHolder.setAsyncSupported(true);
server.setHandler(servletContextHandler);
server.start();
}
}
SimpleJettyApplication
http://localhost:8080
in any browser and observe the event stream.For reference, here is how I set up my Tomcat application, using the same servlet:
public class TomcatApplication extends HttpServlet {
public static void main(String[] args) {
File baseDir = new File(".catalina");
if(!baseDir.exists()) baseDir.mkdir();
Tomcat tomcat = new Tomcat();
tomcat.setBaseDir(baseDir.getAbsolutePath());
String docBase = new File("public").getAbsolutePath();
Context appContext = tomcat.addContext("", docBase);
final var routerWrapper = tomcat.addServlet("", "sse", new SSEServlet());
routerWrapper.setAsyncSupported(true);
appContext.addServletMappingDecoded("/", "sse");
try {
tomcat.getConnector();
tomcat.start();
tomcat.getServer().await();
} catch (LifecycleException e) {
throw new RuntimeException(e);
}
}
}
I reran the code from a smaller project (jetty-issue-12008.zip) and I can confirm that the catch block is being executed. It turns out that once you include Logback, and you set Jetty's log level to anything lower than INFO
, it causes IntelliJ to report an error when the EofException
is raised:
Which lead me to believe that the catch block wasn't being honoured. Setting the Jetty logger to INFO
or above allows the application to behave normally.
Great. So can you close this issue or do think there is something strange with our integration with logback?
I think the core of the issue has been resolved, therefore I will close it. The issue with the logback integration can be another discussion. Thank you so much for your help!
Jetty Version 12.0.10 Jetty Environment
ee10 Java Version 17 Question I have the following code:
When I run the server and close the connection on the client side to trigger an IOException, my catch bock never runs, nor does any of my listener code. Instead I see the following console output and the while loop continues as normal, attempting to write to the PrintWriter:
This is how I am mounting the servlet: