abrt가 충돌하지 않은 프로세스의 로그 출력을 인수하는 이유는 무엇입니까?

간결한 버전:

1. syslog에 (상세하게) 기록하는 장기 실행 프로세스(웹 프록시)가 있습니다.
2. 무엇나쁜 일이 일어나면 갑자기 개입해어떻게든
3. 프로세스가 계속 실행됩니다...
4. ...그러나 syslog에 대한 모든 로그 메시지는 이제 "xfcproxy[1234]:" 대신 "abrt:"로 표시됩니다.
5. 이유를 아시나요?

긴 버전:

이는 로그 관점에서 볼 수 있는 "무언가 발생"의 예입니다. 프로세스는 계속 기록되지만 syslog의 프로세스 이름은 변경됩니다. 프록시의 모든 메시지가 "uuid=..."로 시작하는 방식에 유의하세요. 스니펫 상단의 "xfcproxy[4808]:" 및 스니펫 하단의 "abrt:" 아래에 기록된 메시지를 볼 수 있습니다.

Aug 27 07:02:55 proxy1 xfcproxy[4808]: uuid=63e63d9e connection=Open client_ip=192.168.3.21 client_port=40973
Aug 27 07:02:55 proxy1 xfcproxy[4808]: uuid=63e63d9e connection=Information method=CONNECT path=www.example.com port=443
Aug 27 07:02:55 proxy1 xfcproxy[4808]: uuid=63e63d9e rule=Destination message="Match made" rule=monitoring uri=www.example.com
Aug 27 07:02:55 proxy1 rsyslogd-2177: imuxsock begins to drop messages from pid 4808 due to rate-limiting
Aug 27 07:02:55 proxy1 abrtd: New client connected
Aug 27 07:02:55 proxy1 abrtd: Directory 'pyhook-2014-08-27-07:02:55-4808' creation detected
Aug 27 07:02:55 proxy1 abrt-server[27032]: Saved Python crash dump of pid 4808 to /var/spool/abrt/pyhook-2014-08-27-07:02:55-4808
Aug 27 07:02:55 proxy1 abrtd: Executable '/var/lib/xfcProxy/bin/xfcProxy.py' doesn't belong to any package and ProcessUnpackaged is set to 'no'
Aug 27 07:02:55 proxy1 abrtd: 'post-create' on '/var/spool/abrt/pyhook-2014-08-27-07:02:55-4808' exited with 1
Aug 27 07:02:55 proxy1 abrtd: Deleting problem directory '/var/spool/abrt/pyhook-2014-08-27-07:02:55-4808'
Aug 27 07:03:37 proxy1 rsyslogd-2177: imuxsock lost 1642 messages from pid 4808 due to rate-limiting
Aug 27 07:03:37 proxy1 abrt: uuid=06bc7247 connection=Open client_ip=192.168.3.21 client_port=40976
Aug 27 07:03:37 proxy1 abrt: uuid=06bc7247 connection=Information method=CONNECT path=www.example.com port=443
Aug 27 07:03:37 proxy1 abrt: uuid=06bc7247 rule=Destination message="Match made" rule=monitoring uri=www.example.com

"ps"를 사용하면 실행 중이던 PID 4808이 여전히 실행 중임을 확인할 수 있습니다.

[root@proxy1 log]# ps 4808
  PID TTY      STAT   TIME COMMAND
 4808 ?        S      1:34 python /var/lib/xfcProxy/bin/xfcProxy.py
[root@proxy1 log]#

"imuxsock이 메시지 삭제를 시작했습니다"는 다소 정상입니다. 이 데몬은 매우 수다스럽습니다(여기서는 연속 메시지의 작은 하위 집합만 표시함). 속도 제한 문제를 제외하고 일련의 메시지가 속도 제한을 완전히 트리거할 수 있습니다.

abrt에 대한 나의 지식은 제한적이지만 충돌 정보가 없는 것 같지만 프로세스 충돌은 로그 타이밍과 관련이 있다고 생각합니다.

