일이 단순할수록 실수를 더 자주 하게 된다

이 사소한 작업은 어느 금요일 오후에 발생했으며 2~3분 정도 소요되었습니다. 일반적으로 언제나 그렇듯이.

동료가 나에게 자신의 서버에 있는 스크립트를 수정해 달라고 요청했습니다. 나는 그것을 해내고 그에게 건네주다가 실수로 떨어뜨렸다: "시간은 5분 빠르다." 서버가 동기화 자체를 처리하도록 합니다. XNUMX분, XNUMX시간이 지났지만 그는 여전히 숨을 헐떡이며 조용히 욕설을 퍼부었다.

"멍청한! — 서버 콘솔로 전환하면서 — 알았어, 몇 분 더 쉬겠습니다."

우리는 본다 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

시간은 XNUMX초 단위로 설정되고 즉시 다시 "돌진"하기 시작합니다.

동시에 로그에는 이러한 수동 변경 시 시간이 각각 올바른/잘못된 방향으로 변경되었다는 시스템 보고서만 표시됩니다. 재동기화 중 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

재동기화 중 사라지고 그렇지 않으면 로그가 깨끗해집니다.

결론 확인 TCP 덤프 모든 인터페이스의 포트 123에서. 요청은 없지만 아직 시간이 흐르고 있습니다.

오류 XNUMX. 서두르다

이번주 퇴근까지 한시간 남았는데, 사소한 문제로 주말을 떠나기 싫다. ).
그리고 여기서도 이유를 찾는 대신 결과에 대한 설명을 생각해 내려고 노력하기 시작했습니다. 내가 "발명하다"고 말하는 이유는 결과에 대한 설명이 아무리 논리적이더라도 문제 해결에 있어서는 결함이 있는 접근 방식이기 때문입니다.

이 서버는 스트리밍 서버이며 DVB-S2 스트림을 IP로 변환합니다. DVB-S 스트림에는 타임스탬프가 포함되어 있으므로 수신기, 멀티플렉서, 스크램블러 및 TV는 종종 이를 사용하여 시스템 클럭을 동기화합니다. DVB-S 보드 드라이버는 커널에 내장되어 있으므로 DVB-S2 스트림을 제거하는 가장 빠른 방법은 "플레이트"에서 나오는 케이블을 분리하는 것입니다. 다행스럽게도 서버는 벽 뒤에 있으므로 그렇게 하십시오.

물론, 로그에 있어야 할 내용이 포함되어 있었다면 이런 일이 발생하지 않았을 것입니다. 그러나 이에 대한 자세한 내용은 기사 끝부분에서 다시 설명합니다.

글쎄, 우리는 이미 모든 위성 신호를 제거했으므로 지상파 신호도 제거할 것입니다. 동시에 모든 네트워크 케이블을 뽑습니다. 서버는 외부 세계와 단절되어 완전히 자율적으로 작동하지만 시스템 시계는 여전히 서두르고 있습니다.

일주일 근무는 끝났고 날짜/시간 문제 자체는 크게 중요하지 않으니 그냥 집에 가도 되지만 여기서 또 새로운 실수를 범하게 됩니다.

오류 XNUMX. 고문

절대! 답변이 Google의 첫 번째 페이지를 연구하고 맨 페이지 하나를 읽는 것 이상이 필요한 경우 포럼 및 일반 전문(la stackoverflow) 사이트에 질문하지 마십시오.

그들은 당신을 다시 구글로 보내고, 같은 사람을 읽고, 포럼/사이트의 규칙을 대중적으로 설명할 것이지만 당신에게 대답을 주지는 않을 것입니다.

다음은 몇 가지 객관적인 요소입니다.

• 당신 외에는 누구도 문제를 알 수 없습니다.
• 누구도 당신과 같은 조건에서 테스트를 할 수 없습니다

그리고 주관적:

• 이미 '올바른' 방향을 제시하고 이에 초점을 맞춰 문제의 본질을 제시하고 있기 때문에 문제 해결을 위한 모든 의견을 제시하지 못할 수도 있습니다.
• 감독(모더레이터, 구직자, 관리자)은 항상 옳습니다. 감독이 틀리면... 글쎄요...

댓글에 답할 때 검열된 어휘의 한계 내에 머물렀다면 당신은 강한 신경을 가지고 있는 것입니다.

결정

작업을 단순하고 복잡하게 나눌 필요가 없습니다.

우리는 경험, 통계, 조언자에 대한 의존을 중단하고 최종 결과를 "설명"하는 것이 아니라 지속적으로 이유를 찾기 시작합니다.

누군가가 시간을 설정해 놓았기 때문에 해당 시스템 콜이 발생해야 한다.

소프트웨어 문서에서 가장 좋은 문서가 소스인 것처럼 시스템 관리에서 가장 좋은 조력자는 감사입니다. 감사.

의심의 순간마나를 살펴봤지만 Linux에서만 시간을 설정할 수 있는지 완전히 확신할 수 없었습니다. clock_settime и 오늘의 설정 시간, 그래서 첫 번째 테스트에서는 "적절한" 호출을 모두 선택했습니다.

# 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

내가 관심 있는 로그 위치에 다른 로그가 없는지 확인한 후 시스템 호출 이 두 가지 외에는 이것들만 더 사용했습니다.

시스템 호출 감사 실행 clock_settime и 오늘의 설정 시간 날짜를 변경해 보세요.

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

우리의 '기생충'이 시간을 정확하게 맞출 수 있도록 XNUMX초의 지연이 추가되었습니다.

보고서를 살펴보겠습니다:

# 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 - 우리 기생충이 발견됐어요. "악의적인" 행위에도 불구하고 조건부 접근 시스템을 거부하는 것은 불가능하지만 그래도 알고 싶습니다. 오캠, 무슨 일이야?

답은 다음에서 빠르게 찾을 수 있습니다. 출처:

#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");
}

여기 왤케 귀엽게 생겼어 주석 처리됨 선 경고...

출처 : habr.com