Приложение Cloud Run отвечает сообщением 503 Service Unavailable при использовании HTTP-клиента Micronaut

Мое приложение основано на Micronaut и GraalVM (java 11) и выполняет простой вызов 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")
        }
    }
}

Когда я создаю докер-образ приложения с помощью этого 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"]

В моей локальной среде все работает. Но когда я отправляю образ в Google Cloud Repository, развертываю его в Cloud Run и пытаюсь получить доступ к конечной точке /api/fb, происходит сбой контейнера с 503 Service Unavailable.

Ошибка в журналах: «Запрос не удался из-за ошибки HTTP-соединения с экземпляром». Когда я включаю strace, это журналы:

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 

Я попытался использовать другую библиотеку для вызова, клиент Java 11 Http, и она работает. Но что бы я ни делал, это не работает, когда я использую клиент Micronaut Http, и нет полезного сообщения.

Я также пробовал использовать Java 8, другой дистрибутив Linux в образе докера (fedora: latest, ubuntu: latest), но это не помогло.

Вы хоть представляете, что могло быть причиной этого?

Заранее спасибо за ответ.


person VaclavDedik    schedule 07.02.2020    source источник
comment
Официальный пример Cloud Run можно найти в репозиторий Micronaut, можете ли вы посмотреть, работает ли оно для вас? и если да, попробуйте понять разницу с вашим кодом   -  person Steren    schedule 07.02.2020
comment
Когда вы пробовали его в своей локальной среде, вы пробовали образ Docker или непосредственно свой код?   -  person guillaume blaquiere    schedule 07.02.2020
comment
@Steren Это приложение не вызывает никаких внешних API, как у меня. Моя конечная точка hello world работает нормально, она вылетает, когда я вызываю конечную точку, которая отправляет Http-запрос.   -  person VaclavDedik    schedule 07.02.2020
comment
@guillaumeblaquiere Я пробовал как образ Docker, так и непосредственно свой код, как с graalvm, так и без него. Работал каждый раз.   -  person VaclavDedik    schedule 07.02.2020
comment
@Steren, у меня тоже такие странности, когда я выполнял внешний вызов на Python. Мне нужно время, чтобы исправить ошибку.   -  person guillaume blaquiere    schedule 07.02.2020
comment
@VaclavDedik, вы видели какое-нибудь сообщение gvisor в журналах Cloud Run?   -  person guillaume blaquiere    schedule 07.02.2020
comment
Действительно, если вы подозреваете наличие ошибки, предоставьте минимальный пример, который воспроизводит и подробно описывает проблему, на странице cloud.google.com/support/docs/issue-trackers   -  person Steren    schedule 09.02.2020
comment
Я пытался воспроизвести вашу ошибку, но не смог. Вот что я сделал из вашего описания: github.com/benjaminkomen/micronaut. Основное отличие в том, что я не использовал Kotlin, но я не думаю, что это должно иметь значение (я попробую использовать Kotlin, чтобы проверить, имеет ли это значение).   -  person Benjamin    schedule 09.02.2020
comment
@Benjamin Вау, большое спасибо за то, что попробовали. Я пытался развернуть ваше приложение, но это не сработало. Итак, я попытался отключить аутентификацию, и она начала работать! Но только потому, что я вдруг стал использовать для отправки запроса не curl, а браузер. Итак, я обнаружил, что он работает в браузере, но не тогда, когда я делаю запрос в завитке или бессоннице и т. Д. Не имеет смысла, как это возможно? Я попытался включить те же заголовки, что и мой браузер, но это не помогает :(   -  person VaclavDedik    schedule 10.02.2020
comment
Похоже, что это делается с помощью заголовка accept-encoding: gzip, deflate, br .. так что я должен архивировать вывод, чтобы сервер не сбоил, это смешно: D   -  person VaclavDedik    schedule 10.02.2020
comment
Еще одна интересная вещь заключается в том, что если я блокирую реактивный вызов с помощью blockingFirst, как это httpClient.retrieve(url).blockingFirst() вместо httpClient.retrieve(url) в контроллере, он работает нормально. Так что эта ошибка становится все более и более странной :(   -  person VaclavDedik    schedule 10.02.2020
comment
Теперь мне интересно, является ли это ошибкой запуска облака Google или ошибкой микронавта: /   -  person VaclavDedik    schedule 10.02.2020
comment
Если я использую httpClient.retrieve(url).firstElement(), он также работает, поэтому, похоже, что-то не так с конкретным возвратом Flowable в качестве ответа. Если я просто верну Flowable.fromIterable(setOf("hello", "world")), он тоже вылетит.   -  person VaclavDedik    schedule 10.02.2020
comment
@VaclavDedik, я рад, что смог помочь :) Я также видел некоторые предупреждения на этапе усложнения собственного изображения, например Предупреждение: инициализация класса io.micronaut.http.bind.binders.ContinuationArgumentBinder завершилась неудачно с исключением java.lang.NoClassDefFoundError: kotlin / TypeCastException. Этот класс будет инициализирован во время выполнения, поскольку для построения изображения используется опция --allow-incomplete-classpath. Используйте параметр --initialize-at-run-time = io.micronaut.http.bind.binders.ContinuationArgumentBinder, чтобы явно запросить отложенную инициализацию этого класса.   -  person Benjamin    schedule 10.02.2020
comment
@Benjamin Да, я тоже это видел, когда пользовался вашим приложением. Мое приложение этого не делает, возможно, это потому, что мое приложение использует Kotlin, но кто знает :)   -  person VaclavDedik    schedule 10.02.2020