[root@proxy1 abrt]# pwd
/var/spool/abrt
[root@proxy1 abrt]# ls -l
total 4
-rw-r--r--. 1 root root  0 Mar 18 15:45 abrt-db
-rw-------  1 root root 33 Aug 27 07:02 last-via-server
[root@proxy1 abrt]# echo `cat last-via-server `
/var/lib/xfcProxy/bin/xfcProxy.py
[root@proxy1 abrt]#

문제의 프로세스는 다중 스레드 Python 프로세스입니다. 스레드를 제대로 정리하지 않아 이 동작이 발생한다는 생각에 확실히 열려 있습니다. 이건 정말 이상한 행동이에요.

@Mikel에 대한 설명:

• 예, RHEL 6입니다.
• rsyslog를 통한 /var/log/messages. 아직 저널링을 시도하지 않았으며 이러한 변경을 시도하려면 비프로덕션 서버에서 재현해야 합니다.

아래의 포상금 기간이 업데이트되었습니다.

죄송하지만 다음과 같은 이유로 E Carter Young의 기존 답변에 현상금을 수여할 수 없습니다.

1. rsyslog 소스를 보면 알 수 있는 한 imuxsock 속도 제한은 프로세스에 대한 어떤 종류의 변경도 유발하지 않으며 어떤 방식으로든 abrtd를 포함하지 않습니다. 일시적으로 스트림을 중단한 다음 나중에 읽기를 다시 시작합니다.
2. 프로세스가 syslog에 과도하게 쓰는 것은 버퍼 오버플로 상황이 아닙니다. 리소스 활용, 예. 서비스 거부일 수도 있지만 버퍼라고 해서 너무 꽉 차 있다고 해서 버퍼 오버플로가 발생하는 것은 아닙니다.
3. 설명된 단계는 실제 상황과 일치하지 않습니다. 특히 6단계에서 rsyslog는 abrt 프로세스에서 얻어지지 않지만 원래 프로세스에서 abrt라는 이름을 사용하는 이유는 무엇입니까?
4. 나는 여기에도 경쟁 조건이 있다고 믿지 않습니다. (로그 버퍼를 빨리 채우는 것은 경쟁 조건이 아닙니다)

이 질문은 너무 복잡하고 데이터가 부족하다고 생각합니다. 결국 더 많은 데이터를 사용하여 질문할 수 있는 여러 가지 간단한 질문으로 귀결됩니다.

• 정의에 따라 abrtd가 충돌한 프로세스에서 실행되는 경우 종료되지 않는 프로세스에서 실행되는 이유는 무엇입니까? abrtd가 관련될 만큼 충분한 충돌을 나타내는 것은 무엇입니까? 저는 사라진 로그에 답이 있다고 생각하지만, 사라진 로그 자체가 답은 아니라고 생각합니다. rsyslog가 abrtd를 호출한다는 증거는 없습니다.
• rsyslog가 프로세스에서 abrtd를 트리거한 후 abrt를 프로세스 이름으로 사용하기 시작하는 이유는 무엇입니까(이전 질문에서 답변한 것처럼 입증 가능한 방식으로)?

아쉽게도 오늘은 더 많은 데이터 없이 이러한 질문을 제기하기가 꺼려집니다.

이 답변을 받아들일 수는 없지만 확실히 가치 있는 답변이라고 생각합니다.

• abrtd 블랙리스트 설명
• 내가 선택할 수 있는 옵션을 명확하고 간결하게 논의하세요.
  • 속도 제한 및 클러터 로그 추가 또는 제거
  • 프로세스 길이 변경
  • abrt를 사용하여 프로세스를 블랙리스트에 추가하여 프로세스가 개입하지 않도록 하세요.

따라서 현상금이 만료되면 현상금의 절반이 E Carter Young의 답변에 가장 많이 투표된 답변으로 전달됩니다.