تمارين Kata في تشخيص الأعطال بثلاثة مستويات مع الحلول

الأمر التالي هو سجل Nginx، لأنه الطرف الذي أعطى 502 ويعرف لماذا، والمخرج سوف يكون كما يلي:

$ docker logs --tail 2 lab-kata-ops-ts-nginx
2026/10/07 08:28:23 [error] 22#22: *3 connect() failed (111: Connection refused) while connecting to upstream, client: 192.168.96.1, server: , request: "GET / HTTP/1.1", upstream: "http://192.168.96.2:8000/", host: "127.0.0.1:21415"
192.168.96.1 - - [07/Oct/2026:08:28:23 +0000] "GET / HTTP/1.1" 502 157 "-" "curl/8.12.1" "-"

الرسالة Connection refused تعني أن العنوان موجود ولا يوجد شيء يستمع على المنفذ، فالخطوة التالية حالة التطبيق:

$ docker ps -a --filter name=lab-kata-ops-ts --format 'table {{.Names}}\t{{.Status}}'
NAMES                   STATUS
lab-kata-ops-ts-app     Up 1 second
lab-kata-ops-ts-nginx   Up 52 seconds
$ docker inspect lab-kata-ops-ts-app --format 'RestartCount={{.RestartCount}} ExitCode={{.State.ExitCode}}'
RestartCount=7 ExitCode=1
$ docker logs --tail 6 lab-kata-ops-ts-app
Traceback (most recent call last):
  File "/app.py", line 6, in <module>
    DATABASE_URL = os.environ["DATABASE_URL"]      # new in 2.0: required setting
                   ~~~~~~~~~~^^^^^^^^^^^^^^^^
  File "<frozen os>", line 717, in __getitem__
KeyError: 'DATABASE_URL'

في المخرج أعلاه لاحظ التالي:

• Up 1 second يبدو حالة سليمة، وهذا فخ، فال Container يعمل لأن سياسة --restart unless-stopped تعيده كل مرة، والدليل الحقيقي هو RestartCount=7 وExitCode=1.
• السبب الجذري Root Cause أن النسخة 2.0 تحتاج إعداداً جديداً DATABASE_URL لم يضف إلى بيئة الإنتاج، والإصلاح السريع إما أن تضيف المتغير وتعيد النشر، أو تتراجع إلى 1.0 إذا لم تعرف القيمة الصحيحة الآن.
• إعادة تشغيل Nginx لم تكن لتغير شيئاً، والأسوأ أنها تمسح من ذهنك أن المشكلة بدأت مع النشر.
• للمستقبل: أي إعداد جديد يذكر في ملاحظات النسخة، والتطبيق يفحص إعداداته عند التشغيل ويطبع رسالة واضحة، وفحص صحة Healthcheck في خط النشر يمنع اعتبار النشر ناجحاً.

للتفصيل: حالة 502 و504 في دليل استكشاف الأخطاء، وتجربة 502 في دليل تتبع الطلب البطيء.

سجل Nginx يعطي نفس السطر connect() failed (111: Connection refused) إلى 192.168.96.2:8000، فالأمر التالي سجل التطبيق، ثم الاختبار من مكان Nginx:

$ docker logs lab-kata-ops-ts-app
listening on 0.0.0.0:8080 (v2.0)
$ docker exec lab-kata-ops-ts-nginx wget -qO- http://lab-kata-ops-ts-app:8000/
wget: can't connect to remote host (192.168.96.2): Connection refused
$ docker exec lab-kata-ops-ts-nginx wget -qO- http://lab-kata-ops-ts-app:8080/
ok from 6fcdef9de0fb v2.0
$ docker exec lab-kata-ops-ts-app cat /proc/net/tcp
  sl  local_address rem_address   st tx_queue rx_queue tr tm->when retrnsmt   uid  timeout inode
   0: 00000000:1F90 00000000:0000 0A 00000000:00000000 00:00000000 00000000     0        0 899805 1 000000009d9cf5fd 100 0 0 10 0
   1: 0B00007F:AA5B 00000000:0000 0A 00000000:00000000 00:00000000 00000000     0        0 901609 1 000000006df71daf 100 0 0 10 0

في المخرج أعلاه لاحظ التالي:

• التطبيق يستمع على 8080 وNginx يرسل إلى 8000، وهذا هو السبب الجذري. والإصلاح أن تثبت المنفذ صراحة في إعداد التطبيق PORT=8000، ولا تعتمد على القيمة الافتراضية لمكتبة قد تتغير.
• ال Docker Image الصغير لا يحتوي على ss أو netstat، فقرأنا الجدول الذي تقرأ منه هذه الأدوات: 1F90 بالست عشري هي 8080، والحالة 0A تعني LISTEN، و00000000 تعني كل العناوين، والسطر الثاني 0B00007F هو 127.0.0.11 أي ال DNS الداخلي في Docker.
• الفرق بين هذا التمرين والذي قبله يظهر في الحالة وعدد مرات إعادة التشغيل، وليس في رسالة Nginx، فرسالة Nginx واحدة في الحالتين.

