Полезный способ выяснить, что и где сломано.

Ах да, "Он отлично работает на моей машине!" Пожалуй, самая известная поговорка в нашей индустрии. Даже с появлением контейнеров, которые обеспечивают согласованные среды в SDLC, мы все еще слышим, как разработчики возвращаются к этому заявлению при обнаружении дефекта. Но, в конце концов, если код не работает в тестовом или производственном режиме, он не работает, даже если работает локально. Поэтому, как разработчику, возможность глубоко погрузиться в ваше контейнерное приложение, чтобы решить проблему, независимо от среды, является критически важным навыком, который мы все должны освоить.

Давайте посмотрим на пример приложения, которое работает локально, но не работает при развертывании, и как вы можете использовать научный метод (вы помните это из школы, верно?) Для отладки этих сбоев в контейнерных приложениях.

Наш пример

Для нашего примера мы будем использовать простое приложение Flask, развернутое в контейнере Kubernetes, которое отображает известных людей, которые использовали наше приложение. Он безупречно работает в нашей локальной системе!

Теперь давайте развернем это в нашем сервисе Heroku и посмотрим, будет ли он вести себя так же (подсказка: не будет).

heroku container:push worker -a heroku-troubleshooting

heroku container:release worker -a heroku-troubleshooting

Драт! Помешано мощной производственной средой. Теперь мы можем начать вникать в то, что произошло, и посмотреть, какие инструменты есть в нашем распоряжении.

Наш подход

Когда ваше приложение дает сбой, полезно использовать беспристрастный и объективный подход, чтобы отсортировать проблему и понять ошибки. Один из таких классических подходов - Научный метод. Прошедшие сотни лет тщательных повторений и проверок, я обнаружил, что этот метод отлично подходит для современной отладки.

Слишком часто разработчики и инженеры DevOps применяют разрозненный подход к отладке «давайте посмотрим, что это делает». Мы хватаем первое, что приходит в голову, что может быть неправильным, меняем наш код / ​​конфигурацию, развертываем и смотрим, сработало ли это. И если это не сработает, мы просто продолжаем пытаться, иногда забывая о том, что мы уже пробовали, иногда проводя часы или даже дни, идя по пути, который, если мы просто остановимся и подумаем об этом на минуту, явно будет неправильным путем. . Но если мы будем использовать более аргументированный, структурированный подход, такой как научный метод, наш процесс отладки может быть более продуктивным, быстрым и, в конце концов, лучше.

В основе научного метода лежит формирование гипотезы, проведение экспериментов, наблюдение за результатами и последующее уточнение вашей гипотезы. Научный метод, который я применяю для отладки контейнерных приложений, выглядит так:

  1. Спросите: «Что должно происходить?»
  2. Определите причины, которые могут объяснить, почему этого не.
  3. Разработайте тест для проверки / признания недействительным этих утверждений, настроив конфигурацию или используя инструмент.
  4. Наблюдайте за результатом.
  5. Делать вывод.
  6. Повторяйте, пока результат не будет таким, каким должен быть.

Научный метод в действии

Теперь давайте посмотрим на этот подход в действии.

1. Спросите: «Что должно происходить?»

Во-первых, нам нужно понять, что пытается делать наше приложение. Чтобы начать расследование, нам нужно понять детали рендеринга страницы. Давайте посмотрим, как Dockerfile описывает нашу службу:

FROM python:3
WORKDIR /usr/src/app
COPY requirements.txt ./
RUN pip install --no-cache-dir -r requirements.txt
RUN echo "healthy" >> /tmp/healthy && \
        cat /tmp/healthy
ENV FLASK_ENV=development
ENV FLASK_APP=myapp.py
COPY myapp.py .
CMD [ "python3", "myapp.py" ]

Довольно просто. У нас есть приложение Python3, оно устанавливает некоторые требования, а затем запускается myapp.py. Давайте быстро посмотрим, что делает наше приложение Python, и тогда мы сможем решить, что делать дальше.

