تعطل Discourse "لحظي" - كيفية الحصول على مزيد من المعلومات من السجلات

أهلاً،

هذا الصباح حذرني بعض المستخدمين من أن تثبيت discourse الخاص بنا كان معطلاً على ما يبدو، ولكن بحلول الوقت الذي تحققت فيه كان يعمل مرة أخرى. كانت هناك عدة سلوكيات تشبه “عدم الاتصال بالإنترنت” يمكنني رؤيتها من مكدس المراقبة الخاص بي، ولكن عندما ذهبت للتحقق من السجلات عبر launcher logs app، بدا أنها تُخرج بدون طابع زمني (:confused:) والأحدث فقط على ما أعتقد، دون تمييز حقيقي من مصدر السجلات حيث توجد مكونات متعددة تشكل تثبيت discourse (nginx، redis، psql، إلخ).

هل هناك طريقة للحصول على سجلات أكثر دقة أو، بشكل أفضل، جعلها متاحة بطريقة ما حتى أتمكن من التقاطها باستخدام loki / promtail؟

جميع الرسوم البيانية هي “آخر 5 أيام” حيث أنني أضفت هذه المراقبة فقط منذ ذلك الحين. هذا ما يمكنني رؤيته في مراقبتي:

وقت تشغيل الحاوية:

من إضافات discourse-prometheus، الكثير من “الثقوب” التي أفترض أنها من وقت عدم استجابة discourse حيث تتطابق مع وقت إبلاغي من المستخدمين هذا الصباح:

تم تكبير آخر 6 ساعات لتوضيح أن هذه ليست نافذة “صغيرة” وأنها بالتأكيد غير مقبولة من قبل المستخدمين بالطبع:

السجلات المستخرجة باستخدام ./launcher logs app

root@vmi1229594:/var/discourse# ./launcher logs app
x86_64 arch detected.
run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/01-cleanup-web-pids
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
Started runsvdir, PID is 41
ok: run: redis: (pid 53) 0s
ok: run: postgres: (pid 55) 0s
supervisor pid: 51 unicorn pid: 87
Shutting Down
run-parts: executing /etc/runit/3.d/01-nginx
ok: down: nginx: 0s, normally up
run-parts: executing /etc/runit/3.d/02-unicorn
(51) exiting
ok: down: unicorn: 1s, normally up
run-parts: executing /etc/runit/3.d/10-redis
ok: down: redis: 0s, normally up
run-parts: executing /etc/runit/3.d/99-postgres
ok: down: postgres: 0s, normally up
ok: down: nginx: 10s, normally up
ok: down: postgres: 0s, normally up
ok: down: redis: 3s, normally up
ok: down: unicorn: 5s, normally up
ok: down: cron: 1s, normally up
ok: down: rsyslog: 1s, normally up
run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/01-cleanup-web-pids
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
Started runsvdir, PID is 35
ok: run: redis: (pid 49) 0s
ok: run: postgres: (pid 48) 0s
supervisor pid: 43 unicorn pid: 81
(43) Reopening logs
(43) Reopening logs
Shutting Down
run-parts: executing /etc/runit/3.d/01-nginx
ok: down: nginx: 0s, normally up
run-parts: executing /etc/runit/3.d/02-unicorn
(43) exiting
ok: down: unicorn: 0s, normally up
run-parts: executing /etc/runit/3.d/10-redis
ok: down: redis: 0s, normally up
run-parts: executing /etc/runit/3.d/99-postgres
timeout: run: postgres: (pid 48) 34983s, want down, got TERM
run-parts: /etc/runit/3.d/99-postgres exited with return code 1
ok: down: nginx: 10s, normally up
ok: down: redis: 8s, normally up
ok: down: unicorn: 10s, normally up
ok: down: cron: 0s, normally up
ok: down: rsyslog: 0s, normally up
kill: run: postgres: (pid 48) 34991s, want down, got TERM
run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/01-cleanup-web-pids
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
Started runsvdir, PID is 35
fail: redis: runsv not running
ok: run: redis: (pid 53) 1s
ok: run: postgres: (pid 48) 1s
supervisor pid: 79 unicorn pid: 83
(79) Reopening logs
Shutting Down
run-parts: executing /etc/runit/3.d/01-nginx
ok: down: nginx: 0s, normally up
run-parts: executing /etc/runit/3.d/02-unicorn
(79) exiting
ok: down: unicorn: 0s, normally up
run-parts: executing /etc/runit/3.d/10-redis
ok: down: redis: 0s, normally up
run-parts: executing /etc/runit/3.d/99-postgres
ok: down: postgres: 0s, normally up
ok: down: nginx: 5s, normally up
ok: down: postgres: 0s, normally up
ok: down: redis: 3s, normally up
ok: down: unicorn: 5s, normally up
ok: down: cron: 1s, normally up
ok: down: rsyslog: 1s, normally up
run-parts: executing /etc/runit/1.d/00-ensure-links
run-parts: executing /etc/runit/1.d/00-fix-var-logs
run-parts: executing /etc/runit/1.d/01-cleanup-web-pids
run-parts: executing /etc/runit/1.d/anacron
run-parts: executing /etc/runit/1.d/cleanup-pids
Cleaning stale PID files
run-parts: executing /etc/runit/1.d/copy-env
Started runsvdir, PID is 34
ok: run: redis: (pid 49) 0s
ok: run: postgres: (pid 44) 0s
supervisor pid: 41 unicorn pid: 80
(41) Reopening logs
(41) Reopening logs
(41) Reopening logs
(41) Reopening logs
(41) Reopening logs
إعجاب واحد (1)

