My application is based on Micronaut and GraalVM (java 11) and does a simple call to http://httpbin.org/get:
@Controller("/api")
class HelloWorld(
@Client("http://httpbin.org")
private val httpClient: RxHttpClient
) {
private val logger = LoggerFactory.getLogger(javaClass)
@Get("/hello")
fun hello(): String {
return "Hello World!"
}
@Get("/fb")
fun fb(): Flowable<String> {
logger.info("Trying to call FB")
logger.info("Using url http://httpbin.org/get")
try {
return httpClient.retrieve("/get")
.doOnError { logger.error("Error calling fb api flowable", it) }
.doFinally { logger.info("Finished calling FB api flowable") }
} catch (ex: Exception) {
logger.error("Error calling fb api", ex)
throw ex
} finally {
logger.info("Finished calling fb api")
}
}
}
When I build a docker image of the app using this Dockerfile:
FROM maven:3.6.3-jdk-11 as maven
COPY . /home/app
WORKDIR /home/app
RUN mvn package
FROM oracle/graalvm-ce:19.3.1-java11 as graalvm
COPY --from=maven /home/app/target/app-*.jar /home/app/
WORKDIR /home/app
RUN gu install native-image
RUN native-image --no-server --enable-http --enable-https -cp app-*.jar
FROM debian:stretch
EXPOSE 8080
COPY --from=graalvm /home/app/app .
#RUN apt-get update && apt-get -y install strace
ENTRYPOINT ["./app"]
Everything works in my local environment.
But when I push the image to Google Cloud Repository, deploy it to Cloud Run and try to access the endpoint /api/fb, it crashes the container with 503 Service Unavailable.
The error in the logs is "The request failed because the HTTP connection to the instance had an error.". When I enable strace, these are the logs:
A 2020-02-07T12:04:27.443115Z [pid 18] <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
A 2020-02-07T12:04:27.443125Z [pid 18] futex(0x3e61dc018a80, FUTEX_WAKE_PRIVATE, 1) = 0
A 2020-02-07T12:04:27.443357Z [pid 18] futex(0x3e62040009c4, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x3e6204000990, 234) = 1
A 2020-02-07T12:04:27.443369Z [pid 15] <... futex resumed> ) = 0
A 2020-02-07T12:04:27.443440Z [pid 18] futex(0x3e61dc018ab4, FUTEX_WAIT_BITSET_PRIVATE, 157, {tv_sec=3624, tv_nsec=391761056}, 0xffffffff <unfinished ...>
A 2020-02-07T12:04:27.443478Z [pid 15] futex(0x3e6204000990, FUTEX_WAKE_PRIVATE, 1) = 0
A 2020-02-07T12:04:27.959629Z [pid 20] epoll_wait(17, <unfinished ...>
A 2020-02-07T12:04:27.959658Z [pid 8] <... epoll_wait resumed> [{EPOLLIN, {u32=53, u64=53}}], 1024, -1) = 1
A 2020-02-07T12:04:27.959865Z [pid 8] accept(53, {sa_family=AF_INET6, sin6_port=htons(36294), inet_pton(AF_INET6, "::ffff:169.254.8.129", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 4
A 2020-02-07T12:04:27.959884Z [pid 8] fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
A 2020-02-07T12:04:27.959945Z [pid 8] getsockname(4, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:169.254.8.130", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 0
A 2020-02-07T12:04:27.960036Z [pid 8] getsockname(4, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:169.254.8.130", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 0
A 2020-02-07T12:04:27.960085Z [pid 8] fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
A 2020-02-07T12:04:27.960128Z [pid 8] fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
A 2020-02-07T12:04:27.960211Z [pid 8] setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
A 2020-02-07T12:04:27.960322Z [pid 8] getsockopt(4, SOL_SOCKET, SO_SNDBUF, [1048576], [4]) = 0
A 2020-02-07T12:04:27.960440Z [pid 8] mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x3e60f0e00000
A 2020-02-07T12:04:27.960564Z [pid 8] mprotect(0x3e60f0e00000, 4096, PROT_NONE) = 0
A 2020-02-07T12:04:27.960793Z [pid 8] clone(/usr/bin/strace: Process 22 attached
A 2020-02-07T12:04:27.960875Z <unfinished ...>
A 2020-02-07T12:04:27.965711Z [pid 22] set_robust_list(0x3e60f16009e0, 24 <unfinished ...>
A 2020-02-07T12:04:27.965738Z [pid 8] <... clone resumed> child_stack=0x3e60f15fffb0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x3e60f16009d0, tls=0x3e60f1600700, child_tidptr=0x3e60f16009d0) = 22
A 2020-02-07T12:04:27.965753Z [pid 22] <... set_robust_list resumed> ) = -1 ENOSYS (Function not implemented)
A 2020-02-07T12:04:27.965761Z [pid 8] epoll_wait(29, <unfinished ...>
A 2020-02-07T12:04:27.965770Z [pid 22] sched_getaffinity(22, 32, [0, 1]) = 8
A 2020-02-07T12:04:27.965783Z [pid 22] futex(0x3b4c0c4, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x3b4c068, 30) = 1
A 2020-02-07T12:04:27.965790Z [pid 3] <... futex resumed> ) = 0
A 2020-02-07T12:04:27.965799Z [pid 3] futex(0x3b4c068, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
A 2020-02-07T12:04:27.965807Z [pid 22] futex(0x3b4c068, FUTEX_WAKE_PRIVATE, 1) = 1
A 2020-02-07T12:04:27.965816Z [pid 22] mmap(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
A 2020-02-07T12:04:27.965824Z [pid 3] <... futex resumed> ) = 0
A 2020-02-07T12:04:27.965833Z [pid 3] futex(0x3b4c068, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
A 2020-02-07T12:04:27.965842Z [pid 22] <... mmap resumed> ) = 0x3e60f0c00000
A 2020-02-07T12:04:27.965850Z [pid 3] <... futex resumed> ) = 0
A 2020-02-07T12:04:27.965858Z [pid 3] futex(0x3b4c0c4, FUTEX_WAIT_PRIVATE, 31, NULL <unfinished ...>
A 2020-02-07T12:04:27.965866Z [pid 22] munmap(0x3e60f0d00000, 1048576) = 0
A 2020-02-07T12:04:27.965874Z [pid 22] prctl(PR_SET_NAME, "ntLoopGroup-1-7"...) = 0
A 2020-02-07T12:04:27.965882Z [pid 22] epoll_wait(20, [], 1024, 0) = 0
A 2020-02-07T12:04:27.965891Z [pid 22] mmap(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x3e60f0a00000
A 2020-02-07T12:04:27.965903Z [pid 22] munmap(0x3e60f0b00000, 1048576) = 0
A 2020-02-07T12:04:27.966731Z [pid 22] epoll_ctl(20, EPOLL_CTL_ADD, 4, {EPOLLIN, {u32=4, u64=4}}) = 0
A 2020-02-07T12:04:27.966836Z [pid 22] epoll_wait(20, [{EPOLLIN, {u32=4, u64=4}}], 1024, 299996) = 1
A 2020-02-07T12:04:27.967306Z [pid 22] mmap(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x3e60f0800000
A 2020-02-07T12:04:27.967325Z [pid 22] munmap(0x3e60f0900000, 1048576) = 0
A 2020-02-07T12:04:27.967493Z [pid 22] mmap(NULL, 16781312, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x3e60ef600000
A 2020-02-07T12:04:27.984977Z [pid 22] read(4, "GET /api/fb HTTP/1.1\r\nhost: app"..., 1024) = 864
A 2020-02-07T12:04:27.985474Z [36m12:04:27.985[0;39m [1;30m[nioEventLoopGroup-1-7][0;39m [34mINFO [0;39m [35mcom.roihunter.app.HelloWorld[0;39m - Trying to call FB
A 2020-02-07T12:04:27.985581Z [36m12:04:27.985[0;39m [1;30m[nioEventLoopGroup-1-7][0;39m [34mINFO [0;39m [35mcom.roihunter.app.HelloWorld[0;39m - Using url /act_984750788289990/insights
A 2020-02-07T12:04:27.985645Z [pid 22] write(1, "\33[36m12:04:27.985\33[0;39m \33[1;30m"..., 143) = 143
A 2020-02-07T12:04:27.985666Z [pid 22] write(1, "\33[36m12:04:27.985\33[0;39m \33[1;30m"..., 165) = 165
A 2020-02-07T12:04:27.985766Z [36m12:04:27.985[0;39m [1;30m[nioEventLoopGroup-1-7][0;39m [34mINFO [0;39m [35mcom.roihunter.app.HelloWorld[0;39m - Finished calling fb api
A 2020-02-07T12:04:27.985836Z [pid 22] write(1, "\33[36m12:04:27.985\33[0;39m \33[1;30m"..., 149) = 149
A 2020-02-07T12:04:27.986363Z [pid 22] write(4, "HTTP/1.1 200 OK\r\ntransfer-encodi"..., 143) = 143
E 2020-02-07T12:04:27.988626Z GET 503 546 B 31 ms curl/7.66.0 https://app-5phkf6s3jq-ez.a.run.app/api/fb GET 503 546 B 31 ms curl/7.66.0
A 2020-02-07T12:04:27.989104Z [pid 22] writev(4, [{iov_base="1\r\n", iov_len=3}, {iov_base="[", iov_len=1}, {iov_base="\r\n", iov_len=2}], 3) = 6
A 2020-02-07T12:04:27.989513Z [pid 22] mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x3e60eec00000
A 2020-02-07T12:04:27.989534Z [pid 22] mprotect(0x3e60eec00000, 4096, PROT_NONE) = 0
A 2020-02-07T12:04:27.989732Z [pid 22] clone(/usr/bin/strace: Process 23 attached
A 2020-02-07T12:04:27.989753Z <unfinished ...>
A 2020-02-07T12:04:27.989873Z [pid 23] set_robust_list(0x3e60ef4009e0, 24) = -1 ENOSYS (Function not implemented)
A 2020-02-07T12:04:27.989884Z [pid 23] sched_getaffinity(23, 32, [0, 1]) = 8
A 2020-02-07T12:04:27.989964Z [pid 23] futex(0x3b4c0c4, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x3b4c068, 32) = 1
A 2020-02-07T12:04:27.990286Z [pid 23] mmap(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
A 2020-02-07T12:04:27.990303Z [pid 22] <... clone resumed> child_stack=0x3e60ef3fffb0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x3e60ef4009d0, tls=0x3e60ef400700, child_tidptr=0x3e60ef4009d0) = 23
A 2020-02-07T12:04:27.990311Z [pid 23] <... mmap resumed> ) = 0x3e60eea00000
A 2020-02-07T12:04:27.990320Z [pid 3] <... futex resumed> ) = 0
A 2020-02-07T12:04:27.990327Z [pid 3] futex(0x3b4c068, FUTEX_WAKE_PRIVATE, 1) = 0
A 2020-02-07T12:04:27.990335Z [pid 3] futex(0x3b4c0c4, FUTEX_WAIT_PRIVATE, 33, NULL <unfinished ...>
A 2020-02-07T12:04:27.990345Z [pid 23] munmap(0x3e60eeb00000, 1048576) = 0
A 2020-02-07T12:04:27.990423Z [pid 22] socket(AF_INET6, SOCK_STREAM, IPPROTO_IP <unfinished ...>
A 2020-02-07T12:04:27.990435Z [pid 23] prctl(PR_SET_NAME, "ionThreadPool-1"... <unfinished ...>
A 2020-02-07T12:04:27.990446Z [pid 22] <... socket resumed> ) = 80
A 2020-02-07T12:04:27.990668Z [pid 22] setsockopt(80, SOL_IPV6, IPV6_V6ONLY, [0], 4) = 0
A 2020-02-07T12:04:27.990684Z [pid 23] <... prctl resumed> ) = 0
I tried using a different library to make the call, Java 11 Http client, and it works. But whatever I do, it doesn't work when I use Micronaut Http client, and there is no helpful message.
I also tried using Java 8, a different linux distribution in the docker image (fedora:latest, ubuntu:latest), but it didn't help.
Do you have any idea what could be causing this?
Thanks for you answer in advance.
So it looks like the core of the issue is that Cloud Run currently does not support HTTP streaming:
https://cloud.google.com/run/docs/issues#grpc_websocket
And when I return Flowable with Micronauts, it is opening a streamable HTTP connection. So the solution is not to use Flowable (or any other Publisher that is unbounded e.g. Flow, Flux etc) as a response.