Jkube: k8s:watch port forward websocket error

[ningpengtao-coder]

The order of the two variables of the forwardPortAsync method of PortForwardService is reversed, resulting in port-forward not working.

code line: PortForwardService.java line 219

Affected version: 1.1.0 1.1.1 1.2.0

[manusa]

https://github.com/eclipse/jkube/blob/1e1cb66ab1cba21daa9d5c56ce1dd5595cc66471/jkube-kit/config/service/src/main/java/org/eclipse/jkube/kit/config/service/PortForwardService.java#L219

https://github.com/fabric8io/kubernetes-client/blob/62d43cdda82d296b3e29519308bf4a715abb8f8e/kubernetes-client/src/main/java/io/fabric8/kubernetes/client/dsl/PortForwardable.java#L37

[manusa]

This is really weird. Services depending on this method work (debug, watch, etc.)
@rohanKanojia ?

[rohanKanojia]

@PengtaoNing : ~Hello, I tried reproducing this on https://github.com/rohanKanojia/eclipse-jkube-demo-project with minikube v1.17.1(K8s v1.20.2) but for me watch goal seems to be working okay:~

[INFO] <<< kubernetes-maven-plugin:1.2.0:watch (default-cli) < :deploy @ random-generator <<<
[INFO] 
[INFO] 
[INFO] --- kubernetes-maven-plugin:1.2.0:watch (default-cli) @ random-generator ---
[INFO] k8s: Running in Kubernetes mode
[INFO] k8s: Building Docker image in Kubernetes mode
[INFO] k8s: Running generator spring-boot
[INFO] k8s: spring-boot: Using Docker image quay.io/jkube/jkube-java-binary-s2i:0.0.9 as base / builder
[INFO] k8s: Running watcher spring-boot
[INFO] k8s: spring-boot: Watching pods with selector LabelSelector(matchExpressions=[], matchLabels={app=random-generator, provider=jkube, group=meetup}, additionalProperties={}) waiting for a running pod...   
[INFO] k8s: [NEW] random-generator-67c66cd774-p7p64 status: Running 
[INFO] k8s: [NEW] Tailing log of pod: random-generator-67c66cd774-p7p64
[INFO] k8s: [NEW] Press Ctrl-C to stop tailing the log
[INFO] k8s: [NEW] 
[INFO] k8s: spring-boot: Starting the Java application using /opt/jboss/container/java/run/run-java.sh ...                                                                                                        
[INFO] k8s: spring-boot: INFO exec  java -javaagent:/usr/share/java/jolokia-jvm-agent/jolokia-jvm.jar=config=/opt/jboss/container/jolokia/etc/jolokia.properties -javaagent:/usr/share/java/prometheus-jmx-exporter/jmx_prometheus_javaagent.jar=9779:/opt/jboss/container/prometheus/etc/jmx-exporter-config.yaml -XX:+UseParallelOldGC -XX:MinHeapFreeRatio=10 -XX:MaxHeapFreeRatio=20 -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 -XX:MaxMetaspaceSize=100m -XX:+ExitOnOutOfMemoryError -cp "." -jar /deployments/random-generator-0.0.1.jar                                                                                                 
[INFO] k8s: spring-boot: WARNING: An illegal reflective access operation has occurred
[INFO] k8s: spring-boot: WARNING: Illegal reflective access by org.jolokia.util.ClassUtil (file:/usr/share/java/jolokia-jvm-agent/jolokia-jvm.jar) to constructor sun.security.x509.X500Name(java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String)                        
[INFO] k8s: spring-boot: WARNING: Please consider reporting this to the maintainers of org.jolokia.util.ClassUtil                                                                                                 
[INFO] k8s: spring-boot: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations                                                                                    
[INFO] k8s: spring-boot: WARNING: All illegal access operations will be denied in a future release
[INFO] k8s: spring-boot: I> No access restrictor found, access to any MBean is allowed
[INFO] k8s: spring-boot: Jolokia: Agent started with URL https://172.17.0.6:8778/jolokia/
[INFO] k8s: spring-boot: {spring.web.resources.chain.cache=false, spring.web.resources.cache.period=0}
[INFO] k8s: spring-boot: 
[INFO] k8s: spring-boot:   .   ____          _            __ _ _
[INFO] k8s: spring-boot:  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
[INFO] k8s: spring-boot: ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
[INFO] k8s: spring-boot:  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
[INFO] k8s: spring-boot:   '  |____| .__|_| |_|_| |_\__, | / / / /
[INFO] k8s: spring-boot:  =========|_|==============|___/=/_/_/_/
[INFO] k8s: spring-boot:  :: Spring Boot ::                (v2.4.0)
[INFO] k8s: spring-boot: 
[INFO] k8s: spring-boot: 2021-04-08 08:41:43.950  INFO 1 --- [           main] m.r.RandomGeneratorApplication           : Starting RandomGeneratorApplication v0.0.1 using Java 11.0.9.1 on random-generator-67c66cd774-p7p64 with PID 1 (/deployments/random-generator-0.0.1.jar started by jboss in /deployments)        
[INFO] k8s: [NEW] random-generator-67c66cd774-p7p64 status: Running 
[INFO] k8s: [OLD] random-generator-67c66cd774-jvv6r status: Running 
[INFO] k8s: [OLD] random-generator-655f9997c9-r7smc status: Running Ready
[INFO] k8s: spring-boot: 2021-04-08 08:41:43.954  INFO 1 --- [           main] m.r.RandomGeneratorApplication           : No active profile set, falling back to default profiles: default                        
[INFO] k8s: spring-boot: 2021-04-08 08:41:44.129  INFO 1 --- [           main] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable                                                                                                    
[INFO] k8s: spring-boot: 2021-04-08 08:41:44.130  INFO 1 --- [           main] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'                                                                                                  
[INFO] k8s: spring-boot: 2021-04-08 08:41:47.777  INFO 1 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)                                            
[INFO] k8s: spring-boot: 2021-04-08 08:41:47.796  INFO 1 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]                                                               
[INFO] k8s: spring-boot: 2021-04-08 08:41:47.798  INFO 1 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.39]                                         
[INFO] k8s: spring-boot: 2021-04-08 08:41:47.928  INFO 1 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext                                      
[INFO] k8s: spring-boot: 2021-04-08 08:41:47.929  INFO 1 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 3797 ms                         
[INFO] k8s: spring-boot: 2021-04-08 08:41:48.483  WARN 1 --- [           main] .s.b.d.a.RemoteDevToolsAutoConfiguration : Listening for remote restart updates on /.~~spring-boot!~/restart                       
[INFO] k8s: spring-boot: 2021-04-08 08:41:48.664  INFO 1 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'                                  
[INFO] k8s: spring-boot: 2021-04-08 08:41:49.084  INFO 1 --- [           main] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 2 endpoint(s) beneath base path '/actuator'                                    
[INFO] k8s: spring-boot: 2021-04-08 08:41:49.294  INFO 1 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''                             
[INFO] k8s: spring-boot: 2021-04-08 08:41:49.319  INFO 1 --- [           main] m.r.RandomGeneratorApplication           : Started RandomGeneratorApplication in 6.508 seconds (JVM running for 8.08)              
[INFO] k8s: spring-boot: No exposed service found for connecting the dev tools
[INFO] k8s: spring-boot: Running RemoteSpringApplication against endpoint: http://localhost:57538
[INFO] k8s: Starting port-forward to pod random-generator-655f9997c9-r7smc
[INFO] k8s: spring-boot: Spring-Remote:   .   ____          _                                              __ _ _                                                                                                 
[INFO] k8s: spring-boot: Spring-Remote:  /\\ / ___'_ __ _ _(_)_ __  __ _          ___               _      \ \ \ \                                                                                                
[INFO] k8s: spring-boot: Spring-Remote: ( ( )\___ | '_ | '_| | '_ \/ _` |        | _ \___ _ __  ___| |_ ___ \ \ \ \                                                                                               
[INFO] k8s: spring-boot: Spring-Remote:  \\/  ___)| |_)| | | | | || (_| []::::::[]   / -_) '  \/ _ \  _/ -_) ) ) ) )                                                                                              
[INFO] k8s: spring-boot: Spring-Remote:   '  |____| .__|_| |_|_| |_\__, |        |_|_\___|_|_|_\___/\__\___|/ / / /                                                                                               
[INFO] k8s: spring-boot: Spring-Remote:  =========|_|==============|___/===================================/_/_/_/                                                                                                
[INFO] k8s: spring-boot: Spring-Remote:  :: Spring Boot Remote ::  (v2.4.0)
[INFO] k8s: spring-boot: Spring-Remote: 
[INFO] k8s: spring-boot: Spring-Remote: 2021-04-08 14:11:50.842  INFO 28420 --- [           main] o.s.b.devtools.RemoteSpringApplication   : Starting RemoteSpringApplication v2.4.0 using Java 11.0.9 on localhost.localdomain with PID 28420 (/home/rohaan/.m2/repository/org/springframework/boot/spring-boot-devtools/2.4.0/spring-boot-devtools-2.4.0.jar started by rohaan in /home/rohaan/work/repos/eclipse-jkube-demo-project)
[INFO] k8s: spring-boot: Spring-Remote: 2021-04-08 14:11:50.845  INFO 28420 --- [           main] o.s.b.devtools.RemoteSpringApplication   : No active profile set, falling back to default profiles: default
[INFO] k8s: spring-boot: Spring-Remote: 2021-04-08 14:11:51.071  WARN 28420 --- [           main] o.s.b.d.r.c.RemoteClientConfiguration    : The connection to http://localhost:57538 is insecure. You should use a URL starting with 'https://'.
[INFO] k8s: spring-boot: Spring-Remote: 2021-04-08 14:11:51.214  INFO 28420 --- [           main] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
[INFO] k8s: spring-boot: Spring-Remote: 2021-04-08 14:11:51.232  INFO 28420 --- [           main] o.s.b.devtools.RemoteSpringApplication   : Started RemoteSpringApplication in 0.778 seconds (JVM running for 1.187)
[INFO] k8s: Closing port-forward from pod random-generator-655f9997c9-r7smc
[INFO] k8s: [OLD] random-generator-655f9997c9-r7smc status: Running Ready
[INFO] k8s: spring-boot: 2021-04-08 08:41:57.295  INFO 1 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
[INFO] k8s: spring-boot: 2021-04-08 08:41:57.295  INFO 1 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
[INFO] k8s: spring-boot: 2021-04-08 08:41:57.300  INFO 1 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 3 ms
[INFO] k8s: [OLD] random-generator-655f9997c9-r7smc status: Running 
[INFO] k8s: Starting port-forward to pod random-generator-67c66cd774-p7p64
[INFO] k8s: [OLD] random-generator-655f9997c9-r7smc status: Running 
[INFO] k8s: [OLD] random-generator-655f9997c9-r7smc status: Running : Pod Deleted
[INFO] k8s: [OLD] random-generator-67c66cd774-jvv6r status: Running 
[INFO] k8s: [OLD] random-generator-67c66cd774-jvv6r status: Running : Pod Deleted