Ответы (2)


Ok. Поскольку это единственный вопрос, который возникает всякий раз, когда кто-то ищет cloud run 503 error, я хотел бы поделиться своим ужасным опытом и решением.

Я развернул приложение весенней загрузки в облаке и настроил для него триггер push-подписки pub-sub. Я тестировал его в своей локальной системе. Затем я протестировал его на своем частном проекте GCP. А затем, когда я развернул его в учетной записи GCP моей организации, я начал получать ошибку 503.

После этого я попробовал следующее.

  1. Я попытался изменить роли / разрешения учетной записи службы по умолчанию (которая использовалась экземпляром запуска), предоставив максимальные разрешения, но это было бесполезно.
  2. Пытался изменить параллелизм на 1 (как предлагается в документации GCP), но безрезультатно.
  3. Я начал сравнивать каждую конфигурацию моего экземпляра запуска с моим частным экземпляром запуска GCP, а затем я обнаружил, что я по ошибке проверил параметр ниже, который вызывал эту проблему.

введите описание изображения здесь

Итак, я снял флажок, повторно развернул свой экземпляр, и он сработал.

person Manish Bansal    schedule 12.02.2021
comment
не могли бы вы указать, где я могу увидеть часть подключений в GCP, как показано на скриншоте? - person Abdulkader Khateeb; 13.02.2021
comment
Вам нужно перейти в облачный запуск, щелкнуть свой сервис, нажать кнопку редактирования вверху, и тогда откроется эта страница. (Названия кнопок могут быть разными, я не помню, но вы сможете найти). - person Manish Bansal; 13.02.2021
comment
Я получил доступ к этой странице, и эта опция уже не отмечена, к сожалению, проблема (503 Service Unavailable) все еще существует - person Abdulkader Khateeb; 13.02.2021
comment
Это была ОГРОМНАЯ помощь. Абсолютно проблема, и я даже не использую эту настройку. Спасибо!!!! - person m-torin; 30.04.2021

Таким образом, похоже, что суть проблемы в том, что Cloud Run в настоящее время не поддерживает потоковую передачу HTTP:

https://cloud.google.com/run/docs/issues#grpc_websocket

И когда я возвращаю Flowable с Micronauts, он открывает потоковое HTTP-соединение. Таким образом, решение состоит в том, чтобы не использовать Flowable (или любой другой неограниченный издатель, например Flow, Flux и т. Д.) В качестве ответа.

person VaclavDedik    schedule 12.02.2020