ככל שהמשימה פשוטה יותר, כך אני עושה טעויות לעתים קרובות יותר

המשימה הטריוויאלית הזו התעוררה ביום שישי אחר הצהריים והייתה אמורה לקחת 2-3 דקות של זמן. באופן כללי, כמו תמיד.

עמית ביקש ממני לתקן את הסקריפט בשרת שלו. עשיתי את זה, מסרתי לו והפלתי בלי משים: "הזמן מהיר ב-5 דקות." תן לשרת לטפל בסנכרון עצמו. חלפה חצי שעה, שעה, והוא עדיין התנפח וקילל בשקט.

"מְטוּפָּשׁ! - חשבתי, עברתי לקונסולת השרת - בסדר, אני אקח הפסקה לעוד כמה דקות."

אנחנו מסתכלים ntp, rdate, sdwdate לא מותקן סינכרון זמן מושבת ולא פועל.

# timedatectl
      Local time: Sun 2019-08-25 20:44:39 +03
  Universal time: Sun 2019-08-25 17:44:39 UTC
        RTC time: Sun 2019-08-25 17:39:52
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: no
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

כאן אציין מיד שזמן החומרה נכון: יהיה קל יותר לנווט הלאה.

כאן התחילה סדרת הטעויות.

הטעות הראשונה. ביטחון עצמי

לחץ על...

# systemctl enable systemd-timesyncd.service && systemctl start systemd-timesyncd.service && ntpdate 0.ru.pool.ntp.org && timedatectl set-ntp on && timedatectl
25 Aug 21:00:10 ntpdate[28114]: adjust time server 195.210.189.106 offset -249.015251 sec
      Local time: Sun 2019-08-25 21:00:10 +03
  Universal time: Sun 2019-08-25 18:00:10 UTC
        RTC time: Sun 2019-08-25 18:00:10
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: no
      DST active: n/a

הכל בסדר, השעה מסונכרנת, זמן המערכת תואם לזמן החומרה. "קח את זה," אמרתי וחזרתי לעסק שלי.

"לקחת את מה? - הקולגה התמרמר. "זו אותה שעה!"

ככל שאתה פותר בעיות טיפוסיות, כך החשיבה שלך הופכת למצומצמת ואתה כבר לא חושב שהמצב המאה או האלף יהיה שונה, אבל לא הפעם.

# timedatectl
      Local time: Sun 2019-08-25 21:09:15 +03
  Universal time: Sun 2019-08-25 18:09:15 UTC
        RTC time: Sun 2019-08-25 18:05:04
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

זמן המערכת שוב שגוי.

בוא ננסה שוב:

# ntpdate 0.ru.pool.ntp.org && timedatectl && sleep 1 && timedatectl
25 Aug 21:07:37 ntpdate[30350]: step time server 89.175.20.7 offset -249.220828 sec
      Local time: Sun 2019-08-25 21:07:37 +03
  Universal time: Sun 2019-08-25 18:07:37 UTC
        RTC time: Sun 2019-08-25 18:07:37
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: no
      DST active: n/a
      Local time: Sun 2019-08-25 21:11:46 +03
  Universal time: Sun 2019-08-25 18:11:46 UTC
        RTC time: Sun 2019-08-25 18:07:37
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

בואו נעשה את זה אחרת:

# date -s "2019-08-25 21:10:30" && date && sleep 1 && timedatectl
Sun Aug 25 21:10:30 +03 2019
Sun Aug 25 21:10:30 +03 2019
      Local time: Sun 2019-08-25 21:14:36 +03
  Universal time: Sun 2019-08-25 18:14:36 UTC
        RTC time: Sun 2019-08-25 18:10:30
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

אבל ככה:

# hwclock --hctosys && timedatectl && sleep 1 && timedatectl
      Local time: Sun 2019-08-25 21:11:31 +03
  Universal time: Sun 2019-08-25 18:11:31 UTC
        RTC time: Sun 2019-08-25 18:11:31
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: yes
 RTC in local TZ: no
      DST active: n/a
      Local time: Sun 2019-08-25 21:15:36 +03
  Universal time: Sun 2019-08-25 18:15:36 UTC
        RTC time: Sun 2019-08-25 18:11:32
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: yes
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

הזמן נקבע לשבריר שנייה, ומיד מתחיל "למהר" שוב.

יחד עם זאת, ביומנים, בזמן שינוי ידני שכזה, אנו רואים רק דיווחי מערכת שהשעה השתנתה, בהתאמה, בכיוון הנכון/לא נכון ומדי פעם מסנכרן מחדש מ-systemd-timesyncd.

Aug 25 21:18:51 wisi systemd[1]: Time has been changed
Aug 25 21:18:51 wisi systemd-timesyncd[29258]: System time changed. Resyncing.
Aug 25 21:18:51 wisi systemd[1187]: Time has been changed
Aug 25 21:18:51 wisi systemd[1]: Time has been changed
Aug 25 21:18:51 wisi systemd[1187]: Time has been changed