للتفصيل: حالة 502 في دليل شبكات Docker، وقسم ss وحالات الاتصال في دليل تحليل أداء Linux.

صنعنا الحادثة في Container فيه قسم صغير بحجم 64 ميجابايت (--tmpfs /srv:size=64m) حتى لا نملأ قرص جهازك. والأمر التالي df -h على المسار نفسه، ثم du ثم find، والمخرج سوف يكون كما يلي:

$ df -h /srv
Filesystem                Size      Used Available Use% Mounted on
tmpfs                    64.0M     64.0M         0 100% /srv
$ du -xh -d2 /srv | sort -h | tail -4
3.8M	/srv/shop/uploads
60.2M	/srv/shop/logs
64.0M	/srv
64.0M	/srv/shop
$ find /srv -xdev -type f -size +10240k -exec ls -lh {} +
-rw-r--r--    1 root     root       60.2M Oct  7 08:44 /srv/shop/logs/app.log
$ truncate -s 0 /srv/shop/logs/app.log && df -h /srv
Filesystem                Size      Used Available Use% Mounted on
tmpfs                    64.0M      3.8M     60.2M   6% /srv
$ echo "{\"id\": 1042}" > /srv/shop/data/order-1042.json && cat /srv/shop/data/order-1042.json
{"id": 1042}

في المخرج أعلاه لاحظ التالي:

• السبب الجذري ملف سجل واحد بلا تدوير Rotation، والإصلاح السريع truncate وليس rm، لأن التطبيق يبقي الملف مفتوحاً، والحذف لا يعيد المساحة حتى يغلقه، وهذه حالة مستقلة شرحناها في تمرين الملف المحذوف في تمارين Linux.
• الإصلاح الدائم تدوير السجلات بالأداة logrotate، أو حدود حجم لسجلات Docker في daemon.json، وتنبيه عندما يتجاوز القرص 80% قبل أن يصل إلى 100%.
• ابدأ دائماً من df على المسار الذي فشلت فيه الكتابة، لأن السيرفر قد يكون فيه عدة أقسام، وقد يكون القسم الممتلئ غير الذي تظنه.

للتفصيل: قسم القرص الممتلئ في دليل تحليل أداء Linux، وقسم logrotate في دليل السجلات.

137 = 128 + 9، أي أن العملية قتلت بالإشارة SIGKILL، ولهذا لا يوجد خطأ في السجل. والأمر التالي docker inspect لمعرفة من قتلها:

$ docker inspect lab-kata-ops-ts-oom --format 'ExitCode={{.State.ExitCode}} OOMKilled={{.State.OOMKilled}} Memory={{.HostConfig.Memory}}'
ExitCode=137 OOMKilled=true Memory=67108864

والحادثة صنعناها بهذا الأمر، وفيه حد ذاكرة 64 ميجابايت وكود يضيف 8 ميجابايت إلى الذاكرة كل 0.2 ثانية دون أي حد:

docker run --name lab-kata-ops-ts-oom -m 64m --memory-swap 64m python:3.13-slim python -c "
import time
cache = []
for i in range(1, 200):
    cache.append(bytearray(8 * 1024 * 1024))
    print(f'cached {i * 8} MB', flush=True)
    time.sleep(0.2)
"; echo "exit=$?"

في المخرج أعلاه لاحظ التالي:

• OOMKilled=true تعني أن النواة قتلت العملية لأنها تجاوزت حد الذاكرة في ال Container (67108864 بايت = 64 ميجابايت)، وآخر رقم في السجل 56 ميجابايت لأن المحاولة التالية تجاوزت الحد مع ذاكرة Python نفسها.
• السبب الجذري في الكود وليس في الحد: ذاكرة مؤقتة Cache بلا حد أعلى ولا وقت انتهاء، فرفع الحد إلى 512 ميجابايت يؤخر الحادثة فقط. والإصلاح أن تحدد حجم ال Cache، وبعدها تضبط الحد حسب ما تقيسه بالأمر docker stats.
• 137 قد تأتي أيضاً من docker kill أو من انتهاء مهلة docker stop، ولذلك لا تحكم من الرقم وحده، فالحقل OOMKilled هو الذي يفرق.

للتفصيل: قسم OOM في دليل تحليل أداء Linux، وحدود الموارد في توثيق Docker.

صنعنا شهادة من جهة إصدار CA خاصة بالمختبر، صلاحيتها من 1 يوليو حتى 5 أكتوبر 2026، وشغلناها على Nginx في المنفذ 21416. والأمر التالي يقرأ الشهادة التي يرسلها السيرفر الآن، لأن الملف على القرص قد يكون غير الذي حمله السيرفر في الذاكرة:

