From 93ac72ea0cb49fdffec9a9bea9c56112296c97d9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?J=C3=B6rg=20Prante?= Date: Fri, 31 Mar 2023 17:54:30 +0200 Subject: [PATCH] working on response flush bugs, move logging to FINEST level --- .../server/netty/HttpResponseBuilder.java | 104 ++++++++--------- .../http/server/netty/NettyHttpServer.java | 8 +- .../http/server/BaseHttpResponseBuilder.java | 4 +- .../http/server/BaseHttpServerContext.java | 5 + .../net/http/server/HttpServerContext.java | 3 + .../http/server/application/Application.java | 3 + .../application/ApplicationBuilder.java | 7 ++ .../ApplicationThreadPoolExecutor.java | 6 +- .../server/application/BaseApplication.java | 16 ++- .../application/BaseApplicationBuilder.java | 12 ++ .../auth/LoginAuthenticationHandler.java | 6 +- .../resource/AbstractResourceHandler.java | 106 +++++++++++------- .../server/resource/HtmlTemplateResource.java | 8 +- .../session/IncomingSessionHandler.java | 2 +- .../session/OutgoingSessionHandler.java | 6 +- .../groovy/DefaultMarkupTemplate.java | 2 +- .../groovy/DefaultTemplateResolver.java | 2 +- ...oovyHttpResonseStatusTemplateResource.java | 5 +- .../groovy/GroovyTemplateRenderer.java | 2 +- .../groovy/GroovyTemplateResource.java | 20 ++-- 20 files changed, 195 insertions(+), 132 deletions(-) diff --git a/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/HttpResponseBuilder.java b/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/HttpResponseBuilder.java index df9c77b..4ced16d 100644 --- a/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/HttpResponseBuilder.java +++ b/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/HttpResponseBuilder.java @@ -137,13 +137,17 @@ public class HttpResponseBuilder extends BaseHttpResponseBuilder { internalFileWrite(fileChannel, bufferSize, true); } else if (inputStream != null) { internalStreamWrite(inputStream, bufferSize, true); + } else { + logger.log(Level.FINEST, "no content, we assume header only"); + flush(); } return new HttpResponse(this); } - public void flush() { - internalBufferWrite(Unpooled.buffer(0)); + logger.log(Level.FINEST, "flush netty response"); + this.dataBuffer = NettyDataBufferFactory.getInstance().wrap(Unpooled.buffer(0)); + internalBufferWrite(dataBuffer); } @Override @@ -187,23 +191,23 @@ public class HttpResponseBuilder extends BaseHttpResponseBuilder { } HttpHeaders trailingHeaders = new DefaultHttpHeaders(); super.trailingHeaders.entries().forEach(e -> trailingHeaders.add(e.getKey(), e.getValue())); - ctx.channel().eventLoop().execute(() -> { - FullHttpResponse fullHttpResponse = new DefaultFullHttpResponse(HttpVersion.valueOf(version.text()), - responseStatus, byteBuf.retain(), headers, trailingHeaders); - ChannelFuture channelFuture; - if (sequenceId != null) { - HttpPipelinedResponse httpPipelinedResponse = new HttpPipelinedResponse(fullHttpResponse, - ctx.channel().newPromise(), sequenceId); - channelFuture = ctx.write(httpPipelinedResponse); - } else { - channelFuture = ctx.write(fullHttpResponse); - } - if (!keepAlive || shouldClose()) { - logger.log(Level.FINER, "adding close listener to channel future " + channelFuture); - channelFuture.addListener(CLOSE); - } - ctx.flush(); - }); + HttpVersion httpVersion = HttpVersion.valueOf(version.text()); + FullHttpResponse fullHttpResponse = + new DefaultFullHttpResponse(httpVersion, responseStatus, byteBuf.retain(), headers, trailingHeaders); + ChannelFuture channelFuture; + if (sequenceId != null) { + HttpPipelinedResponse httpPipelinedResponse = new HttpPipelinedResponse(fullHttpResponse, + ctx.channel().newPromise(), sequenceId); + channelFuture = ctx.write(httpPipelinedResponse); + } else { + channelFuture = ctx.write(fullHttpResponse); + } + if (!keepAlive || shouldClose()) { + logger.log(Level.FINEST, "adding close listener to channel future " + channelFuture); + channelFuture.addListener(CLOSE); + } + logger.log(Level.FINEST, "flush netty ctx"); + ctx.flush(); } private void internalFileWrite(FileChannel fileChannel, int bufferSize, boolean keepAlive) { @@ -213,20 +217,19 @@ public class HttpResponseBuilder extends BaseHttpResponseBuilder { } HttpResponseStatus responseStatus = HttpResponseStatus.valueOf(status.code()); DefaultHttpResponse rsp = new DefaultHttpResponse(HttpVersion.HTTP_1_1, responseStatus); - ctx.channel().eventLoop().execute(() -> { - ctx.write(rsp); - try { - ctx.write(new ChunkedNioFile(fileChannel, bufferSize)); - } catch (IOException e) { - throw new UncheckedIOException(e); - } - ChannelFuture channelFuture = ctx.writeAndFlush(LastHttpContent.EMPTY_LAST_CONTENT); - if (!keepAlive || shouldClose()) { - logger.log(Level.FINER, "adding close listener to channel future " + channelFuture); - channelFuture.addListener(CLOSE); - } - ctx.flush(); - }); + ctx.write(rsp); + try { + ctx.write(new ChunkedNioFile(fileChannel, bufferSize)); + } catch (IOException e) { + throw new UncheckedIOException(e); + } + ChannelFuture channelFuture = ctx.writeAndFlush(LastHttpContent.EMPTY_LAST_CONTENT); + if (!keepAlive || shouldClose()) { + logger.log(Level.FINEST, "adding close listener to channel future " + channelFuture); + channelFuture.addListener(CLOSE); + } + logger.log(Level.FINEST, "flush netty ctx"); + ctx.flush(); } private void internalStreamWrite(InputStream inputStream, int bufferSize, boolean keepAlive) { @@ -260,25 +263,24 @@ public class HttpResponseBuilder extends BaseHttpResponseBuilder { } HttpHeaders trailingHeaders = new DefaultHttpHeaders(); super.trailingHeaders.entries().forEach(e -> trailingHeaders.add(e.getKey(), e.getValue())); - ctx.channel().eventLoop().execute(() -> { - DefaultHttpResponse defaultHttpResponse = new DefaultHttpResponse(HttpVersion.HTTP_1_1, responseStatus); - if (!headers.contains(HttpHeaderNames.CONTENT_LENGTH)) { - headers.set(HttpHeaderNames.TRANSFER_ENCODING, HttpHeaderValues.CHUNKED); - } else { - if (keepAlive) { - headers.set(HttpHeaderNames.CONNECTION, HttpHeaderValues.KEEP_ALIVE); - } + DefaultHttpResponse defaultHttpResponse = new DefaultHttpResponse(HttpVersion.HTTP_1_1, responseStatus); + if (!headers.contains(HttpHeaderNames.CONTENT_LENGTH)) { + headers.set(HttpHeaderNames.TRANSFER_ENCODING, HttpHeaderValues.CHUNKED); + } else { + if (keepAlive) { + headers.set(HttpHeaderNames.CONNECTION, HttpHeaderValues.KEEP_ALIVE); } - defaultHttpResponse.headers().set(headers); - ctx.write(defaultHttpResponse); - ctx.write(new ChunkedStream(inputStream, bufferSize)); - ChannelFuture channelFuture = ctx.writeAndFlush(LastHttpContent.EMPTY_LAST_CONTENT); - if (!keepAlive || shouldClose) { - logger.log(Level.FINER, "adding close listener to channel future " + channelFuture); - channelFuture.addListener(CLOSE); - } - ctx.flush(); - }); + } + defaultHttpResponse.headers().set(headers); + ctx.write(defaultHttpResponse); + ctx.write(new ChunkedStream(inputStream, bufferSize)); + ChannelFuture channelFuture = ctx.writeAndFlush(LastHttpContent.EMPTY_LAST_CONTENT); + if (!keepAlive || shouldClose) { + logger.log(Level.FINEST, "adding close listener to channel future " + channelFuture); + channelFuture.addListener(CLOSE); + } + logger.log(Level.FINEST, "flush netty ctx"); + ctx.flush(); } } } diff --git a/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/NettyHttpServer.java b/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/NettyHttpServer.java index 70c89b0..15093e8 100644 --- a/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/NettyHttpServer.java +++ b/net-http-server-netty/src/main/java/org/xbib/net/http/server/netty/NettyHttpServer.java @@ -64,7 +64,7 @@ public class NettyHttpServer implements HttpServer { this.serviceLoader = ServiceLoader.load(HttpChannelInitializer.class); this.channelFutures = new ArrayList<>(); this.channels = new ArrayList<>(); - logger.log(Level.INFO, "parent event loop group = " + parentEventLoopGroup + + logger.log(Level.FINE, "parent event loop group = " + parentEventLoopGroup + " child event loop group = " + childEventLoopGroup + " socket channel class = " + socketChannelClass + " router addresses = " + getApplication().getAddresses()); @@ -85,7 +85,7 @@ public class NettyHttpServer implements HttpServer { @Override public void bind() throws BindException { Set httpAddressSet = getApplication().getAddresses(); - logger.log(Level.INFO, "http adresses = " + httpAddressSet); + logger.log(Level.FINE, "http adresses = " + httpAddressSet); for (HttpAddress httpAddress : httpAddressSet) { SocketConfig socketConfig = httpAddress.getSocketConfig(); ServerBootstrap bootstrap = new ServerBootstrap() @@ -124,7 +124,7 @@ public class NettyHttpServer implements HttpServer { throw new IOException("unable to bind to " + httpAddress + " because network class " + detectedNetworkClass + " is not allowed by configured network class " + configuredNetworkClass); } - logger.log(Level.INFO, () -> "trying to bind to " + inetSocketAddress); + logger.log(Level.FINE, () -> "trying to bind to " + inetSocketAddress); channelFutures.add(bootstrap.bind(inetSocketAddress)); } catch (IOException e) { throw new BindException(e.getMessage()); @@ -139,7 +139,7 @@ public class NettyHttpServer implements HttpServer { }); channels.add(channelFuture.sync().channel()); channelFuture.await(); - logger.log(Level.FINER, () -> channelFuture.channel() + " ready, listening"); + logger.log(Level.FINE, () -> channelFuture.channel() + " ready, listening"); } catch (InterruptedException e) { logger.log(Level.WARNING, e.getMessage(), e); } diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpResponseBuilder.java b/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpResponseBuilder.java index fc5334d..59eb82c 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpResponseBuilder.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpResponseBuilder.java @@ -340,7 +340,7 @@ public abstract class BaseHttpResponseBuilder implements HttpResponseBuilder { @Override public void done() { this.done = true; - logger.log(Level.FINER, "done"); + logger.log(Level.FINEST, "done"); } @Override @@ -379,7 +379,7 @@ public abstract class BaseHttpResponseBuilder implements HttpResponseBuilder { if (httpServerConfig != null && httpServerConfig.getServerName() != null) { headers.add(HttpHeaderNames.SERVER, httpServerConfig.getServerName()); } - logger.log(Level.FINER, "build headers: status = " + status + " headers = " + headers); + logger.log(Level.FINEST, () -> "headers: status = " + status + " headers = " + headers); } public CharBuffer wrapHeaders() { diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpServerContext.java b/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpServerContext.java index 81d1231..78b07b5 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpServerContext.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/BaseHttpServerContext.java @@ -75,6 +75,11 @@ public class BaseHttpServerContext implements HttpServerContext { this.attributes.put("ctx", this); } + @Override + public Application getApplication() { + return application; + } + @Override public HttpRequestBuilder request() { return httpRequestBuilder; diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/HttpServerContext.java b/net-http-server/src/main/java/org/xbib/net/http/server/HttpServerContext.java index a44b4bd..cbcab60 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/HttpServerContext.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/HttpServerContext.java @@ -9,11 +9,14 @@ import java.nio.file.Path; import org.xbib.net.Attributes; import org.xbib.net.URL; import org.xbib.net.buffer.DataBuffer; +import org.xbib.net.http.server.application.Application; import org.xbib.net.http.server.route.HttpRouteResolver; import org.xbib.net.http.server.service.HttpService; public interface HttpServerContext { + Application getApplication(); + HttpRequestBuilder request(); HttpResponseBuilder response(); diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/application/Application.java b/net-http-server/src/main/java/org/xbib/net/http/server/application/Application.java index 70a9553..295da79 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/application/Application.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/application/Application.java @@ -14,6 +14,7 @@ import org.xbib.net.http.server.HttpResponseBuilder; import org.xbib.net.http.server.HttpServerContext; import org.xbib.net.http.server.domain.HttpDomain; import org.xbib.net.http.server.session.SessionListener; +import org.xbib.net.mime.MimeTypeService; import org.xbib.settings.Settings; public interface Application extends SessionListener, Resolver, Closeable { @@ -26,6 +27,8 @@ public interface Application extends SessionListener, Resolver, Closeable ZoneId getZoneId(); + MimeTypeService getMimeService(); + Path getHome(); String getContextPath(); diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationBuilder.java b/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationBuilder.java index 23de792..518be93 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationBuilder.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationBuilder.java @@ -5,6 +5,7 @@ import java.time.ZoneId; import java.util.Locale; import java.util.concurrent.TimeUnit; import org.xbib.net.http.server.route.HttpRouter; +import org.xbib.net.mime.MimeTypeService; public interface ApplicationBuilder { @@ -30,5 +31,11 @@ public interface ApplicationBuilder { ApplicationBuilder setZoneId(ZoneId zoneId); + ApplicationBuilder setMimeTypeService(MimeTypeService mimeTypeService); + + ApplicationBuilder setStaticSuffixes(String... suffixes); + + ApplicationBuilder registerModule(ApplicationModule applicationModule); + Application build(); } diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationThreadPoolExecutor.java b/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationThreadPoolExecutor.java index 38cac70..8d46547 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationThreadPoolExecutor.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/application/ApplicationThreadPoolExecutor.java @@ -19,7 +19,7 @@ public class ApplicationThreadPoolExecutor extends ThreadPoolExecutor { long keepAliveTime, TimeUnit timeUnit, ThreadFactory threadFactory) { super(nThreads, nThreads, keepAliveTime, timeUnit, createBlockingQueue(maxQueue), threadFactory); - logger.log(Level.FINE, "threadpool executor up with nThreads = " + nThreads + + logger.log(Level.FINE, () -> "threadpool executor up with nThreads = " + nThreads + " keepAliveTime = " + keepAliveTime + " time unit = " + timeUnit + " maxQueue = " + maxQueue + @@ -38,14 +38,14 @@ public class ApplicationThreadPoolExecutor extends ThreadPoolExecutor { @Override protected void afterExecute(Runnable runnable, Throwable terminationCause) { super.afterExecute(runnable, terminationCause); - logger.log(Level.FINEST, "after execute of " + runnable); + logger.log(Level.FINEST, () -> "after execute of " + runnable); if (terminationCause != null) { logger.log(Level.SEVERE, terminationCause.getMessage(), terminationCause); return; } if (runnable instanceof RouterTask routerTask) { RouterCallable routerCallable = (RouterCallable) routerTask.getCallable(); - logger.log(Level.FINEST, "release " + routerCallable); + logger.log(Level.FINEST, () -> "releasing " + routerCallable); routerCallable.release(); } } diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplication.java b/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplication.java index 60cbbbf..56f3ee4 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplication.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplication.java @@ -34,6 +34,7 @@ import org.xbib.net.http.server.session.OutgoingSessionHandler; import org.xbib.net.http.server.session.Session; import org.xbib.net.http.server.session.memory.MemoryPropertiesSessionCodec; import org.xbib.net.http.server.validate.HttpRequestValidator; +import org.xbib.net.mime.MimeTypeService; import org.xbib.net.util.NamedThreadFactory; import org.xbib.net.util.RandomUtil; import org.xbib.settings.Settings; @@ -90,6 +91,11 @@ public class BaseApplication implements Application { return builder.zoneId; } + @Override + public MimeTypeService getMimeService() { + return builder.mimeTypeService; + } + public Path getHome() { return builder.home; } @@ -147,7 +153,7 @@ public class BaseApplication implements Application { } }; Future future = executor.submit(routerCallable); - logger.log(Level.FINE, "dispatched " + future); + logger.log(Level.FINEST, "dispatched " + future); } @Override @@ -169,7 +175,7 @@ public class BaseApplication implements Application { } }; Future future = executor.submit(routerCallable); - logger.log(Level.FINE, "dispatched status " + future); + logger.log(Level.FINEST, "dispatched status " + future); } @Override @@ -242,13 +248,13 @@ public class BaseApplication implements Application { @Override public void onCreated(Session session) { - logger.log(Level.FINE, "session name = " + sessionName + " created = " + session); + logger.log(Level.FINER, "session name = " + sessionName + " created = " + session); builder.applicationModuleList.forEach(module -> module.onOpen(this, session)); } @Override public void onDestroy(Session session) { - logger.log(Level.FINE, "session name = " + sessionName + " destroyed = " + session); + logger.log(Level.FINER, "session name = " + sessionName + " destroyed = " + session); builder.applicationModuleList.forEach(module -> module.onClose(this, session)); } @@ -342,7 +348,7 @@ public class BaseApplication implements Application { ((Closeable) outgoingSessionHandler).close(); } if (incomingSessionHandler != null && (incomingSessionHandler instanceof Closeable)) { - logger.log(Level.FINE, "application closing incming session handler"); + logger.log(Level.FINE, "application closing incoming session handler"); ((Closeable) incomingSessionHandler).close(); } if (sessionCodec != null && sessionCodec instanceof Closeable) { diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplicationBuilder.java b/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplicationBuilder.java index 6695c0b..c78cb2e 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplicationBuilder.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/application/BaseApplicationBuilder.java @@ -18,6 +18,7 @@ import org.xbib.config.ConfigLogger; import org.xbib.config.ConfigParams; import org.xbib.config.SystemConfigLogger; import org.xbib.net.http.server.route.HttpRouter; +import org.xbib.net.mime.MimeTypeService; import org.xbib.settings.Settings; public class BaseApplicationBuilder implements ApplicationBuilder { @@ -57,6 +58,8 @@ public class BaseApplicationBuilder implements ApplicationBuilder { protected ZoneId zoneId; + protected MimeTypeService mimeTypeService; + protected Set staticFileSuffixes; protected ConfigParams configParams; @@ -79,6 +82,7 @@ public class BaseApplicationBuilder implements ApplicationBuilder { this.sessionsEnabled = true; this.locale = Locale.getDefault(); this.zoneId = ZoneId.systemDefault(); + this.mimeTypeService = new MimeTypeService(); this.applicationModuleList = new ArrayList<>(); } @@ -153,11 +157,19 @@ public class BaseApplicationBuilder implements ApplicationBuilder { return this; } + @Override + public ApplicationBuilder setMimeTypeService(MimeTypeService mimeTypeService) { + this.mimeTypeService = mimeTypeService; + return this; + } + + @Override public ApplicationBuilder setStaticSuffixes(String... suffixes) { this.staticFileSuffixes = Set.of(suffixes); return this; } + @Override public ApplicationBuilder registerModule(ApplicationModule applicationModule) { applicationModuleList.add(applicationModule); return this; diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/auth/LoginAuthenticationHandler.java b/net-http-server/src/main/java/org/xbib/net/http/server/auth/LoginAuthenticationHandler.java index 38f01b6..5043bb4 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/auth/LoginAuthenticationHandler.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/auth/LoginAuthenticationHandler.java @@ -42,8 +42,8 @@ public class LoginAuthenticationHandler implements HttpHandler { userProfile = new BaseUserProfile(); try { authenticate(userProfile, - (String) context.httpRequest().getParameter().get(userParameterName, Parameter.Domain.DEFAULT, Parameter.Domain.FORM), - (String) context.httpRequest().getParameter().get(passwordParameterName, Parameter.Domain.DEFAULT, Parameter.Domain.FORM), + (String) context.httpRequest().getParameter().get(userParameterName, Parameter.Domain.FORM), + (String) context.httpRequest().getParameter().get(passwordParameterName, Parameter.Domain.FORM), context.httpRequest()); context.getAttributes().put("userprofile", userProfile); } catch (Exception e) { @@ -51,7 +51,7 @@ public class LoginAuthenticationHandler implements HttpHandler { } } - protected void authenticate(UserProfile userProfile, String username, String password, Request request) throws Exception { + protected void authenticate(UserProfile userProfile, String username, String password, Request request) { if (username == null) { logger.log(Level.FINE, "no username given for check, doing nothing"); return; diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/resource/AbstractResourceHandler.java b/net-http-server/src/main/java/org/xbib/net/http/server/resource/AbstractResourceHandler.java index b2f45b2..4dfee3b 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/resource/AbstractResourceHandler.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/resource/AbstractResourceHandler.java @@ -54,20 +54,17 @@ public abstract class AbstractResourceHandler implements HttpHandler { @Override public void handle(HttpServerContext context) throws IOException { - logger.log(Level.FINE, "handle: before creating resource " + this.getClass().getName()); + logger.log(Level.FINEST, () -> "handle: before creating resource " + this.getClass().getName()); Resource resource = createResource(context); - logger.log(Level.FINE, "handle: resource = " + (resource != null ? resource.getClass().getName() + " " + resource : null)); + logger.log(Level.FINEST, () -> "handle: resource = " + (resource != null ? resource.getClass().getName() + " " + resource : null)); if (resource instanceof HtmlTemplateResource) { - logger.log(Level.FINE, "handle: HTML template resource, generate cacheable resource"); generateCacheableResource(context, resource); - logger.log(Level.FINE, "handle: done"); return; } if (resource == null) { - logger.log(Level.FINER, "resource is null: " + resource); throw new HttpException("resource not found", context, HttpResponseStatus.NOT_FOUND); } else if (resource.isDirectory()) { - logger.log(Level.FINER, "we have a directory request"); + logger.log(Level.FINEST, "we have a directory request"); if (!resource.getResourcePath().isEmpty() && !resource.getResourcePath().endsWith("/")) { URL url = context.request().getBaseURL(); String loc = url.resolve(resource.getName() + '/') @@ -76,59 +73,66 @@ public abstract class AbstractResourceHandler implements HttpHandler { .fragment(url.getFragment()) .build() .toString(); - logger.log(Level.FINER, "client must add a /, external redirect to = " + loc); + logger.log(Level.FINEST, "client must add a /, external redirect to = " + loc); context.response() .addHeader(HttpHeaderNames.LOCATION, loc) .setResponseStatus(HttpResponseStatus.TEMPORARY_REDIRECT) // 307 - .build().flush(); // flush is important + .build(); } else if (resource.isExistsIndexFile()) { // internal redirect to default index file in this directory - logger.log(Level.FINER, "internal redirect to default index file in this directory: " + resource.getIndexFileName()); + logger.log(Level.FINEST, "internal redirect to default index file in this directory: " + resource.getIndexFileName()); generateCacheableResource(context, resource); } else { // send forbidden, we do not allow directory access context.response() .setResponseStatus(HttpResponseStatus.FORBIDDEN) - .build() - .flush(); // write status + .build(); } context.done(); } else { - logger.log(Level.FINER, "handle: generate cacheable resource"); generateCacheableResource(context, resource); context.done(); } - logger.log(Level.FINER, "handle: done"); } - private void generateCacheableResource(HttpServerContext context, Resource resource) throws IOException { - // if resource is length of 0, there is nothing to send. Do not send any content, + private void generateCacheableResource(HttpServerContext context, + Resource resource) throws IOException { + // if resource is length of 0, there is nothing to send. Do not send any content if (resource.getLength() == 0) { - logger.log(Level.FINER, "the resource length is 0, do nothing"); - context.response().build().flush(); + logger.log(Level.FINEST, "the resource length is 0, return not found"); + context.response() + .setResponseStatus(HttpResponseStatus.NOT_FOUND) + .build(); return; } HttpHeaders headers = context.request().getHeaders(); - logger.log(Level.FINER, "before generating resource, the response headers are " + context.response().getHeaders()); + logger.log(Level.FINEST, () -> "before generating resource, the response headers are " + context.response().getHeaders()); String contentType = resource.getMimeType(); context.response().addHeader(HttpHeaderNames.CONTENT_TYPE, contentType); // heuristic for inline disposition - String disposition = "inline"; - if (!contentType.startsWith("text") && !contentType.startsWith("image")) { + String disposition; + if (!contentType.startsWith("text") && !contentType.startsWith("image") && !contentType.startsWith("font")) { String accept = context.request().getHeaders().get(HttpHeaderNames.ACCEPT); disposition = accept != null && accepts(accept, contentType) ? "inline" : "attachment"; + } else { + disposition = "inline"; } if (resource.getBaseName() != null && resource.getSuffix() != null) { + String contentDisposition = disposition + ";filename=\"" + resource.getBaseName() + '.' + resource.getSuffix() + '"'; + logger.log(Level.FINEST, () -> "content type = " + contentType + " content disposition = " + contentDisposition); context.response() - .addHeader(HttpHeaderNames.CONTENT_DISPOSITION, - disposition + ";filename=\"" + resource.getBaseName() + '.' + resource.getSuffix() + '"'); + .addHeader(HttpHeaderNames.CONTENT_DISPOSITION, contentDisposition); } long expirationMillis = System.currentTimeMillis() + 1000L * getMaxAgeSeconds(); + String expires = DateTimeUtil.formatRfc1123(expirationMillis); if (isCacheResponseEnabled()) { + String cacheControl = "public, max-age=" + getMaxAgeSeconds(); + logger.log(Level.FINEST, () -> "cache response, expires = " + expires + " cache control = " + cacheControl); context.response() - .addHeader(HttpHeaderNames.EXPIRES, DateTimeUtil.formatRfc1123(expirationMillis)) - .addHeader(HttpHeaderNames.CACHE_CONTROL, "public, max-age=" + getMaxAgeSeconds()); + .addHeader(HttpHeaderNames.EXPIRES, expires) + .addHeader(HttpHeaderNames.CACHE_CONTROL, cacheControl); } else { + logger.log(Level.FINEST, () -> "uncached response"); context.response() .addHeader(HttpHeaderNames.EXPIRES, "0") .addHeader(HttpHeaderNames.CACHE_CONTROL, "no-cache, no-store, must-revalidate"); @@ -137,46 +141,53 @@ public abstract class AbstractResourceHandler implements HttpHandler { if (isETagResponseEnabled()) { Instant lastModifiedInstant = resource.getLastModified(); String eTag = Long.toHexString(resource.getResourcePath().hashCode() + lastModifiedInstant.toEpochMilli() + resource.getLength()); + logger.log(Level.FINEST, () -> "eTag = " + eTag); Instant ifUnmodifiedSinceInstant = DateTimeUtil.parseDate(headers.get(HttpHeaderNames.IF_UNMODIFIED_SINCE)); if (ifUnmodifiedSinceInstant != null && ifUnmodifiedSinceInstant.plusMillis(1000L).isAfter(lastModifiedInstant)) { + logger.log(Level.FINEST, () -> "precondition failed, lastModified = " + lastModifiedInstant + " ifUnmodifiedSince = " + ifUnmodifiedSinceInstant); context.response() .setResponseStatus(HttpResponseStatus.PRECONDITION_FAILED) - .build().flush(); + .build(); return; } String ifMatch = headers.get(HttpHeaderNames.IF_MATCH); if (ifMatch != null && !matches(ifMatch, eTag)) { + logger.log(Level.FINEST, () -> "precondition failed, ifMatch = " + ifMatch); context.response() .setResponseStatus(HttpResponseStatus.PRECONDITION_FAILED) - .build().flush(); + .build(); return; } String ifNoneMatch = headers.get(HttpHeaderNames.IF_NONE_MATCH); if (ifNoneMatch != null && matches(ifNoneMatch, eTag)) { + logger.log(Level.FINEST, () -> "not modified, eTag = " + eTag); context.response() .addHeader(HttpHeaderNames.ETAG, eTag) - .addHeader(HttpHeaderNames.EXPIRES, DateTimeUtil.formatRfc1123(expirationMillis)) .setResponseStatus(HttpResponseStatus.NOT_MODIFIED) - .build().flush(); + .build(); return; } Instant ifModifiedSinceInstant = DateTimeUtil.parseDate(headers.get(HttpHeaderNames.IF_MODIFIED_SINCE)); if (ifModifiedSinceInstant != null && ifModifiedSinceInstant.plusMillis(1000L).isAfter(lastModifiedInstant)) { + logger.log(Level.FINEST, () -> "not modified (after if-modified-since), eTag = " + eTag); context.response() .addHeader(HttpHeaderNames.ETAG, eTag) - .addHeader(HttpHeaderNames.EXPIRES, DateTimeUtil.formatRfc1123(expirationMillis)) .setResponseStatus(HttpResponseStatus.NOT_MODIFIED) - .build().flush(); + .build(); return; } + String lastModified = DateTimeUtil.formatRfc1123(lastModifiedInstant); + logger.log(Level.FINEST, () -> "sending resource, lastModified = " + lastModified); context.response() .addHeader(HttpHeaderNames.ETAG, eTag) - .addHeader(HttpHeaderNames.LAST_MODIFIED, DateTimeUtil.formatRfc1123(lastModifiedInstant)); + .addHeader(HttpHeaderNames.LAST_MODIFIED, lastModified); if (isRangeResponseEnabled()) { performRangeResponse(context, resource, contentType, eTag, headers); sent = true; + } else { + logger.log(Level.WARNING, "range response not enabled"); } } if (!sent) { @@ -185,18 +196,23 @@ public abstract class AbstractResourceHandler implements HttpHandler { String string = Long.toString(resource.getLength()); context.response() .addHeader(HttpHeaderNames.CONTENT_LENGTH, string); + logger.log(Level.FINEST, "length is known = " + resource.getLength()); send(resource, HttpResponseStatus.OK, contentType, context, 0L, resource.getLength()); } else { + logger.log(Level.FINEST, "length is unknown"); send(resource, HttpResponseStatus.OK, contentType, context, 0L, -1L); } } + logger.log(Level.FINEST, "generation done"); } private void performRangeResponse(HttpServerContext context, - Resource resource, - String contentType, String eTag, - HttpHeaders headers) throws IOException { + Resource resource, + String contentType, + String eTag, + HttpHeaders headers) throws IOException { long length = resource.getLength(); + logger.log(Level.FINEST, "performing range response on resource = " + resource); context.response().addHeader(HttpHeaderNames.ACCEPT_RANGES, "bytes"); Range full = new Range(0, length - 1, length); List ranges = new ArrayList<>(); @@ -293,19 +309,21 @@ public abstract class AbstractResourceHandler implements HttpHandler { HttpResponseStatus httpResponseStatus, String contentType, HttpServerContext context, - long offset, long size) throws IOException { + long offset, + long size) throws IOException { if (resource instanceof HttpServerResource) { - logger.log(Level.FINER, "we have a server resource, render by resource"); + logger.log(Level.FINEST, "let server resource render"); ((HttpServerResource) resource).render(context); return; } URL url = resource.getURL(); + logger.log(Level.FINEST, "sending URL = " + url + " offset = " + offset + " size = " + size); if (url == null) { - logger.log(Level.WARNING, "url is null, generating not found"); context.response() .setResponseStatus(HttpResponseStatus.NOT_FOUND) .build(); } else if (context.request().getMethod() == HttpMethod.HEAD) { + logger.log(Level.FINEST, "HEAD request, do not send body"); context.response() .setResponseStatus(HttpResponseStatus.OK) .setContentType(contentType) @@ -323,9 +341,16 @@ public abstract class AbstractResourceHandler implements HttpHandler { } } else { try (InputStream inputStream = url.openStream()) { - send(inputStream, httpResponseStatus, contentType, context.response(), offset, size); + if (inputStream != null) { + send(inputStream, httpResponseStatus, contentType, context.response(), offset, size); + } else { + logger.log(Level.WARNING, "input stream is null, url = " + url); + context.response() + .setResponseStatus(HttpResponseStatus.NOT_FOUND) + .build(); + } } catch (IOException e) { - logger.log(Level.SEVERE, e.getMessage(), e); + logger.log(Level.SEVERE, e.getMessage() + " url=" + url, e); context.response() .setResponseStatus(HttpResponseStatus.NOT_FOUND) .build(); @@ -357,7 +382,8 @@ public abstract class AbstractResourceHandler implements HttpHandler { HttpResponseStatus httpResponseStatus, String contentType, HttpResponseBuilder responseBuilder, - long offset, long size) throws IOException { + long offset, + long size) throws IOException { if (inputStream == null) { logger.log(Level.WARNING, "inputstream is null, generating not found"); responseBuilder.setResponseStatus(HttpResponseStatus.NOT_FOUND).build(); diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/resource/HtmlTemplateResource.java b/net-http-server/src/main/java/org/xbib/net/http/server/resource/HtmlTemplateResource.java index f55d768..1f02d0f 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/resource/HtmlTemplateResource.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/resource/HtmlTemplateResource.java @@ -53,7 +53,7 @@ public class HtmlTemplateResource implements HttpServerResource { } this.resourcePath = httpServerContext.request().getRequestPath().substring(1); this.path = resourcePath.length() > 0 ? root.resolve(resourcePath) : root; - logger.log(Level.FINER, "class = " + getClass().getName() + + logger.log(Level.FINEST, "class = " + getClass().getName() + " root = " + root + " resource path = " + resourcePath + " path = " + path + @@ -64,9 +64,9 @@ public class HtmlTemplateResource implements HttpServerResource { if (Files.isDirectory(path)) { if (getIndexFileName() != null) { Path indexPath = path.resolve(indexFileName); - logger.log(Level.FINE, "resolved to index path = " + indexPath); + logger.log(Level.FINEST, "resolved to index path = " + indexPath); if (Files.exists(indexPath)) { - logger.log(Level.FINE, "index path exists"); + logger.log(Level.FINEST, "index path exists"); this.isExistsIndexFile = true; this.path = indexPath; this.isDirectory = false; @@ -84,7 +84,7 @@ public class HtmlTemplateResource implements HttpServerResource { } this.isExists = Files.exists(path); this.url = URL.create(path.toUri().toString()); - logger.log(Level.FINE, "isExists = " + isExists + " isDirectory = " + isDirectory + " url = " + url); + logger.log(Level.FINEST, () -> "isExists = " + isExists + " isDirectory = " + isDirectory + " url = " + url); this.lastModified = isExists ? Files.getLastModifiedTime(path).toInstant() : Instant.now(); // length will be computed at rendering time this.length = -1; diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/session/IncomingSessionHandler.java b/net-http-server/src/main/java/org/xbib/net/http/server/session/IncomingSessionHandler.java index fbfeed6..5f3a8e5 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/session/IncomingSessionHandler.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/session/IncomingSessionHandler.java @@ -107,7 +107,7 @@ public class IncomingSessionHandler implements HttpHandler { } } context.getAttributes().put("session", session); - logger.log(Level.FINER, "incoming session " + session.id()); + logger.log(Level.FINEST, "incoming session " + session.id()); } private Map decodeCookie(Cookie cookie) throws IOException, diff --git a/net-http-server/src/main/java/org/xbib/net/http/server/session/OutgoingSessionHandler.java b/net-http-server/src/main/java/org/xbib/net/http/server/session/OutgoingSessionHandler.java index d0cd1f6..d011481 100644 --- a/net-http-server/src/main/java/org/xbib/net/http/server/session/OutgoingSessionHandler.java +++ b/net-http-server/src/main/java/org/xbib/net/http/server/session/OutgoingSessionHandler.java @@ -84,7 +84,7 @@ public class OutgoingSessionHandler implements HttpHandler { } String suffix = SessionUtil.extractExtension(context.request().getRequestPath()); if (suffix != null && suffixes.contains(suffix)) { - logger.log(Level.FINE, "suffix " + suffix + " blocking outgoing session handling"); + logger.log(Level.FINEST, () -> "suffix " + suffix + " blocking outgoing session handling"); return; } CookieBox cookieBox = context.getAttributes().get(CookieBox.class, "outgoingcookies"); @@ -105,7 +105,7 @@ public class OutgoingSessionHandler implements HttpHandler { if (session != null) { try { if (userProfile != null) { - logger.log(Level.FINE, "user profile present: " + userProfile); + logger.log(Level.FINEST, () -> "user profile present: " + userProfile); if (sessionUserName != null) { session.put(sessionUserName, userProfile.getUserId()); } @@ -123,7 +123,7 @@ public class OutgoingSessionHandler implements HttpHandler { throw new HttpException("unable to create session cookie", context, HttpResponseStatus.INTERNAL_SERVER_ERROR); } } - logger.log(Level.FINER, "outgoing cookies = " + cookieBox); + logger.log(Level.FINEST, "outgoing cookies = " + cookieBox); context.getAttributes().put("outgoingcookies", cookieBox); } diff --git a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultMarkupTemplate.java b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultMarkupTemplate.java index 2278701..356c80b 100644 --- a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultMarkupTemplate.java +++ b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultMarkupTemplate.java @@ -121,7 +121,7 @@ public abstract class DefaultMarkupTemplate extends BaseTemplate { } if (request != null) { URL url = request.getServerURL().resolve(prefix).resolve(rel); - logger.log(Level.FINE, "server base URL = " + request.getServerURL() + + logger.log(Level.FINEST, "server base URL = " + request.getServerURL() + " prefix = " + prefix + " rel = " + rel + " --> " + url); return absolute ? url.toExternalForm() : toOrigin(url); } else { diff --git a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultTemplateResolver.java b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultTemplateResolver.java index 92fb4c0..da2add7 100644 --- a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultTemplateResolver.java +++ b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/DefaultTemplateResolver.java @@ -41,7 +41,7 @@ public class DefaultTemplateResolver implements TemplateResolver { String templateResourceString = languageTag != null ? templateResource.withLocale(languageTag).toString() : templateResource.toString(); - logger.log(Level.FINER, "template resource string = " + templateResourceString + " locale = " + locale + logger.log(Level.FINEST, "template resource string = " + templateResourceString + " locale = " + locale + " templateConfiguration.getLocale() = " + templateConfiguration.getLocale() + " languageTag = " + languageTag); Path path = resolver.resolve(templateResourceString); return path.toUri().toURL(); diff --git a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyHttpResonseStatusTemplateResource.java b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyHttpResonseStatusTemplateResource.java index 9acb8e7..1ad8396 100644 --- a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyHttpResonseStatusTemplateResource.java +++ b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyHttpResonseStatusTemplateResource.java @@ -31,17 +31,16 @@ class GroovyHttpResonseStatusTemplateResource extends GroovyTemplateResource { @Override public void render(HttpServerContext httpServerContext) throws IOException { - logger.log(Level.FINE, "rendering HTTP status by Groovy"); + logger.log(Level.FINEST, "rendering HTTP status by Groovy"); httpServerContext.getAttributes().put("_status", httpResponseStatus); httpServerContext.getAttributes().put("_message", message); httpServerContext.getAttributes().put("_resource", this); Application application = httpServerContext.getAttributes().get(Application.class, "application"); GroovyMarkupTemplateHandler groovyMarkupTemplateHandler = new GroovyMarkupTemplateHandler(application); - logger.log(Level.FINE, "handle groovyMarkupTemplateHandler"); + logger.log(Level.FINEST, "handle groovyMarkupTemplateHandler"); groovyMarkupTemplateHandler.handle(httpServerContext); super.render(httpServerContext); GroovyTemplateRenderer groovyTemplateRenderer = new GroovyTemplateRenderer(); - logger.log(Level.FINE, "handle groovyTemplateRenderer"); groovyTemplateRenderer.handle(httpServerContext); } diff --git a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateRenderer.java b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateRenderer.java index 177e2da..af1ee2c 100644 --- a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateRenderer.java +++ b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateRenderer.java @@ -29,9 +29,9 @@ public class GroovyTemplateRenderer implements HttpHandler { HttpResponseStatus httpResponseStatus = context.getAttributes().get(HttpResponseStatus.class, "_status", HttpResponseStatus.OK); context.response() .setResponseStatus(httpResponseStatus) + .setHeader("cache-control", "no-cache") // override default must-revalidate behavior .setHeader("content-length", Integer.toString(dataBuffer.writePosition())) .setContentType("text/html; charset=" + StandardCharsets.UTF_8.displayName()) - .setHeader("cache-control", "no-cache") .write(dataBuffer); } } diff --git a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateResource.java b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateResource.java index c64ef03..640ed01 100644 --- a/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateResource.java +++ b/net-http-template-groovy/src/main/java/org/xbib/net/http/template/groovy/GroovyTemplateResource.java @@ -47,7 +47,7 @@ public class GroovyTemplateResource extends HtmlTemplateResource { @Override public void render(HttpServerContext httpServerContext) throws IOException { - logger.log(Level.FINER, "rendering groovy template, path = " + getPath() + " isExists = " + isExists() + " isDirectory =" + isDirectory() ); + logger.log(Level.FINEST, () -> "rendering groovy template, path = " + getPath() + " isExists = " + isExists() + " isDirectory =" + isDirectory() ); Application application = httpServerContext.getAttributes().get(Application.class, "application"); if (application == null) { logger.log(Level.WARNING, "application is null"); @@ -63,9 +63,9 @@ public class GroovyTemplateResource extends HtmlTemplateResource { if (service instanceof GroovyTemplateService groovyTemplateService) { if (groovyTemplateService.getTemplateName() != null) { templatePath = application.resolve(groovyTemplateService.getTemplateName()); - logger.log(Level.FINER, "templatePath after application.resolve() = " + templatePath); + logger.log(Level.FINEST, "templatePath after application.resolve() = " + templatePath); } else { - logger.log(Level.FINER, "the GroovyTemplateService does not have a templateName"); + logger.log(Level.FINEST, "the GroovyTemplateService does not have a templateName"); } } // status response handlers have priority @@ -75,17 +75,17 @@ public class GroovyTemplateResource extends HtmlTemplateResource { if (indexFileName != null) { templatePath = application.resolve(indexFileName); } - logger.log(Level.FINER, "rendering Groovy HTTP status response with templatePath = " + templatePath); + logger.log(Level.FINEST, "rendering Groovy HTTP status response with templatePath = " + templatePath); } else { // override if 'templatePath' attribute is set String overridePath = httpServerContext.getAttributes().get(String.class, "templatePath"); if (overridePath != null) { - logger.log(Level.FINER, "found override templatePath = " + overridePath); + logger.log(Level.FINEST, "found override templatePath = " + overridePath); templatePath = application.resolve(overridePath); - logger.log(Level.FINER, "found override templatePath, resolved to " + templatePath); + logger.log(Level.FINEST, "found override templatePath, resolved to " + templatePath); } if (templatePath == null) { - logger.log(Level.FINER, "templatePath is null, OOTB effort on " + getIndexFileName()); + logger.log(Level.FINEST, "templatePath is null, OOTB effort on " + getIndexFileName()); // OOTB rendering via getIndexFileName(), no getPath(), no getTemplateName() templatePath = application.resolve(getIndexFileName()); } @@ -104,7 +104,7 @@ public class GroovyTemplateResource extends HtmlTemplateResource { } templates.computeIfAbsent(templatePath, path -> { try { - logger.log(Level.FINEST, "groovy templatePath = " + path + " creating by template engine"); + logger.log(Level.FINEST, () -> "groovy templatePath = " + path + " creating by template engine"); return templateEngine.createTemplate(Files.readString(path)); } catch (Exception e) { throw new IllegalArgumentException(e); @@ -132,7 +132,7 @@ public class GroovyTemplateResource extends HtmlTemplateResource { return; } // handle programmatic locale change plus template making under lock so no other request/response can interrupt us - logger.log(Level.FINER, "application locale for template = " + application.getLocale()); + logger.log(Level.FINEST, () -> "application locale for template = " + application.getLocale()); try { lock.lock(); templateResolver.setLocale(application.getLocale()); @@ -141,7 +141,7 @@ public class GroovyTemplateResource extends HtmlTemplateResource { if (acceptLanguage != null) { Locale negotiatedLocale = LocaleNegotiator.findLocale(acceptLanguage); if (negotiatedLocale != null) { - logger.log(Level.FINER, "negotiated locale for template = " + negotiatedLocale); + logger.log(Level.FINEST, () -> "negotiated locale for template = " + negotiatedLocale); templateResolver.setLocale(negotiatedLocale); } }