from flask import Flask, Response
import os
import psycopg2
app = Flask(__name__)
query = ("select * from actor order by random() limit 5;")
host = os.getenv("host")
password = os.getenv("PSQL_PASSWORD")
user = os.getenv("PSQL_USERNAME")
dbname = os.getenv("PSQL_DBNAME")
print(host)
print(user)
print(dbname)
def callpsql():
    conn = psycopg2.connect(dbname=dbname, user=user, password=password, host=host, port="5432")
    cur = conn.cursor()
    cur.execute(query)
    results = cur.fetchall()
    cur.close()
    conn.close()
    return results
@app.route('/')
def index():
    response = callpsql()
    print("Getting some juicy logs")
    results = "I've sold to these famous people from server "+os.getenv("DYNO")+": <br>\n"
    for row in response:
        results = results+"<br>\n"+str(row[1])+"\t"+str(row[2])
    return results
@app.route('/health')
def health():
    f = open("/tmp/healthy", "r")
    print(f)
    health = f.readline().rstrip()
    resp = Response(health)
    if health != "healthy":
        resp.status=500
    resp.headers['health-check'] = health
    return resp
if __name__ == "__main__":
    port = 5000
    app.run(debug=True, host='0.0.0.0', port=port)

Еще одно довольно простое приложение. Это принимает несколько переменных среды для аутентификации и выполняет SQL-запрос к базе данных Postgres при вызове корневой страницы.

2. Определите причины, которые могут объяснить, почему этого не происходит

Теперь, когда мы знаем, что приложение пытается делать, мы переходим к следующему шагу и объясняем, почему этого не происходит в нашей новой среде.

Здесь мы можем посмотреть на команду Heroku logs --tail, которая предлагается на странице ошибки. Это должно дать нам хорошее представление о том, что делает наш сервис в любой момент времени, а также помочь нам сформировать гипотезу относительно того, в чем может быть проблема.

$ heroku logs --tail -a heroku-troubleshooting
...
2020-08-22T22:45:34.805282+00:00 heroku[router]: at=error code=H14 desc="No web processes running" method=GET path="/" host=heroku-troubleshooting.herokuapp.com request_id=09292b76-b372-49e9-858b-e8611c020fd5 fwd="xx.xx.xx.xx" dyno= connect= service= status=503 bytes= protocol=https
…

Мы видим, что каждый раз при загрузке страницы появляется сообщение об ошибке «Нет запущенных веб-процессов». Похоже, Heroku не знает, что мы запустили Flask. Большой! У нас есть гипотеза: «Вероятно, Flask не работает в среде Heroku».

3. Разработайте тест для подтверждения / признания этих утверждений недействительным, настроив конфигурацию или используя инструмент

Теперь перейдем к следующим шагам: создадим тест, чтобы проверить, что, по нашему мнению, происходит, наблюдать за результатом и сделать вывод.

Итак, давайте проверим нашу гипотезу. Мы подключимся к нашему стенду и проверим, действительно ли служба Flask работает (или не работает). Наш Dockerfile указывает, что python должен быть работающей службой прослушивания.