echo | openssl s_client -connect shop.example.test:21416 -servername shop.example.test -CAfile /certs/ca.crt 2>/dev/null | grep -E "Verify return code|Verification error"
echo | openssl s_client -connect shop.example.test:21416 -servername shop.example.test 2>/dev/null | openssl x509 -noout -subject -enddate
date -u

والمخرج سوف يكون كما يلي:

Verification error: certificate has expired
Verify return code: 10 (certificate has expired)
subject=CN=shop.example.test
notAfter=Oct  5 00:00:00 2026 GMT
Wed Oct  7 08:48:27 UTC 2026

وبعد إصدار شهادة جديدة لمدة 90 يوماً وإعادة تحميل Nginx بالأمر nginx -s reload:

notAfter=Jan  5 08:49:05 2027 GMT
$ curl -sS --cacert /certs/ca.crt https://shop.example.test:21416/
shop ok

في المخرج أعلاه لاحظ التالي:

• الخيار -servername يرسل اسم الموقع SNI، وبدونه قد يرد السيرفر بشهادة موقع آخر على نفس العنوان، فتشخص الشهادة الخطأ.
• تحقق من date -u على السيرفر وعلى جهاز العميل، فالساعة الخاطئة تعطي نفس الرسالة لشهادة سليمة.
• السبب الجذري ليس الشهادة وإنما أن التجديد التلقائي لم يعمل ولم ينبه أحداً، فبعد التجديد افحص لماذا فشل (مهمة cron متوقفة، أو منفذ 80 مغلق أمام التحقق، أو Reload لم يحدث)، وأضف مراقبة تنبه قبل الانتهاء بأسبوعين على الأقل.

للتفصيل: تجربة الانتهاء في دليل الشهادات الرقمية، وحالة الشهادة في دليل استكشاف الأخطاء.

شغلنا التطبيق بالمتغير REPORT_SECONDS=8، ووضعنا في إعداد Nginx السطر proxy_read_timeout 5s;. والأمر التالي سجل Nginx، ثم قياس التطبيق مباشرة:

$ docker logs --tail 2 lab-kata-ops-ts-nginx
2026/10/07 08:35:40 [error] 60#60: *15 upstream timed out (110: Operation timed out) while reading response header from upstream, client: 192.168.96.1, server: , request: "GET /report?year=2026 HTTP/1.1", upstream: "http://192.168.96.2:8000/report?year=2026", host: "127.0.0.1:21415"
192.168.96.1 - - [07/Oct/2026:08:35:40 +0000] "GET /report?year=2026 HTTP/1.1" 504 167 "-" "curl/8.12.1" "-"
$ docker exec lab-kata-ops-ts-nginx sh -c 'time wget -qO- http://lab-kata-ops-ts-app:8000/report?year=2026'
ok from 1d9c8ff8381e v1.0
real	0m 8.00s
user	0m 0.00s
sys	0m 0.00s

في المخرج أعلاه لاحظ التالي:

• 502 تعني أن الاتصال فشل أو جاء رد غير صالح، و504 تعني أن الاتصال نجح والتطبيق لم يرد في المهلة، والرسالة upstream timed out ... while reading response header تقول ذلك حرفياً.
• التطبيق يأخذ 8 ثوان والمهلة 5، فالإصلاح السهل رفع المهلة، لكنه يخفي السؤال الحقيقي: لماذا يأخذ التقرير 8 ثوان؟ وكل طلب معلق يحجز اتصالاً وخيطاً Thread في التطبيق، ومع عشرين زائراً يطلبون التقرير تتعطل بقية الصفحات.
• الإصلاح الصحيح للتقارير الثقيلة أن تبنى في الخلفية وترسل عند جهوزها، أو أن تحفظ نتيجتها مسبقاً، وأن تقيس الاستعلام الذي خلفها كما في التمرين 7. والقيمة الافتراضية للمهلة في Nginx هي 60 ثانية، وأي قيمة أخرى قرار يكتب سببه بجانبه.

للتفصيل: حالة 504 في دليل تطبيقك خلف Reverse Proxy، وقسم رموز الحالة في دليل تتبع الطلب البطيء.

صنعنا الحادثة في PostgreSQL 18 بجدول customers فيه مليونا صف بلا فهرس على البريد، وحمل من عشرة اتصالات بالأداة pgbench:

docker run -d --name lab-kata-ops-ts-pg -e POSTGRES_PASSWORD=example postgres:18-alpine -c max_connections=20
docker exec -i lab-kata-ops-ts-pg psql -U postgres -c "create table customers(id bigserial primary key, email text not null, name text, created_at timestamptz default now()); insert into customers(email,name) select 'user'||g||'@example.com', 'Customer '||g from generate_series(1,2000000) g; analyze customers;"

والأمر التالي pg_stat_activity أثناء الحمل، لأنه يقول ماذا تفعل القاعدة الآن بدل أن تخمن، والمخرج سوف يكون كما يلي:

$ psql -c "select state, left(query, 70) as query, count(*) from pg_stat_activity where backend_type='client backend' and pid <> pg_backend_pid() group by 1,2 order by 3 desc;"
 state  |                                 query                                  | count