للتوضيح، سأضيف أنني أعلم أن السجلات يمكن أن تكون في الحاوية /var/logs ولكن nginx و postgres و redis لا تظهر أي شيء غير طبيعي في تجربتي.

nginx لديها الكثير من السجلات حول طلبات الفيضان (وبالتالي الحد منها) لبيانات JSON الخاصة بالمستخدمين القادمين من المواضيع
postgresql ببساطة تعيد الاستعلام المنفذ (أعتقد؟ هذه استعلامات طويلة جدًا)
redis تظهر فقط حفظ البيانات بانتظام كما ينبغي

في messages أرى بعض الرسائل غير المريحة، مثل:

[....]
May  1 07:46:50 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  2 07:56:45 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  2 23:20:57 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="49" x-info="https://www.rsyslog.com"] start
May  3 07:35:27 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  4 07:38:08 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  5 07:40:32 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  6 08:01:40 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  7 07:38:45 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  8 07:37:31 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May  9 07:35:21 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 10 07:53:08 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 11 07:43:09 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 12 07:56:06 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 12 15:15:30 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="48" x-info="https://www.rsyslog.com"] start
May 12 15:59:28 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="41" x-info="https://www.rsyslog.com"] start
May 12 17:20:56 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="43" x-info="https://www.rsyslog.com"] start
May 12 18:55:45 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="44" x-info="https://www.rsyslog.com"] start
May 12 19:13:36 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="42" x-info="https://www.rsyslog.com"] start
May 12 21:04:24 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="44" x-info="https://www.rsyslog.com"] start
May 12 22:15:46 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="47" x-info="https://www.rsyslog.com"] start
May 13 07:43:36 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 13 20:07:44 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="49" x-info="https://www.rsyslog.com"] start
May 14 07:46:22 vmi1229594-app logrotate: ALERT exited abnormally with [1]
May 14 22:05:18 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="42" x-info="https://www.rsyslog.com"] start
May 14 22:16:04 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="44" x-info="https://www.rsyslog.com"] start
May 14 22:43:03 vmi1229594-app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="49" x-info="https://www.rsyslog.com"] start
May 14 23:00:09 discourse_app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="49" x-info="https://www.rsyslog.com"] start
May 15 00:22:59 discourse_app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="45" x-info="https://www.rsyslog.com"] start
May 15 00:56:17 discourse_app logrotate: ALERT exited abnormally with [1]
May 15 10:06:13 discourse_app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="43" x-info="https://www.rsyslog.com"] start
May 16 07:55:46 discourse_app logrotate: ALERT exited abnormally with [1]
May 16 08:40:17 discourse_app rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="45" x-info="https://www.rsyslog.com"] start
May 17 07:58:24 discourse_app logrotate: ALERT exited abnormally with [1]
May 18 07:55:33 discourse_app logrotate: ALERT exited abnormally with [1]
May 19 07:48:14 discourse_app logrotate: ALERT exited abnormally with [1]
May 20 08:03:44 discourse_app logrotate: ALERT exited abnormally with [1]
May 21 07:40:15 discourse_app logrotate: ALERT exited abnormally with [1]
May 22 07:44:59 discourse_app logrotate: ALERT exited abnormally with [1]

وفي syslog الكثير والكثير من هذا:

[....]
May 20 05:17:01 discourse_app CRON[1001623]: (root) CMD (	cd / && run-parts --report /etc/cron.hourly)
May 20 05:25:01 discourse_app CRON[1002727]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 05:35:01 discourse_app CRON[1004446]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 05:45:01 discourse_app CRON[1006215]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 05:55:01 discourse_app CRON[1007612]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:05:01 discourse_app CRON[1009398]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:15:01 discourse_app CRON[1011120]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:17:01 discourse_app CRON[1011400]: (root) CMD (	cd / && run-parts --report /etc/cron.hourly)
May 20 06:25:01 discourse_app CRON[1012535]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:25:01 discourse_app CRON[1012537]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
May 20 06:35:01 discourse_app CRON[1014375]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:45:01 discourse_app CRON[1016178]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 06:55:01 discourse_app CRON[1017757]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:05:02 discourse_app CRON[1019550]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:15:01 discourse_app CRON[1021373]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:17:01 discourse_app CRON[1021667]: (root) CMD (	cd / && run-parts --report /etc/cron.hourly)
May 20 07:25:01 discourse_app CRON[1022811]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:30:01 discourse_app CRON[1023931]: (root) CMD (/usr/sbin/anacron -s >/dev/null)
May 20 07:30:01 discourse_app anacron[1023933]: Anacron 2.3 started on 2023-05-20
May 20 07:30:01 discourse_app anacron[1023933]: Will run job `cron.daily' in 5 min.
May 20 07:30:01 discourse_app anacron[1023933]: Jobs will be executed sequentially
May 20 07:35:01 discourse_app anacron[1023933]: Job `cron.daily' started
May 20 07:35:01 discourse_app anacron[1024646]: Updated timestamp for job `cron.daily' to 2023-05-20
May 20 07:35:01 discourse_app CRON[1024649]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:45:01 discourse_app CRON[1026439]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 07:55:01 discourse_app CRON[1027921]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 08:03:44 discourse_app logrotate: ALERT exited abnormally with [1]
May 20 08:03:44 discourse_app anacron[1023933]: Job `cron.daily' terminated (exit status: 1) (mailing output)
May 20 08:03:44 discourse_app anacron[1023933]: Can't find sendmail at /usr/sbin/sendmail, not mailing output
May 20 08:03:44 discourse_app anacron[1023933]: Normal exit (1 job run)
May 20 08:05:01 discourse_app CRON[1029819]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 08:15:01 discourse_app CRON[1031611]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 20 08:17:01 discourse_app CRON[1031886]: (root) CMD (	cd / && run-parts --report /etc/cron.hourly)
[....]

السؤال الرئيسي: ماذا تعني هذه الرسائل في سياق Discourse وكيف يمكنني الحصول على مزيد من المعلومات؟
ملاحظة جانبية: هل هناك طريقة لاستخراج هذه السجلات حتى أتمكن من التقاطها وتوحيدها؟

launcher logs هو ببساطة غلاف لـ docker logs، والذي يمكنه عرض الطوابع الزمنية باستخدام -t. ما يلي يجب أن يمنحك سجلات ذات طوابع زمنية:

sudo docker logs -t --tail 1000 app

الأسطر التي اقتبستها في هذين الملفين ليست متعلقة بـ Discourse؛ إذا استنتجت ذلك بسبب وجود discourse_app في بعض هذه الأسطر، فضع في اعتبارك أن هذا اسم مضيف وليس تسمية تشير إلى أنها مرتبطة بإعداد Docker الخاص بـ Discourse بأي شكل من الأشكال.

بناءً عليها، يبدو أن logrotate يفشل، ولكنك لن ترى خطأ مفصلاً إلا إذا قمت بتثبيت إعداد بريد محلي. بافتراض مشتق من Debian، قم بتشغيل apt install default-mta، ثم انتظر حتى يحدث خطأ آخر، ثم تحقق من البريد المحلي باستخدام الأمر mail.

أود أيضًا التحقق من صحة الخادم مثل المساحة المتاحة على القرص، وضغط الذاكرة، وما إلى ذلك. ضغط الذاكرة الشديد (على سبيل المثال، الترحيل) هو سبب محتمل لعدم الاستجابة المتكررة.

6 إعجابات

شخصيًا، سألقي نظرة على الأجزاء ذات الصلة من مخرجات dmesg - أحد الاحتمالات هو أن أحداث جدار الحماية (UFW) تمنع حركة المرور.

في الواقع، قد يكون بعض تسجيل الاتصال مفيدًا، للتمييز بين حالة عدم إمكانية الوصول إلى الجهاز نفسه، وحالة عدم استجابة الخطاب.

إذا كان لديك أي نوع من ترتيبات شبكة توصيل المحتوى (CDN)، فتحقق من ذلك أيضًا.

إعجابَين (2)

شكرًا لك ليوناردو، لقد أضفت postfix (الافتراضي لأوبونتو). سنرى ما سيخرج من ذلك.

لدي مراقبة أخرى مطبقة وبصراحة لا أرى أي مشكلة في الذاكرة أو مساحة القرص.

يظل التبديل (Swap) حوالي 2 جيجابايت من أصل 8 جيجابايت المتاحة. يحتوي الجهاز الظاهري على 30 جيجابايت من ذاكرة الوصول العشوائي المتاحة. ما هو غريب حقًا بالنسبة لي هو مدى استهلاك discourse لها → Discourse Docker HW reserved/used (CPU, RAM, Disk) and how to manage it