כאן

# ps afx | grep "[1]187"
 1187 ?        Ss     0:02 /lib/systemd/systemd --user

בשלב זה כבר היה צורך לחפש את הסיבה, אבל במשך 18 שנות ניהול, המוח צבר נתונים סטטיסטיים על שגיאות "זמן" ומתוך הרגל, שוב מאשים את הסנכרון.
בוא נכבה את זה לגמרי.

# timedatectl set-ntp off && systemctl stop systemd-timesyncd.service
# hwclock --hctosys && timedatectl && sleep 1 && timedatectl
      Local time: Sun 2019-08-25 21:25:40 +03
  Universal time: Sun 2019-08-25 18:25:40 UTC
        RTC time: Sun 2019-08-25 18:25:40
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: no
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a
      Local time: Sun 2019-08-25 21:29:31 +03
  Universal time: Sun 2019-08-25 18:29:31 UTC
        RTC time: Sun 2019-08-25 18:25:41
       Time zone: Europe/Minsk (+03, +0300)
     NTP enabled: no
NTP synchronized: no
 RTC in local TZ: no
      DST active: n/a

וביומנים

Aug 25 21:25:40 wisi systemd[1]: Time has been changed
Aug 25 21:25:40 wisi systemd[1187]: Time has been changed
Aug 25 21:29:30 wisi systemd[1]: Time has been changed
Aug 25 21:29:30 wisi systemd[1187]: Time has been changed

מסנכרן מחדש נעלמו, וחוץ מזה הבולי עץ בתוליים.

בודקים את המסקנות tcpdump ביציאה 123 בכל הממשקים. אין בקשות, אבל הזמן עדיין בורח.

שגיאה שניה. לְמַהֵר

נותרה שעה לסיום שבוע העבודה, ואני לא רוצה לצאת לסוף שבוע עם בעיה טריוויאלית לא פתורה (אל תשימו לב לשעה בקוד, המאמר נכתב בימים הבאים ).
והנה שוב, במקום לחפש את הסיבה, התחלתי לנסות להמציא הסבר לתוצאה. אני אומר "להמציא" כי לא משנה כמה הגיוני ההסבר לתוצאה עשוי להיות, זו גישה פגומה לפתרון הבעיה.

שרת זה הוא שרת סטרימינג וממיר את זרם DVB-S2 ל-IP. זרם ה-DVB-S מכיל חותמות זמן, כך שמקלטים, מרבבים, סקרמבלים וטלוויזיות משתמשים בהם לעתים קרובות כדי לסנכרן את שעון המערכת. מנהלי התקנים של לוח DVB-S מובנים בתוך הליבה, כך שהדרך המהירה ביותר להבטיח שזרם ה-DVB-S2 יוסר היא לנתק את הכבלים המגיעים מה"צלחות". למרבה המזל, השרת נמצא מאחורי הקיר, אז שיהיה.

כמובן שאם היומנים היו מכילים את מה שצריך להיות שם, זה לא היה קורה, אבל עוד על כך, שוב, בסוף המאמר.

ובכן, מכיוון שכבר הסרנו את כל אותות הלוויין, נסיר גם את האותות היבשתיים - במקביל נשלוף את כל כבלי הרשת. השרת מנותק מהעולם החיצון ועובד באופן אוטונומי לחלוטין, אך שעון המערכת עדיין ממהר.

שבוע העבודה הסתיים, ועניין התאריך/שעה עצמו לא קריטי, אז אפשר פשוט ללכת הביתה, אבל כאן אני עושה טעות חדשה.

שגיאה שלוש. יועצים

לעולם לא! לעולם אל תשאל שאלות בפורומים ובאתרים מיוחדים (a la stackoverflow) אם התשובה עליה דורשת יותר מלימוד העמוד הראשון של גוגל וקריאת דף אדם אחד.

הם ישלחו אותך בחזרה לגוגל, יקראו את אותו האיש ויסבירו באופן עממי את חוקי הפורום/אתר, אבל לא יתנו לך תשובה.

להלן מספר גורמים אובייקטיביים:

• אף אחד מלבדך לא יכול להכיר את הבעיה גם כן;
• אף אחד לא יכול לבצע בדיקות באותם תנאים כמו שלך

וסובייקטיבי:

• ייתכן שלא תתן את כל האינפורמציה לפתרון הבעיה, כי כבר הגעת לכיוון ה"נכון" ומציגה את מהות הנושא תוך התמקדות בו;
• מנהל העבודה (מנחה, ותיק, מנהל) תמיד צודק, אם מנהל העבודה טועה... ובכן, אתה יודע...

אם, כשהגבת לתגובות, נשארת בגבולות אוצר המילים המצונזר, אז יש לך עצבים חזקים.