--------+------------------------------------------------------------------------+-------
 active | select id, name from customers where email = 'user' || 1083796 || '@ex |     1
 active | select id, name from customers where email = 'user' || 1807715 || '@ex |     1
 active | select id, name from customers where email = 'user' || 1845771 || '@ex |     1
 ...
(10 rows)
$ docker stats --no-stream lab-kata-ops-ts-pg
NAME                 CPU %     MEM USAGE / LIMIT
lab-kata-ops-ts-pg   847.75%   383.8MiB / 31.29GiB

كل الاتصالات العشرة تنفذ نفس الاستعلام، فالخطوة التالية خطته:

$ psql -c "explain (analyze, buffers) select id, name from customers where email = '[email protected]';"
 Gather  (cost=1000.00..33089.77 rows=1 width=24) (actual time=255.492..256.657 rows=1.00 loops=1)
   Workers Planned: 2
   Workers Launched: 2
   Buffers: shared hit=13365 read=8308 written=166
   ->  Parallel Seq Scan on customers  (cost=0.00..32089.67 rows=1 width=24) (actual time=242.874..242.875 rows=0.33 loops=3)
         Filter: (email = '[email protected]'::text)
         Rows Removed by Filter: 666666
         Buffers: shared hit=13365 read=8308 written=166
 Execution Time: 256.745 ms

صف واحد مطلوب، والقاعدة تقرأ الجدول كله بثلاث عمليات متوازية وتستبعد قرابة مليوني صف. والإصلاح فهرس على العمود، ثم نفس القياس:

$ psql -c '\timing on' -c "create index customers_email_idx on customers (email);"
Timing is on.
CREATE INDEX
Time: 27497.086 ms (00:27.497)
$ psql -c "explain (analyze) select id, name from customers where email = '[email protected]';"
 Index Scan using customers_email_idx on customers  (cost=0.43..8.45 rows=1 width=24) (actual time=0.063..0.064 rows=1.00 loops=1)
   Index Cond: (email = '[email protected]'::text)
 Execution Time: 0.150 ms

ونتيجة pgbench بعشرة اتصالات لمدة 20 ثانية قبل الفهرس وبعده على نفس الجهاز (أرقام توضيحية من جهاز المختبر، والمهم النسبة بينها):

$ pgbench -U postgres -n -c 10 -j 2 -T 20 -f /tmp/lookup.sql postgres     # before the index
number of clients: 10
number of transactions actually processed: 181
number of failed transactions: 0 (0.000%)
latency average = 1134.632 ms
tps = 8.813429 (without initial connection time)
$ pgbench -U postgres -n -c 10 -j 2 -T 20 -f /tmp/lookup.sql postgres     # after the index
number of transactions actually processed: 142679
number of failed transactions: 0 (0.000%)
latency average = 1.400 ms
tps = 7143.857459 (without initial connection time)

والملف lookup.sql يختار عميلاً عشوائياً في كل طلب:

\set n random(1, 2000000)
select id, name from customers where email = 'user' || :n || '@example.com';

في المخرج أعلاه لاحظ التالي:

• ترقية المعالج كانت ستضاعف السرعة في أحسن حال، والفهرس جعل الاستعلام أسرع من 250 ميلي ثانية إلى أقل من ميلي ثانية واحدة، لأن المشكلة كانت في كمية العمل وليس في سرعة العامل.
• بناء الفهرس أخذ 27 ثانية، وCREATE INDEX العادي يمنع الكتابة في الجدول طوال هذه المدة، وفي الإنتاج استخدم CREATE INDEX CONCURRENTLY الذي يبنيه دون أن يوقف الكتابة.
• «لم يتغير التطبيق» لا يعني أن شيئاً لم يتغير، فحجم البيانات تغير، والاستعلام الذي كان سريعاً على عشرة آلاف صف يصبح بطيئاً على مليونين.

للتفصيل: تجربة الفهرس الناقص في دليل تتبع الطلب البطيء، وحالة البطء للجميع في دليل استكشاف الأخطاء.

صنعنا الحادثة بقسم فيه 2000 Inode فقط (--tmpfs /srv:size=64m,nr_inodes=2000) وتطبيق ينشئ ملف جلسة صغيراً لكل زائر. والأمر التالي df -i، ثم البحث عن المجلد الذي فيه أكبر عدد من الملفات، والمخرج سوف يكون كما يلي:

$ df -i /srv
Filesystem              Inodes      Used Available Use% Mounted on
tmpfs                     2000      2000         0 100% /srv
$ for d in /srv/shop/*; do echo "$(find $d | wc -l) $d"; done | sort -n
1 /srv/shop/data
1997 /srv/shop/sessions
$ ls /srv/shop/sessions | head -3
sess_0
sess_1
sess_10
$ find /srv/shop/sessions -type f -delete; df -i /srv
Filesystem              Inodes      Used Available Use% Mounted on
tmpfs                     2000         4      1996   0% /srv

في المخرج أعلاه لاحظ التالي:

• رسالة النواة واحدة No space left on device لنفاد المساحة ولنفاد ال Inodes، والذي يفرق بينهما هو df -h مقابل df -i، فاجعل الأمرين معاً عادة.
• ال du لا يفيد هنا لأن الملفات صغيرة، والمفيد هو عد الملفات في كل مجلد.
• في الإنتاج لا تحذف كل الجلسات كما فعلنا في المختبر، وإنما القديمة فقط مثل find /srv/shop/sessions -type f -mmin +1440 -delete، والإصلاح الدائم أن ينظف التطبيق جلساته المنتهية، أو أن تنقل الجلسات إلى Redis أو قاعدة البيانات.

للتفصيل: قسم ال Inodes في دليل تحليل أداء Linux، وصفحة df في دليل Linux.

صنعنا الحادثة في نفس قاعدة التمرين السابق (max_connections=20) بمستخدم عادي اسمه shop، و17 اتصالاً مفتوحاً منه لا تفعل شيئاً. والأمر التالي الدخول بالمستخدم postgres الذي له المقاعد المحجوزة:

$ psql -U postgres -c "show max_connections;" -c "show superuser_reserved_connections;"
 max_connections
-----------------
 20
(1 row)

 superuser_reserved_connections
--------------------------------
 3
(1 row)

$ psql -U postgres -c "select usename, application_name, state, count(*), max(now() - state_change) as longest_in_state from pg_stat_activity where backend_type = 'client backend' group by 1,2,3 order by 4 desc;"
 usename  | application_name | state  | count | longest_in_state
----------+------------------+--------+-------+------------------
 shop     | shop-web         | idle   |    17 | 00:00:10.844264
 postgres | psql             | active |     1 | -00:00:00.000001
(2 rows)

في المخرج أعلاه لاحظ التالي:

• المتاح للمستخدمين العاديين هو 20 ناقص 3 = 17 اتصالاً، ونسختان بستة اتصالات تأخذان 12، أما ثلاث نسخ فتطلب 18، فيرفض الاتصال الثامن عشر، وهذا حساب تجريه قبل أن تزيد النسخ وليس بعدها.
• الاتصالات كلها idle، أي أن القاعدة لا تعمل بجهد، وإنما ال Pools تحجز اتصالات لا تستخدمها، فرفع max_connections إلى 500 ليس الحل، لأن كل اتصال في PostgreSQL عملية كاملة تأخذ ذاكرة.
• الإصلاح أن تحسب حجم ال Pool من حد القاعدة مقسوماً على عدد النسخ مع هامش للصيانة، أو أن تضع PgBouncer بين التطبيق والقاعدة فتشترك كل النسخ في عدد صغير من الاتصالات الحقيقية.

للتفصيل: قسم حجم ال Pool في دليل تجميع الاتصالات، وقسم النسخ المتعددة في نفس الدليل، وإعدادات الاتصال في توثيق PostgreSQL.

الأمر التالي هو نفس الطلب من Container Nginx، ثم جدول المنافذ في التطبيق:

$ docker exec lab-kata-ops-ts-nginx wget -qO- http://lab-kata-ops-ts-app:8000/
wget: can't connect to remote host (192.168.96.2): Connection refused
$ docker exec lab-kata-ops-ts-app sh -c "awk 'NR==1 || \$4==\"0A\" {print \$2, \$4}' /proc/net/tcp"
local_address st
0100007F:1F40 0A
0B00007F:8235 0A

وبعد إعادة التشغيل دون BIND=127.0.0.1، أي على 0.0.0.0:

local_address st
0B00007F:ADB5 0A
00000000:1F40 0A

في المخرج أعلاه لاحظ التالي:

• 0100007F:1F40 تعني 127.0.0.1:8000 (العنوان مقلوب البايتات، و1F40 هي 8000)، أي أن التطبيق يقبل الاتصالات من داخل ال Container فقط، وكل Container له 127.0.0.1 خاص به، فطلب Nginx يصل إلى عنوان الشبكة 192.168.96.2 حيث لا يستمع أحد.
• بعد الإصلاح أصبح السطر 00000000:1F40 أي كل العناوين، وهذا صحيح داخل Container لأن العزل يأتي من الشبكة ومن عدم نشر المنفذ، وليس من عنوان الاستماع.
• كثير من أطر العمل تستمع على 127.0.0.1 افتراضياً في وضع التطوير، مثل خادم التطوير في Flask وVite، فعند نقلها إلى Container تحتاج خياراً مثل --host 0.0.0.0.

للتفصيل: قسم التطبيق داخل Container في قائمة تحقق المطور.

السجل يجب أن يذكر النسخة التي ردت على كل طلب، فأضفنا صيغة سجل جديدة:

log_format upstreamlog '$remote_addr "$request" $status upstream=$upstream_addr '
                       'upstream_status=$upstream_status rt=$request_time';

server {
    listen 80;
    access_log /var/log/nginx/upstream.log upstreamlog;
    location / {
        proxy_pass http://shop;
    }
}

والأمر التالي قراءة السجل وتجميعه حسب النسخة، ثم طلب كل نسخة مباشرة، والمخرج سوف يكون كما يلي:

$ docker exec lab-kata-ops-ts-nginx tail -4 /var/log/nginx/upstream.log
192.168.96.1 "GET / HTTP/1.1" 500 upstream=192.168.96.4:8000 upstream_status=500 rt=0.001
192.168.96.1 "GET / HTTP/1.1" 200 upstream=192.168.96.2:8000 upstream_status=200 rt=0.001
192.168.96.1 "GET / HTTP/1.1" 500 upstream=192.168.96.4:8000 upstream_status=500 rt=0.001
192.168.96.1 "GET / HTTP/1.1" 200 upstream=192.168.96.2:8000 upstream_status=200 rt=0.001
$ docker exec lab-kata-ops-ts-nginx sh -c "awk '{print \$5, \$6}' /var/log/nginx/upstream.log | sort | uniq -c"
      5 200 upstream=192.168.96.2:8000
      5 500 upstream=192.168.96.4:8000
$ docker exec lab-kata-ops-ts-nginx wget -S -qO- http://lab-kata-ops-ts-app1:8000/
  HTTP/1.1 200 OK
$ docker exec lab-kata-ops-ts-nginx wget -S -qO- http://lab-kata-ops-ts-app2:8000/
  HTTP/1.1 500 Internal Server Error
$ docker inspect lab-kata-ops-ts-app1 lab-kata-ops-ts-app2 --format '{{.Name}} {{.Config.Env}}'
/lab-kata-ops-ts-app1 [APP_VERSION=1.4 PYTHON_VERSION=3.13.16 ...]
/lab-kata-ops-ts-app2 [APP_VERSION=1.4 BROKEN=1 PYTHON_VERSION=3.13.16 ...]

في المخرج أعلاه لاحظ التالي:

• كل الأخطاء من عنوان واحد، فالسبب في النسخة الثانية وحدها، ومقارنة إعداد النسختين تكشف الفرق، وهو في المختبر متغير BROKEN=1، وفي الواقع يكون إعداداً مختلفاً أو نسخة لم تحدث أو قرصاً ممتلئاً على سيرفر واحد.
• الإصلاح السريع أن تخرج النسخة المعطوبة من التوزيع بإضافة down بجانبها أو بإيقافها، ثم تصلحها بهدوء.
• نسخة Nginx المفتوحة المصدر لا تعتبر الرد 500 فشلاً في النسخة افتراضياً، فهو يعد أخطاء الاتصال والمهلة فقط حسب proxy_next_upstream، ولذلك استمر يرسل نصف الطلبات إلى النسخة المعطوبة، وهذا سبب وجود فحص الصحة Health Check في موزع الحمل.

للتفصيل: حالة الأعطال المتقطعة في دليل استكشاف الأخطاء، وقسم معرف الطلب في دليل السجلات.

صنعنا الحادثة بسيرفري dnsmasq على شبكة Docker: سيرفر موثوق على 10.250.77.10 يعطي السجل بمدة بقاء 300 ثانية، وResolver على 10.250.77.20 يحفظ الأجوبة، ثم غيرنا السجل في الموثوق. والأمر التالي أن تسأل السيرفر الموثوق مباشرة، ثم ال Resolver، والمخرج سوف يكون كما يلي:

$ dig @10.250.77.20 shop.example.test +noall +answer     # before the change
shop.example.test.	300	IN	A	203.0.113.10
$ dig @10.250.77.10 shop.example.test +noall +answer     # authoritative, after the change
shop.example.test.	300	IN	A	203.0.113.20
$ dig @10.250.77.20 shop.example.test +noall +answer     # visitor's resolver, after the change
shop.example.test.	255	IN	A	203.0.113.10

في المخرج أعلاه لاحظ التالي:

• السيرفر الموثوق يعطي العنوان الجديد، فالتغيير صحيح، وال Resolver يعطي العنوان القديم ومعه 255 أي أنه سوف يبقيه 255 ثانية أخرى قبل أن يسأل من جديد، والرقم ينقص كل ثانية حتى يصل إلى الصفر.
• لوحة DNS تسأل السيرفر الموثوق، والزوار يسألون Resolvers كثيرة (مزود الإنترنت، و1.1.1.1، و8.8.8.8، وشبكات الشركات)، وكل واحد منها حفظ الجواب في وقت مختلف، فلا يوجد «انتشار» لحظي، وإنما ذواكر مؤقتة تنتهي واحدة بعد الأخرى.
• الطريقة الصحيحة أن تخفض TTL إلى 60 أو 300 ثانية قبل التغيير بمدة لا تقل عن TTL القديم (إذا كان يوماً كاملاً فقبل يوم)، ثم تغير السجل، وتبقي السيرفر القديم يعمل أو يحول الطلبات إلى الجديد حتى تنتهي أطول مدة بقاء، ثم ترفع TTL من جديد.
• لا تستطيع أن تمسح ذاكرة Resolver لا تملكه، فإطفاء السيرفر القديم مبكراً هو الخطأ الذي حول تغييراً عادياً إلى حادثة.

للتفصيل: قسم TTL والانتشار في شرح DNS، وقسم الذاكرة المؤقتة في نفس الشرح.

الأرقام تقول إن الزمن يتضاعف مع طول المدخل، وإن المدخلات البطيئة كلها مرفوضة، وهذه علامة التراجع الكارثي. وأرسلنا المدخل aaaa…a! بأطوال مختلفة إلى التطبيق على المنفذ 21417، ثم طلباً بطول 30 حرفاً، وقسنا أثناءه:

$ curl -s -o /dev/null -w "%{http_code} %{time_total}s\n" "http://127.0.0.1:21417/signup?name=Ahmad%20Salem"
200 0.231114s
len=21 422 0.510917s
len=23 422 2.232191s
len=25 422 8.472407s
len=27 422 31.968550s
$ docker stats --no-stream --format 'table {{.Name}}\t{{.CPUPerc}}' lab-kata-ops-ts-regex
NAME                    CPU %
lab-kata-ops-ts-regex   104.98%

والسبب في التعبير ([a-zA-Z0-9]+\s?)*: المسافة اختيارية، فالنص aaaa يمكن تقسيمه إلى مجموعات بطرق كثيرة جداً (aaaa أو a|aaa أو aa|aa أو a|a|a|a...)، وعندما تفشل المطابقة عند ! في النهاية يجرب المحرك كل التقسيمات قبل أن يقول «لا»، وعددها يتضاعف مع كل حرف. والإصلاح أن تجعل لكل نص طريقة تقسيم واحدة، فالمسافة إلزامية بين الكلمات:

SAFE = re.compile(r'^[a-zA-Z0-9]+(?: [a-zA-Z0-9]+)*\Z')

len=11 valid=True regex_ms=0.007
len=27 valid=False regex_ms=0.005
len=10001 valid=False regex_ms=1.068
len=12 valid=False regex_ms=0.007

في المخرج أعلاه لاحظ التالي:

• طلب واحد بطول 30 حرفاً يأخذ دقائق ويحجز نواة معالج كاملة، فعشرة طلبات من مخترق تكفي لتعطيل السيرفر، وهذا هجوم معروف باسم ReDoS، وزيادة عدد الطلبات في المراقبة لم تظهر لأنه لا يحتاج عدداً كبيراً.
• المسار الصحيح للتحقيق هنا: المعالج مرتفع ← أي عملية (docker stats أو top) ← أي طلب (السجل مع الزمن والطول) ← أي سطر في الكود، وأداة تحليل مثل py-spy تعطيك السطر مباشرة لكنها تحتاج صلاحيات إضافية في ال Container.
• التعبير الجديد يرفض المسافتين المتتاليتين (len=12 valid=False)، وهذا تغيير في السلوك يجب أن تتأكد أنه مقصود، وأضف حداً لطول المدخل قبل التعبير، فلا يوجد اسم مستخدم بعشرة آلاف حرف.
• بعض المحركات مثل RE2 وRust تضمن زمناً خطياً ولا تتراجع، و.NET يدعم مهلة للتعبير، وكل ذلك في دليل التعبيرات النمطية.

للتفصيل: قسم ReDoS في دليل التعبيرات النمطية، وقسم المرتكزات Anchors في نفس الدليل، وحالة المعالج المرتفع في دليل استكشاف الأخطاء.

صنعنا الحادثة بجلسة فتحت معاملة Transaction وحدثت المنتج 1 ثم توقفت دون commit، كما يحدث عندما يفتح الكود معاملة ثم ينتظر خدمة خارجية أو يرمي استثناء لا يغلقها. والأمر التالي pg_stat_activity مع الدالة pg_blocking_pids بينما تحديث آخر ينتظر:

$ psql -c "select pid, state, wait_event_type, wait_event, pg_blocking_pids(pid) as blocked_by, now() - xact_start as xact_age, left(query, 50) as query from pg_stat_activity where backend_type = 'client backend' and pid <> pg_backend_pid() order by xact_start;"
 pid |        state        | wait_event_type |  wait_event   | blocked_by |    xact_age     |                       query
-----+---------------------+-----------------+---------------+------------+-----------------+----------------------------------------------------
 136 | idle in transaction | Client          | ClientRead    | {}         | 00:00:33.108682 | update stock set qty = qty - 1 where product_id =
 160 | active              | Lock            | transactionid | {136}      | 00:00:07.554467 | update stock set qty = qty - 1 where product_id =
(2 rows)

الجلسة 160 تنتظر قفلاً تملكه الجلسة 136، والجلسة 136 لا تفعل شيئاً منذ 33 ثانية وهي داخل معاملة. والإصلاح الفوري إنهاؤها، ثم إعداد يمنع التكرار:

$ psql -c "select pg_terminate_backend(136);"
 pg_terminate_backend
----------------------
 t
(1 row)

$ psql -c "select * from stock order by 1;"
 product_id | qty
------------+-----
          1 |  49
          2 |   9
(2 rows)

$ psql -c "alter system set idle_in_transaction_session_timeout = '60s';" -c "select pg_reload_conf();"
$ psql -c "show idle_in_transaction_session_timeout;"
 idle_in_transaction_session_timeout
-------------------------------------
 1min
(1 row)

في المخرج أعلاه لاحظ التالي:

• الكمية أصبحت 49 وليس 48: تحديث الجلسة 136 ألغي Rollback عند إنهائها، والتحديث المنتظر 160 أكمل فوراً، وهذا ما تريده، لكن تأكد دائماً ماذا كانت الجلسة التي تنهيها تفعل.
• المعالج خامل لأن الانتظار على قفل لا يستهلك شيئاً، ولهذا لا تظهر المشكلة في مراقبة الموارد، وتظهر فقط في الزمن وفي wait_event_type = Lock.
• الإعداد idle_in_transaction_session_timeout ينهي أي جلسة تبقى خاملة داخل معاملة أكثر من دقيقة، والإصلاح الحقيقي في الكود: لا تنتظر شيئاً خارجياً داخل معاملة، وأغلق المعاملة في finally أو بأداة اللغة التي تغلقها تلقائياً.

للتفصيل: تجربة القفل في دليل تتبع الطلب البطيء، والدالة pg_blocking_pids في توثيق PostgreSQL.

الأمر التالي أن تسأل DNS الشبكة عن عنوان التطبيق الآن، وتقارنه بما يستخدمه Nginx:

$ docker exec lab-kata-ops-ts-nginx getent hosts lab-kata-ops-ts-app
192.168.96.4      lab-kata-ops-ts-app  lab-kata-ops-ts-app
$ docker inspect lab-kata-ops-ts-worker --format '{{(index .NetworkSettings.Networks "lab-kata-ops-ts").IPAddress}}'
192.168.96.2

التطبيق الجديد على 192.168.96.4، وNginx ما زال يرسل إلى 192.168.96.2، وهذا العنوان أخذه Container آخر (Worker) بدأ أثناء النشر، فالرفض يأتي منه. والسبب أن Nginx يحول الاسم المكتوب في proxy_pass إلى عنوان مرة واحدة عند بدء التشغيل أو ال Reload، ولا يسأل بعد ذلك، ولهذا يصلحه ال Reload. وفي المختبر صنعنا الحادثة بحذف التطبيق وتشغيل Container آخر قبله حتى يأخذ العنوان القديم، ثم تشغيل التطبيق من جديد. والإصلاح أن تجعل Nginx يسأل DNS الخاص بDocker على 127.0.0.11 وأن تضع الاسم في متغير، لأن Nginx لا يستخدم ال resolver إلا عندما يكون العنوان في proxy_pass متغيراً:

server {
    listen 80;
    resolver 127.0.0.11 valid=10s ipv6=off;

    location / {
        set $app http://lab-kata-ops-ts-app:8000;
        proxy_pass $app;
    }
}

وبعد Reload واحد لتحميل هذا الإعداد، نشرنا نسخة جديدة بنفس الطريقة (Container آخر يأخذ العنوان القديم، والتطبيق على عنوان جديد)، دون أي Reload بعدها:

new app IP 192.168.96.5
200 200 200 200 200 200
ok from 3eb29d8bbdde v1.6

في المخرج أعلاه لاحظ التالي:

• العطل لا يحدث في كل نشر في الواقع، فإذا أخذ التطبيق الجديد نفس العنوان القديم يعمل كل شيء، ولذلك يبدو عشوائياً، وهذا أصعب نوع من الأعطال لأن الفريق يتعلم «حلاً» دون أن يعرف السبب.
• valid=10s يجعل Nginx يحفظ الجواب عشر ثوان فقط، ف DNS الخاص بDocker لا يعطي مدة بقاء طويلة، وبعض الإعدادات تضع أقل من ذلك.
• مع المتغير في proxy_pass يتغير سلوك المسار: يرسل Nginx المسار كما جاء ما لم تكتب URI، فانتبه إذا كان الإعداد القديم يعتمد على استبدال المسار كما في تمرين الشرطة في تمارين DevOps.
• Nginx من النسخة 1.27.3 يدعم أيضاً في النسخة المفتوحة المصدر الخيار resolve لكل server داخل upstream مع التعليمة zone، وهو الطريق الأفضل عندما يكون لديك أكثر من نسخة.

للتفصيل: التعليمة resolver في توثيق Nginx، وDNS الداخلي في توثيق شبكات Docker، وقسم استكشاف الأخطاء في دليل شبكات Docker.