Reload mode - event not working for k8 config - 1.1.2.RELEASE

[dintualex]

I'm able to fetch the K8 config maps on startup but on subsequent update to the config map, its not resulting in consuming the event and updating the values in my spring boot application.

Here are the versions:
spring boot - 2.2.7.RELEASE
spring-cloud-gcp - 1.2.2.RELEASE
spring-cloud - Hoxton.SR4

Its working fine in
spring boot - 2.1.11.RELEASE
spring-cloud-gcp - 1.1.3.RELEASE
spring-cloud - Greenwich.SR4
Able to fetch the config map during startup as well as consuming the event when there is a change in the config map

[Snazzythat]

I have an issue with events when updating the configmap as well. At first, the application picks up the configmap values and changes to configmap gets do get triggered:

2020-05-20 17:41:28.493 +0000 [OkHttp https://10.96.0.1/...] INFO o.s.c.k.c.r.EventBasedConfigurationChangeDetector - Detected change in config maps
2020-05-20 17:41:28.493 +0000 [OkHttp https://10.96.0.1/...] INFO o.s.c.k.c.r.EventBasedConfigurationChangeDetector - Reloading using strategy: REFRESH

However, if I leave the app running in my k8s cluster for about 15-20 minutes, the events stop firing when I submit changes to the config map.

spring boot - 2.2.4.RELEASE
spring-cloud-starter-kubernetes-config -1.1.2.RELEASE

[ChrisIgel]

Same problem. Here are the relevant logs when the problem occurs:

{"time":"2020-07-16T14:49:39.695Z","msg":"WebSocket close received. code: 1000, reason: ","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:39.695Z","msg":"Submitting reconnect task to the executor","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:39.695Z","msg":"Scheduling reconnect task","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"scheduleReconnect|Executor for Watch 178371348","level":"DEBUG"}
{"time":"2020-07-16T14:49:39.695Z","msg":"Current reconnect backoff is 1000 milliseconds (T0)","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"scheduleReconnect|Executor for Watch 178371348","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.696Z","msg":"Connecting websocket ... io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager@aa1bb14","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"reconnectAttempt|Executor for Watch 178371348","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.726Z","msg":"WebSocket successfully opened","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.727Z","msg":"Force closing the watch io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager@aa1bb14","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.727Z","msg":"Ignoring duplicate firing of onClose event","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.728Z","msg":"WebSocket close received. code: 1000, reason: ","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:49:40.728Z","msg":"Ignoring onClose for already closed/closing websocket","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}

A healthy reconnect looks like this:

{"time":"2020-07-16T14:29:18.998Z","msg":"WebSocket close received. code: 1000, reason: ","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:29:18.999Z","msg":"Submitting reconnect task to the executor","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp WebSocket https://10.253.0.1/...","level":"DEBUG"}
{"time":"2020-07-16T14:29:19.000Z","msg":"Scheduling reconnect task","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"scheduleReconnect|Executor for Watch 721704146","level":"DEBUG"}
{"time":"2020-07-16T14:29:19.000Z","msg":"Current reconnect backoff is 1000 milliseconds (T0)","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"scheduleReconnect|Executor for Watch 721704146","level":"DEBUG"}
{"time":"2020-07-16T14:29:20.001Z","msg":"Connecting websocket ... io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager@2b0454d2","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"reconnectAttempt|Executor for Watch 721704146","level":"DEBUG"}
{"time":"2020-07-16T14:29:20.033Z","msg":"WebSocket successfully opened","logger":"io.fabric8.kubernetes.client.dsl.internal.WatchConnectionManager","thread":"OkHttp https://10.253.0.1/...","level":"DEBUG"}

Versions:
Spring Boot 2.3.1
Spring Cloud Starter Kubernetes Config 1.1.3

[hudi1]

Any progress ? I think we should just catch 'HTTP_GONE' event in onClose and start watch again. This is know issue in kubernetes when resources is too old: fabric8io/kubernetes-client#1800 (comment)
and also mention in WatchConnectionManager

            // The resource version no longer exists - this has to be handled by the caller.
            if (status.getCode() == HTTP_GONE) {
              webSocketRef.set(null); // lose the ref: closing in close() would only generate a Broken pipe
              // exception
              // shut down executor, etc.
              closeEvent(new KubernetesClientException(status));
              close();
              return;
            }

My solution:

            @Override
            public void onClose(KubernetesClientException exception) {
                log.warn("ConfigMaps watch closed");
                Optional.ofNullable(exception).map(e -> {
                    log.debug("Exception received during watch", e);
                    return exception;
                }).map(KubernetesClientException::getStatus).map(Status::getCode)
                        .filter(c -> c.equals(HttpURLConnection.HTTP_GONE)).ifPresent(c -> monitorConfigMaps());
            }

[UltimateFighter]

Are there any solutions or bug fixes here. I have the same problem.

[UltimateFighter]

Any progress ? I think we should just catch 'HTTP_GONE' event in onClose and start watch again. This is know issue in kubernetes when resources is too old: fabric8io/kubernetes-client#1800 (comment)
and also mention in WatchConnectionManager

            // The resource version no longer exists - this has to be handled by the caller.
            if (status.getCode() == HTTP_GONE) {
              webSocketRef.set(null); // lose the ref: closing in close() would only generate a Broken pipe
              // exception
              // shut down executor, etc.
              closeEvent(new KubernetesClientException(status));
              close();
              return;
            }

My solution:

            @Override
            public void onClose(KubernetesClientException exception) {
                log.warn("ConfigMaps watch closed");
                Optional.ofNullable(exception).map(e -> {
                    log.debug("Exception received during watch", e);
                    return exception;
                }).map(KubernetesClientException::getStatus).map(Status::getCode)
                        .filter(c -> c.equals(HttpURLConnection.HTTP_GONE)).ifPresent(c -> monitorConfigMaps());
            }

Which bean was used here? Can you show me the complete code of your solution class?

[yvladimirov]

@UltimateFighter
maybe this help you
#570
#648

[UltimateFighter]

@yvladimirov

Thank you very much for this. In which version (and when) will this be included?

[ryanjbaxter]

We are waiting for the author's to make some minor changes to the PRs

[hudi1]

Any progress ? I think we should just catch 'HTTP_GONE' event in onClose and start watch again. This is know issue in kubernetes when resources is too old: fabric8io/kubernetes-client#1800 (comment)
and also mention in WatchConnectionManager

            // The resource version no longer exists - this has to be handled by the caller.
            if (status.getCode() == HTTP_GONE) {
              webSocketRef.set(null); // lose the ref: closing in close() would only generate a Broken pipe
              // exception
              // shut down executor, etc.
              closeEvent(new KubernetesClientException(status));
              close();
              return;
            }

My solution:

            @Override
            public void onClose(KubernetesClientException exception) {
                log.warn("ConfigMaps watch closed");
                Optional.ofNullable(exception).map(e -> {
                    log.debug("Exception received during watch", e);
                    return exception;
                }).map(KubernetesClientException::getStatus).map(Status::getCode)
                        .filter(c -> c.equals(HttpURLConnection.HTTP_GONE)).ifPresent(c -> monitorConfigMaps());
            }

Which bean was used here? Can you show me the complete code of your solution class?

Sure here it is. It is based on spring sollution but now I also modify onClose to fix this bug

@Configuration
public class OnGoneReconnectEventBasedConfigurationChangeDetector extends ConfigurationChangeDetector {

    private ConfigMapPropertySourceLocator configMapPropertySourceLocator;

    private SecretsPropertySourceLocator secretsPropertySourceLocator;

    private Map<String, Watch> watches;

    public OnGoneReconnectEventBasedConfigurationChangeDetector(AbstractEnvironment environment,
            ConfigReloadProperties properties, KubernetesClient kubernetesClient, ConfigurationUpdateStrategy strategy,
            ConfigMapPropertySourceLocator configMapPropertySourceLocator,
            SecretsPropertySourceLocator secretsPropertySourceLocator) {
        super(environment, properties, kubernetesClient, strategy);

        this.configMapPropertySourceLocator = configMapPropertySourceLocator;
        this.secretsPropertySourceLocator = secretsPropertySourceLocator;
        this.watches = new HashMap<>();
    }

    @PostConstruct
    public void watch() {
        boolean activated = false;

        if (this.properties.isMonitoringConfigMaps()) {
            activated = monitorConfigMaps();
        }

        if (this.properties.isMonitoringSecrets()) {
            activated = monitorSecrets();
        }

        if (activated) {
            this.log.info("Kubernetes event-based configuration change detector activated");
        }
    }

    private boolean monitorConfigMaps() {
        try {
            String name = "config-maps-watch";
            this.watches.put(name, this.kubernetesClient.configMaps().watch(new Watcher<ConfigMap>() {
                @Override
                public void eventReceived(Action action, ConfigMap configMap) {
                    onEvent(configMap);
                }

                @Override
                public void onClose(KubernetesClientException exception) {
                    log.warn("ConfigMaps watch closed");
                    Optional.ofNullable(exception).map(e -> {
                        log.debug("Exception received during watch", e);
                        return exception;
                    }).map(KubernetesClientException::getStatus).map(Status::getCode)
                            .filter(c -> c.equals(HttpURLConnection.HTTP_GONE)).ifPresent(c -> monitorConfigMaps());
                }
            }));
            this.log.info("Added new Kubernetes watch: " + name);
            return true;
        } catch (Exception e) {
            this.log.error("Error while establishing a connection to watch config maps: configuration may remain stale",
                    e);
            return false;
        }
    }

    private boolean monitorSecrets() {
        try {
            String name = "secrets-watch";
            this.watches.put(name, this.kubernetesClient.secrets().watch(new Watcher<Secret>() {
                @Override
                public void eventReceived(Action action, Secret secret) {
                    onEvent(secret);
                }

                @Override
                public void onClose(KubernetesClientException exception) {
                    log.warn("Sercet watch closed");
                    Optional.ofNullable(exception).map(e -> {
                        log.debug("Exception received during watch", e);
                        return exception;
                    }).map(KubernetesClientException::getStatus).map(Status::getCode)
                            .filter(c -> c.equals(HttpURLConnection.HTTP_GONE)).ifPresent(c -> monitorSecrets());
                }
            }));
            this.log.info("Added new Kubernetes watch: " + name);
            return true;
        } catch (Exception e) {
            this.log.error("Error while establishing a connection to watch secrets: configuration may remain stale", e);
            return false;
        }
    }

    @PreDestroy
    public void unwatch() {
        if (this.watches != null) {
            for (Map.Entry<String, Watch> entry : this.watches.entrySet()) {
                try {
                    this.log.debug("Closing the watch " + entry.getKey());
                    entry.getValue().close();

                } catch (Exception e) {
                    this.log.error("Error while closing the watch connection", e);
                }
            }
        }
    }

    private void onEvent(ConfigMap configMap) {
        boolean changed = changed(locateMapPropertySources(this.configMapPropertySourceLocator, this.environment),
                findPropertySources(ConfigMapPropertySource.class));
        if (changed) {
            this.log.info("Detected change in config maps");
            reloadProperties();
        }
    }

    private void onEvent(Secret secret) {
        boolean changed = changed(locateMapPropertySources(this.secretsPropertySourceLocator, this.environment),
                findPropertySources(SecretsPropertySource.class));
        if (changed) {
            this.log.info("Detected change in secrets");
            reloadProperties();
        }
    }

}

[ulrichwinter]

@ryanjbaxter the documentation for the PropertySource Reload feature mentions that it is deprecated in the 2020.0 release:
https://docs.spring.io/spring-cloud-kubernetes/docs/current/reference/html/#propertysource-reload

One can conclude, that this means, that this issue will never get resolved.
Is there any reason for deprecating this functionality?

Would it help to keep it, if someone would work on this issue and implement the mentioned retry?

[ryanjbaxter]

Fixed via 888031d