$ heroku ps:exec -a heroku-troubleshooting
Establishing credentials... error
 ▸    Could not connect to dyno!
 ▸    Check if the dyno is running with `heroku ps'

4. Наблюдайте за результатом

Мы выпустили наш контейнер, поэтому он должен работать. Однако журналы нашего теста показали, что мы не можем подключиться к дино, на котором должен выполняться код. Выполнение предложенной команды может дать нам еще одну подсказку.

$ heroku ps -a heroku-troubleshooting

No dynos on ⬢ heroku-troubleshooting

5. Сделайте вывод

Ну, это неудобно. Вывод научного метода? Мы ошибались в нашем первоначальном утверждении, что наш выпущенный код оставил нам работающий динамометрический стенд для обслуживания кода. Мы определенно продвинули и выпустили наш образ, но мы не добавляли никаких дино в наше приложение. Похоже, мы подтвердили, что приложение не запущено и что наша гипотеза неверна.

6. Повторяйте до тех пор, пока результат не будет таким, каким должен быть.

Итак, мы переходим к следующему шагу, который должен повторить процесс, и мы будем повторять этот процесс на протяжении всей статьи, пока наша проблема не будет решена.

Итак, давайте сформулируем новую гипотезу и проверим ее. Наша новая гипотеза, основанная на последнем тесте, заключается в том, что при работающем динамометрическом стенде мы сможем получить доступ к нашему приложению Flask из внешнего мира. Мы масштабируем дино, чтобы запустить приложение, и снова проверим журналы, чтобы проверить это утверждение.

$ heroku dyno:scale -a heroku-troubleshooting worker=1
Scaling dynos... done, now running worker at 1:Standard-1X
$ heroku logs --tail -a heroku-troubleshooting
2020-08-22T23:29:05.207217+00:00 app[api]: Scaled to worker@1:Standard-1X by user
2020-08-22T23:29:18.202160+00:00 heroku[worker.1]: Starting process with command `python3 myapp.py`
2020-08-22T23:29:18.760500+00:00 heroku[worker.1]: State changed from starting to up
2020-08-22T23:29:21.559386+00:00 app[worker.1]: None
2020-08-22T23:29:21.559547+00:00 app[worker.1]: None
2020-08-22T23:29:21.559548+00:00 app[worker.1]: None
2020-08-22T23:29:21.559549+00:00 app[worker.1]: * Serving Flask app "myapp" (lazy loading)
2020-08-22T23:29:21.559556+00:00 app[worker.1]: * Environment: development
2020-08-22T23:29:21.559556+00:00 app[worker.1]: * Debug mode: on
2020-08-22T23:29:21.636027+00:00 app[worker.1]: * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
2020-08-22T23:29:21.637965+00:00 app[worker.1]: * Restarting with stat
2020-08-22T23:29:21.897821+00:00 app[worker.1]: * Debugger is active!
2020-08-22T23:29:21.929543+00:00 app[worker.1]: * Debugger PIN: 485-744-571

Итак, мы идем. Теперь приложение запущено! Пришло время снова протестировать сайт, чтобы убедиться, что он работает.

Наш вывод сейчас: это определенно не так. Мы должны снова просмотреть наши команды и посмотреть, изменился ли статус вообще, чтобы мы могли создать новую гипотезу.

$ heroku logs -a heroku-troubleshooting
2020-08-22T23:32:12.098568+00:00 heroku[router]: at=error code=H14 desc="No web processes running" method=GET path="/" host=heroku-troubleshooting.herokuapp.com request_id=4d3cbafa-cb31-4452-bfc6-7ee18ce72eb0 fwd="xx.xx.xx.xx" dyno= connect= service= status=503 bytes= protocol=https

$ heroku ps -a heroku-troubleshooting
=== worker (Standard-1X): python3 myapp.py (1)
worker.1: up 2020/08/22 16:31:59 -0700 (~ 3m ago)

Похоже, у нас запущена служба, но мы не можем получить больше данных, используя только журналы. Гипотетически мы можем подключиться к сервису и убедиться, что он работает.

$ heroku ps:exec -d worker.1 -a heroku-troubleshooting
Establishing credentials... error
 ▸    Could not connect to dyno!
 ▸    Check if the dyno is running with `heroku ps'

Здесь мы видим, что даже при работающем динамометрическом стенде мы не можем подключиться к нему. Оглядываясь назад на наш Dockerfile и некоторую документацию, мы можем сделать вывод, что для среды Heroku требуется несколько необходимых условий для поддержки exec в развернутых контейнерах. Мы должны добавить несколько служебных команд, которые могут нам понадобиться, пока мы здесь, чтобы проверить будущие гипотезы, пока мы проверяем, позволит ли эта новая конфигурация нам подключиться.

Dockerfile

...
RUN apt-get update && \
        apt-get install -y \
                curl \
                openssh-server \
                           net-tools \
                           dnsutils \
                           iproute2
RUN mkdir -p /app/.profile.d && \
        touch /app/.profile.d/heroku-exec.sh && \
        echo '[ -z "$SSH_CLIENT" ] && source <(curl --fail --retry 3 -sSL "$HEROKU_EXEC_URL")' >> /app/.profile.d/heroku-exec.sh && \
        chmod +x /app/.profile.d/heroku-exec.sh
...

Еще одно нажатие и отпускание позже, и мы подтвердили, что наш вывод был правильным, и мы, наконец, можем подключиться:

$ heroku ps:exec -d worker.1 -a heroku-troubleshooting
Establishing credentials... done
Connecting to worker.1 on ⬢ heroku-troubleshooting...
The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.
Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
~ $

Теперь, когда мы вошли в приложение, мы можем проверить нашу гипотезу о том, что порт прослушивает так, как должен, и что наше приложение реагирует изнутри самого контейнера. Мы можем использовать команду net-tools netstat в качестве теста, чтобы показать нам список портов, открытых в нашем контейнере, и прослушивать вызовы для открытия сокета.

~ $ netstat -apn | grep 5000 | grep LIST
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:5000            0.0.0.0:*               LISTEN      3/python3

Наш анализ показывает, что порт открыт, как и ожидалось, и наша гипотеза верна.

Поскольку ничего не изменилось, мы должны разработать новый тест. «Curl» может действовать как наш интернет-браузер с командной строкой, чтобы показать нам упрощенное представление о том, что порт, который мы теперь проверили, открыт и правильно прослушивает.

~ $ curl -I localhost:5000
HTTP/1.0 500 INTERNAL SERVER ERROR
Content-Type: text/html; charset=utf-8
X-XSS-Protection: 0
Server: Werkzeug/1.0.1 Python/3.8.5
Date: Sun, 23 Aug 2020 00:27:14 GMT
~ $ curl localhost:5000
...
psycopg2.OperationalError: could not connect to server: No such file or directory
        Is the server running locally and accepting
        connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"?
...

Ага! Наш анализ этой ошибки доказывает, что вызовы не выполняются, потому что в нашем приложении возникает ошибка 500. Наша новая гипотеза состоит в том, что это, безусловно, по крайней мере одна причина, по которой Heroku не будет отправлять трафик в наше приложение. Если мы посмотрим на наш код Python, мы увидим, что он требует некоторых переменных среды. На нашем локальном хосте они экспортируются как часть виртуальной среды разработки. Теперь мы можем сделать вывод, что их также необходимо добавить в наше приложение на Heroku.

Наша новая гипотеза звучит так: «Служба должна работать, как ожидается, как в локальной, так и в производственной среде». Чтобы проверить эту гипотезу и принять новое изменение, нам нужно перезапустить наш worker, что должно позволить приложению принять новые переменные среды.

$ heroku ps:restart worker.1 -a heroku-troubleshooting
Restarting worker.1 dyno on ⬢ heroku-troubleshooting... done
$ heroku ps:exec -d worker.1 -a heroku-troubleshooting
Establishing credentials... done
Connecting to worker.1 on ⬢ heroku-troubleshooting...
The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.
Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
~ $ curl -I localhost:5000
HTTP/1.0 200 OK
Content-Type: text/html; charset=utf-8
Content-Length: 148
Server: Werkzeug/1.0.1 Python/3.8.5
Date: Sun, 23 Aug 2020 00:50:35 GMT
~ $ curl localhost:5000
I've sold to these famous people from server worker.1: <br>
<br>
Julianne        Dench<br>
Sylvester       Dern<br>
Greta   Keitel<br>
Dustin  Tautou<br>
Penelope        Monroe

Мы убедились, что локальный контейнер работает должным образом, после повторного запуска наших предыдущих тестов. Тем не менее, наши журналы и браузер делают вывод, что приложение по-прежнему не работает должным образом.

Бревна из наших внутренних локонов:

2020-08-23T00:50:35.931678+00:00 app[worker.1]: 127.0.0.1 - - [23/Aug/2020 00:50:35] "[37mHEAD / HTTP/1.1[0m" 200 -

2020-08-23T00:50:41.807629+00:00 app[worker.1]: 127.0.0.1 - - [23/Aug/2020 00:50:41] "[37mGET / HTTP/1.1[0m" 200 -

Журналы из нашего внешнего браузера:

2020-08-23T00:50:47.151656+00:00 heroku[router]: at=error code=H14 desc="No web processes running" method=GET path="/" host=heroku-troubleshooting.herokuapp.com request_id=a9421f09-94f2-4822-9608-f2f63ffe5123 fwd="68.251.62.251" dyno= connect= service= status=503 bytes= protocol=https

