0

I have the following code:

import com.fasterxml.jackson.core.JsonParseException;
import com.fasterxml.jackson.databind.DeserializationFeature;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.SerializationFeature;
import com.fasterxml.jackson.databind.json.JsonMapper;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import picocli.CommandLine;

import javax.sound.sampled.AudioInputStream;
import javax.sound.sampled.AudioSystem;
import javax.sound.sampled.Clip;
import java.io.BufferedInputStream;
import java.io.File;
import java.io.IOException;
import java.io.InputStream;
import java.net.HttpURLConnection;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse;
import java.nio.charset.StandardCharsets;
import java.time.Duration;
import java.time.Instant;
import java.time.format.DateTimeFormatter;
import java.util.Collections;
import java.util.List;
import java.util.Objects;
import java.util.Set;
import java.util.regex.Pattern;
import java.util.stream.Stream;

@CommandLine.Command(name = "red-alert-listener",
        mixinStandardHelpOptions = true,
        versionProvider = Listener.class,
        showDefaultValues = true,
        description = "An App that can get \"red alert\"s from IDF's Home Front Command.")
public class Listener implements Runnable, CommandLine.IVersionProvider
{
    private static final Logger LOGGER = LogManager.getLogger();
    private static final ObjectMapper JSON_MAPPER = new JsonMapper()
            .enable(SerializationFeature.INDENT_OUTPUT)
            .disable(DeserializationFeature.READ_DATE_TIMESTAMPS_AS_NANOSECONDS)
            .findAndRegisterModules();
    private static final Configuration DEFAULT_CONFIGURATION = new Configuration(
            false,
            false,
            true,
            false,
            Duration.ofMillis(10000),
            LanguageCode.HE,
            Level.INFO,
            Collections.emptySet()
    );
    private static final HttpClient HTTP_CLIENT = HttpClient.newHttpClient();
    private Configuration configuration = DEFAULT_CONFIGURATION;
    private List<String> districtsNotFound = Collections.emptyList();

    public static void main(String... args)
    {
        System.exit(new CommandLine(Listener.class)
                .setCaseInsensitiveEnumValuesAllowed(true)
                .execute(args));
    }

    private static void sleep()
    {
        try
        {
            Thread.sleep(1000);
        } catch (InterruptedException interruptedException)
        {
            interruptedException.printStackTrace(); // TODO think about
        }
    }

    @Override
    public String[] getVersion()
    {
        return new String[]{"Red Alert Listener v" + getClass().getPackage().getImplementationVersion()};
    }

    @Override
    public void run()
    {
        System.err.println("Preparing Red Alert Listener v" + getClass().getPackage().getImplementationVersion() + "...");
        try (Clip clip = AudioSystem.getClip(Stream.of(AudioSystem.getMixerInfo()).parallel().unordered()
                .filter(mixerInfo -> "default [default]".equals(mixerInfo.getName()))
                .findAny()
                .orElse(null));
             AudioInputStream audioInputStream = AudioSystem.getAudioInputStream(new BufferedInputStream(Objects.requireNonNull(getClass().getResourceAsStream("/alarmSound.wav"))));
             InputStream in = System.in)
        {
            clip.open(audioInputStream);
            final URI uri = URI.create("https://www.oref.org.il/WarningMessages/alert/alerts.json");
            Set<String> prevData = Collections.emptySet();
            Instant currAlertsLastModified = Instant.MIN;
            final int minRedAlertEventContentLength = """
                    {"cat":"1","data":[],"desc":"","id":0,"title":""}""".getBytes(StandardCharsets.UTF_8).length;
            System.err.println("Listening...");
            while (true)
                try
                {
                    final HttpResponse<InputStream> httpResponse = HTTP_CLIENT.send(
                            HttpRequest.newBuilder(uri)
                                    .header("Accept", "application/json")
                                    .header("X-Requested-With", "XMLHttpRequest")
                                    .header("Referer", "https://www.oref.org.il/12481-" + configuration.languageCode().name().toLowerCase() + "/Pakar.aspx")
                                    .timeout(configuration.timeout())
                                    .build(),
                            HttpResponse.BodyHandlers.ofInputStream()
                    );

                    try (InputStream httpResponseBody = httpResponse.body())
                    {
                        if (httpResponse.statusCode() != HttpURLConnection.HTTP_OK/* &&
                                httpURLConnection.getResponseCode() != HttpURLConnection.HTTP_NOT_MODIFIED*/)
                        {
                            LOGGER.error("Connection response status code: {}", httpResponse.statusCode());
                            sleep();
                            continue;
                        }
                        final Instant alertsLastModified;
                        final long contentLength = httpResponse.headers().firstValueAsLong("Content-Length").orElse(-1);
                        if (contentLength < minRedAlertEventContentLength)
                            prevData = Collections.emptySet();
                        else if ((alertsLastModified = httpResponse.headers().firstValue("Last-Modified")
                                .map(lastModifiedStr -> DateTimeFormatter.RFC_1123_DATE_TIME.parse(lastModifiedStr, Instant::from))
                                .filter(currAlertsLastModified::isBefore)
                                .orElse(null)) != null)
                        {
                            currAlertsLastModified = alertsLastModified;

                            final RedAlertEvent redAlertEvent = JSON_MAPPER.readValue(
                                    httpResponseBody,
                                    RedAlertEvent.class
                            );
                            LOGGER.debug("Original event data: {}", redAlertEvent);
                        }
                    } catch (JsonParseException e)
                    {
                        LOGGER.error("JSON parsing error: {}", e.toString());
                    }
                } catch (IOException e)
                {
                    LOGGER.debug("Got exception: {}", e.toString());
                    sleep();
                }
        } catch (Throwable e)
        {
            LOGGER.fatal("Closing connection and exiting...", e);
        }
    }