Could you please provide more details on how to reproduce it?

[manusa]

Yes, the goals work, but as he says, the arguments are inverted. So somewhere, here or Fabric8 things are the opposite as described.

[rohanKanojia]

I think you're right. I just ran a quick simple port forward using client and looks like argument should be remotePort, localPort instead.

[manusa]

:+1: Then we need to create an issue there.

[rohanKanojia]

Umm, why issue there? Isn't the issue in our code that arguments are inverted? I'm not sure how it's working. Maybe we tested it for cases when both remotePort and localPort are same?

[manusa]

Well, you just tested in our repo and seems that things work fine. The easiest case to test is for debug where we use the standard Java remote debug port (5005) and point it to the exposed container port.
We probably need a more thorough check then.

What's clear is that the variable names are not OK, either here or in the client.

[manusa]

After recently checking the SpringBootWatch implementation which is not working ATM, it seems that the order of the parameters/arguments might be wrong at some places.

For SpringBootWatcher, changing this line:
https://github.com/eclipse/jkube/blob/8063d3db1c3bc9e40e2b1097bcf830736a8b7e34/jkube-kit/jkube-kit-spring-boot/src/main/java/org/eclipse/jkube/springboot/watcher/SpringBootWatcher.java#L127
to:

        portForwardService.forwardPortAsync(selector, port, containerPort);

seems to fix the current issue and the SpringBootWatcher works again.

We need to properly name the variables, check which classes are consuming the PortForwardService, and make sure that the method invocations contain the parameters in the proper order.

[rohanKanojia]

@ningpengtao-coder : Thanks a lot for reporting this! You're right about the arguments being inversed. I made a mistake while testing it earlier and now when Marc and I tested the complete flow of the watch, we realized it's broken. LiveReload doesn't happen during k8s:watch session even on updating jarfile.

For k8s:debug when we don't specify localdebug port both container port and local port are assumed to be 5005, When we try to override the debug port, it doesn't work:

# Doesn't work
mvn k8s:debug -Djkube.debug.port=9001

I'll update the arguments in order to address these issues.