لست خبيرًا في dmesg ولكن ما يمكنني رؤيته هو وفرة من رسائل [UFW BLOCK] من عناوين IP مختلفة، ولكن بالطبع نظرًا لكثرتها، من الصعب فهم ما إذا كان هناك نمط.

لإعطائك مثالاً:

[Tue May 23 09:32:21 2023] [UFW BLOCK] IN=eth0 OUT= MAC=MAC_ADDRESS_A SRC=IP_ADDRESS_A DST=SERVER_IP LEN=40 TOS=0x00 PREC=0x00 TTL=248 ID=54321 PROTO=TCP SPT=34909 DPT=40930 WINDOW=65535 RES=0x00 SYN URGP=0
[Tue May 23 09:32:22 2023] [UFW BLOCK] IN=eth0 OUT= MAC=MAC_ADDRESS_A SRC=IP_ADDRESS_A DST=SERVER_IP LEN=40 TOS=0x00 PREC=0x00 TTL=248 ID=54321 PROTO=TCP SPT=43093 DPT=40942 WINDOW=65535 RES=0x00 SYN URGP=0
[Tue May 23 09:32:29 2023] [UFW BLOCK] IN=eth0 OUT= MAC=MAC_ADDRESS_A SRC=IP_ADDRESS_B DST=SERVER_IP LEN=40 TOS=0x00 PREC=0x00 TTL=249 ID=57687 PROTO=TCP SPT=42801 DPT=3350 WINDOW=1024 RES=0x00 SYN URGP=0
[Tue May 23 09:32:35 2023] [UFW BLOCK] IN=eth0 OUT= MAC=MAC_ADDRESS_A SRC=IP_ADDRESS_C DST=SERVER_IP LEN=40 TOS=0x00 PREC=0x00 TTL=54 ID=61548 PROTO=TCP SPT=21721 DPT=23 WINDOW=43065 RES=0x00 SYN URGP=0
[Tue May 23 09:32:59 2023] [UFW BLOCK] IN=eth0 OUT= MAC=MAC_ADDRESS_A SRC=IP_ADDRESS_D DST=SERVER_IP LEN=44 TOS=0x00 PREC=0x00 TTL=114 ID=0 PROTO=TCP SPT=50293 DPT=1023 WINDOW=29200 RES=0x00 SYN URGP=0

المعرفات مجهولة ولكن إذا كانت متماثلة فلها نفس المرجع.

نحن نستخدم Cloudflare ولكن فقط كموفر SSL/نطاق وذاكرة تخزين مؤقت. للأسف، أنا لست مسؤولاً عن ذلك، لذا قبل التعمق أكثر في هذا الاتجاه، أود استنفاد الاحتمالات الأخرى.

لقد أضفت فحص وقت التشغيل عبر blackbox exporter الذي يشير إلى النطاق لمعرفة ما إذا كان هناك أي وقت تعطل تم اكتشافه.

نعم، الأمر مشابه بالنسبة لي. الوحيدون الذين نهتم بهم، أعتقد، هم المنافذ 80 و 443. ربما جرب
dmesg | egrep "DPT=80 |DPT=443 " | egrep PROTO=TCP
ومن المحتمل جدًا ألا يكون هناك شيء. ولكن إذا كان هناك، فقد يعني ذلك أن جدار الحماية يمنع الوصول إلى discourse.

نعم، لا شيء بالنسبة لي أيضًا.

على أي حال، بالنظر إلى المراقبة، يبدو أن الحاوية تعمل طوال الوقت والصفحة الرئيسية كذلك، ولكن التطبيق لا يستجيب فعليًا للطلبات وحقيقة عدم وجود noData على الإطلاق في تلك الرسوم البيانية تؤكد هذه النظرية بصراحة. ما يعنيه ذلك هو أن الصفحة الرئيسية قد يتم تحميلها (إنها الفئة بالنسبة لنا) حيث يتم تخزينها مؤقتًا بواسطة cloudflare، ولكن بعد ذلك يتجاوز التصفح ببساطة مهلة الطلبات.

آخر 24 ساعة

سأحاول إضافة فحص جديد لوقت التشغيل على صفحة /latest التي من المحتمل جدًا ألا يتم تخزينها مؤقتًا بسبب المحتوى الذي يتغير باستمرار تقريبًا.

لا ينبغي لـ CloudFlare تخزين أي من صفحاتك مؤقتًا. Discourse هو تطبيق وليس موقع ويب.

إعجاب واحد (1)

هل هذه الانقطاعات تستمر لمدة ساعة أو أكثر، وتتركز حول منتصف الليل - هل يتوافق ذلك مع ملاحظاتك؟