    @SuppressWarnings("unused")
    private enum LanguageCode
    {
        HE,
        EN,
        AR,
        RU;
    }

    private record RedAlertEvent(
            int cat,
            List<String> data,
            String desc,
            long id,
            String title
    )
    {
    }

    private record Configuration(
            boolean isMakeSound,
            boolean isAlertAll,
            boolean isDisplayResponse,
            boolean isShowTestAlerts,
            Duration timeout,
            LanguageCode languageCode,
            Level logLevel,
            Set<String> districtsOfInterest
    )
    {
    }
}

My dependencies:

<dependencies>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>2.19.0</version>
    </dependency>
    <dependency>
        <groupId>com.lmax</groupId>
        <artifactId>disruptor</artifactId>
        <version>3.4.4</version>
    </dependency>
    <dependency>
        <groupId>info.picocli</groupId>
        <artifactId>picocli</artifactId>
        <version>4.6.3</version>
    </dependency>
    <dependency>
        <groupId>com.fasterxml.jackson.core</groupId>
        <artifactId>jackson-databind</artifactId>
        <version>2.13.4</version>
    </dependency>
    <dependency>
        <groupId>com.fasterxml.jackson.datatype</groupId>
        <artifactId>jackson-datatype-jsr310</artifactId>
        <version>2.13.4</version>
    </dependency>
    <dependency>
        <groupId>io.github.ashr123</groupId>
        <artifactId>time-measurement</artifactId>
        <version>1.0.7</version>
    </dependency>
</dependencies>

I'm using OpenJDK 19 but it happens also on OpenJDK 17.

This is the most minimal code I can show you that demonstrate the problem.

When I used IntelliJ's profiler tool, I saw this image and here is a live CPU and heap charts (over 3 days): enter image description here I think that my HttpClient doesn't close the subscriptions fast enough (i.e. it adds HttpBodySubscriberWrapper via jdk.internal.net.http.HttpClientImpl#registerSubscriber faster that it removes it via jdk.internal.net.http.HttpClientImpl#subscriberCompleted).

  1. Why does it happen?
  2. Why even though I've put the Closeable body in try-with-resources block doesn't remove the subscriber in time for the next loop?
  3. How can I control the size of the subscriber field?
  4. Can I demand in any way that there is only 1 "uncompleted" subscriber?
UPDATE

I've discovered that for HttpResponse.BodyHandlers#ofString it doesn't happen (subscriber list is always of size 1), so the question is why if I keep the body in try-with-resources it and close the InputStream, it doesn't removes the request's subscriber?

From HttpResponse.BodySubscribers#ofInputStream javadoc:

API Note: To ensure that all resources associated with the corresponding exchange are properly released the caller must ensure to either read all bytes until EOF is reached, or call InputStream.close if it is unable or unwilling to do so. Calling close before exhausting the stream may cause the underlying HTTP connection to be closed and prevent it from being reused for subsequent operations.

So is it a bug? is it something else?

Roy Ash
  • 1,078
  • 1
  • 11
  • 28
  • That would only be possible if onError() or onComplete() is not always called on register subscribers. Do you have pending requests that have not been fulfilled? Do you know which version of the protocol is used (HTTP/1.1 or HTTP/2). Which type of body handlers / body subscribers are you using? – daniel Oct 06 '22 at 15:30
  • @daniel this is HTTP/1.1 and as you can see, I'm using `HttpResponse.BodyHandlers.ofInputStream()` body handler. To be clear, `subscriberCompleted` is called but apparently not as fast, even though it is synchronous call. I don't have a direct access to `HttpBodySubscriberWrapper` which has `onComplete` method – Roy Ash Oct 06 '22 at 19:02
  • 2
    This appears to be a regression introduced in JDK 19. See https://bugs.openjdk.org/browse/JDK-8294916 – daniel Oct 11 '22 at 14:39
  • @daniel so if I understand correctly, it says that it will be fixed in Java 20? – Roy Ash Oct 11 '22 at 20:00
  • @daniel in addition I think the problem also exists in JDK 18 (and maybe 17, but I'm not sure) – Roy Ash Oct 11 '22 at 22:40
  • 1
    The list of subscribers and the methods `jdk.internal.net.http.HttpClientImpl#registerSubscriber` and `jdk.internal.net.http.HttpClientImpl#subscriberCompleted` were added in 19, so if there is a leak in 18 or 17 it has a different source. – daniel Oct 12 '22 at 11:20

0 Answers0