החלטה

אין צורך לחלק משימות לפשוטות ומורכבות.

אנו מפסיקים להסתמך על הניסיון, הסטטיסטיקה, היועצים שלנו ומתחילים לא "להסביר" את התוצאה הסופית, אלא לחפש באופן עקבי את הסיבה.

מכיוון שמישהו קובע את השעה, קריאת המערכת המתאימה חייבת להתרחש.

כמו בתיעוד תוכנה המסמכים הטובים ביותר הם המקורות, כך בניהול המערכת העוזר הטוב ביותר הוא הביקורת, במקרה שלנו מבוקר.

רגע של ספקעברתי על המאנה, אבל לא הייתי בטוח לגמרי שאפשר להגדיר את השעה בלינוקס בלבד שעון_הגדרת זמן и קביעת שעת היום, אז למבחן הראשון בחרתי את כל הקריאות ה"מתאימות":

# man syscalls | col | grep -F '(2)' | grep -vE '(:|;)' | grep -E '(time|date|clock)' | sed "s/(2).*//" | xargs -I SYSCALL echo "-S SYSCALL " | xargs echo
-S adjtimex -S clock_adjtime -S clock_getres -S clock_gettime -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S s390_runtime_instr -S setitimer -S settimeofday -S stime -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_create -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes

והשלכה s390_runtime_instr, stime, timerfd_create, איזה auditctl לא זיהה את זה, פתח בהתחלה ביקורת בצורה:

auditctl -a exit,always -S adjtimex -S clock_adjtime -S clock_getres -S clock_nanosleep -S clock_settime -S futimesat -S getitimer -S gettimeofday -S mq_timedreceive -S mq_timedsend -S rt_sigtimedwait -S semtimedop -S setitimer -S settimeofday -S time -S timer_create -S timer_delete -S timer_getoverrun -S timer_gettime -S timer_settime -S timerfd_gettime -S timerfd_settime -S times -S utime -S utimensat -S utimes

לאחר שווידאתי שאין יומנים אחרים במיקומי היומן שאני מעוניין בהם שיחות מערכות מלבד שני אלה, השתמשתי רק בהם עוד יותר.

הפעלת ביקורת קריאת מערכת שעון_הגדרת זמן и קביעת שעת היום ותנסה לשנות את התאריך:

# auditctl -a exit,always -S clock_settime -S settimeofday && date -s "2019-08-22 12:10:00" && sleep 5 && auditctl -D

נוסף עיכוב של חמש שניות כדי ש"טפיל" שלנו מובטח לתקן את השעה.

בוא נראה את הדו"ח:

# aureport -s -i

Syscall Report
=======================================
# date time syscall pid comm auid event
=======================================
Warning - freq is non-zero and incremental flushing not selected.
1. 08/22/2019 12:10:00 settimeofday 3088 chkcache_proces root 479630
2. 08/26/2019 09:37:06 clock_settime 1538 date root 479629

כאן אנו רואים את שלנו נתונים ולא ידוע לנו chkcache_processes. זה הסתיים בדוח שלמעלה מכיוון ש-aureport מיינה את הפלט לפי תאריך בעת המרה מבינארי, והאירוע התרחש בזמן שקבענו תאריך -s "2019-08-22 12:10:00".
מי ילד אותו?

# ausearch -sc settimeofday --comm "chkcache_proces"
----
time->Thu Aug 22 12:10:00 2019
type=PROCTITLE msg=audit(1566465000.000:479630): proctitle="/usr/local/bin/oscam"
type=SYSCALL msg=audit(1566465000.000:479630): arch=c000003e syscall=164 success=yes exit=0 a0=7fde0dfc6e60 a1=0 a2=136cf a3=713ba56 items=0 ppid=3081 pid=3088 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=pts20 ses=68149 comm="chkcache_proces" exe="/usr/local/bin/oscam" key=(null)

/usr/local/bin/oscam - נמצא הטפיל שלנו. למרות ההתנהגות ה"זדונית" שלה, אי אפשר לסרב למערכת הגישה המותנית, אבל אני עדיין רוצה לדעת אוסקאם, WTF?

התשובה נמצאת במהירות ב קודי מקור:

#if defined(CLOCKFIX)
if (tv.tv_sec > lasttime.tv_sec || (tv.tv_sec == lasttime.tv_sec && tv.tv_usec >= lasttime.tv_usec)) // check for time issues!
{
  lasttime = tv; // register this valid time
}
  else
{
  tv = lasttime;
  settimeofday(&tv, NULL); // set time back to last known valid time
  //fprintf(stderr, "*** WARNING: BAD TIME AFFECTING WHOLE OSCAM ECM HANDLING, SYSTEMTIME SET TO LAST KNOWN VALID TIME **** n");
}

כמה חמוד זה נראה כאן הגיב קַו אַזהָרָה...

מקור: www.habr.com