Когда приложение работает в контейнере, кажется, что гипотетически все должно работать нормально. Использование нашего предыдущего повторного запуска тестов и более тщательный анализ ошибки Нет запущенных веб-процессов дает нам еще один намек. Есть два типа дино, и мы развернули их как рабочие. Глядя на документацию, мы можем сделать вывод, что, возможно, мы развернули не тот тип ресурса, который не получает вход. Гипотетически Heroku должен предоставить динамический внешний порт, если мы настроим динамометрический стенд как веб, а не рабочий. Пришло время протестировать повторное развертывание в качестве веб-дино.

heroku ps:scale worker=0 -a heroku-troubleshooting
heroku container:push web -a heroku-troubleshooting
heroku container:release web -a heroku-troubleshooting
heroku ps:scale web=1 -a heroku-troubleshooting

Просмотр сайта по-прежнему дает тот же вывод, что и наши первоначальные тесты, но теперь наши наблюдаемые журналы дают нам следующую цепочку для исследования.

2020-08-23T01:03:12.890612+00:00 app[web.1]:  * Serving Flask app "myapp" (lazy loading)
2020-08-23T01:03:12.890619+00:00 app[web.1]:  * Environment: development
2020-08-23T01:03:12.890620+00:00 app[web.1]:  * Debug mode: on
2020-08-23T01:03:12.905580+00:00 app[web.1]:  * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
2020-08-23T01:03:12.906860+00:00 app[web.1]:  * Restarting with stat
2020-08-23T01:03:13.661451+00:00 app[web.1]:  * Debugger is active!
2020-08-23T01:03:13.662395+00:00 app[web.1]:  * Debugger PIN: 196-723-097
2020-08-23T01:04:07.990856+00:00 heroku[web.1]: Error R10 (Boot timeout) -> Web process failed to bind to $PORT within 60 seconds of launch
2020-08-23T01:04:08.016515+00:00 heroku[web.1]: Stopping process with SIGKILL
2020-08-23T01:04:08.224860+00:00 heroku[web.1]: Process exited with status 137
2020-08-23T01:04:08.290383+00:00 heroku[web.1]: State changed from starting to crashed
2020-08-23T01:04:08.293139+00:00 heroku[web.1]: State changed from crashed to starting
“Web process failed to bind to $PORT”

Мы можем сделать вывод, что нам нужно привязать наш процесс к переменной, а не к нашему порту Flask по умолчанию. Это достаточно просто исправить в нашем приложении Python. Если у нас есть правильная переменная, отображаемая в нашей производственной среде, и наше приложение использует ее в качестве конфигурации порта, тогда у нас должен быть полностью функционирующий сайт. Чтобы проверить это, мы можем передать переменную среды с хоста и использовать ее в нашем аргументе app.run.

myapp.py
if __name__ == "__main__":
    port = int(os.getenv("PORT", 5000))
    app.run(debug=True, host='0.0.0.0', port=port)

И вот оно! Наш анализ теста показывает, что приложение работает как локально, так и при развертывании. Еще одна последняя проверка, чтобы убедиться, что наши изменения продолжают работать и в нашей среде разработки.

Собираем все вместе

В этом рабочем процессе мы использовали научный метод для исследования приложения, которое не выполнялось при рендеринге в производственной среде. Отладка управляемой инфраструктуры - непростая задача, но только из-за совокупности ее частей. Разбивая каждый уровень продукта, анализируя его поведение с помощью стандартных инструментов, извлекая подсказки из выходных данных журналов и выходных данных приложений, а также просматривая различную документацию по продукту, мы можем разбить эти сложные структуры на осмысленные и простые выводы, которые воскреснут. любая услуга.

Если вы хотите дополнительно проанализировать развернутое нами приложение, вы можете увидеть его здесь. В следующий раз, когда вы обнаружите, что исследуете сложную проблему, не забудьте взять каждый компонент по одному слою за раз и применять методические, научные подходы к процессу. Поступая так, вы можете устранить большую часть личных предубеждений, которые в противном случае потенциально могли бы пустить вас в безумную погоню за статьями StackOverflow и случайными форумами сообщества.