PHP 로그 파일 최대한 활용하기: 실용 가이드

게시 됨: 2022-03-11

로그는 프리랜서 PHP 개발자가 마음대로 사용할 수 있는 가장 과소평가되고 활용도가 낮은 도구 중 하나라고 할 수 있습니다. 그들이 제공할 수 있는 풍부한 정보에도 불구하고, 개발자가 문제를 해결하려고 할 때 로그가 마지막으로 보는 곳이 드문 일이 아닙니다.

사실, PHP 로그 파일은 많은 경우에 문제가 발생했을 때 단서를 찾는 첫 번째 장소여야 합니다. 종종 여기에 포함된 정보는 지독한 버그를 추적하기 위해 머리카락을 뽑는 데 드는 시간을 크게 줄일 수 있습니다.

그러나 아마도 더 중요한 것은 약간의 창의성과 사전 고려를 통해 로그 파일을 활용하여 사용 정보 및 분석의 귀중한 소스로 사용할 수 있다는 것입니다. 로그 파일을 창의적으로 사용하면 다음과 같은 질문에 답하는 데 도움이 될 수 있습니다. 내 사이트를 방문하는 데 가장 일반적으로 사용되는 브라우저는 무엇입니까? 내 서버의 평균 응답 시간은 얼마입니까? 사이트 루트에 대한 요청 비율은 얼마입니까? 최신 업데이트를 배포한 후 사용량이 어떻게 변경되었습니까? 그리고 훨씬 더.

PHP 로그 파일

이 문서에서는 로그 파일이 제공하는 이점을 최대화하기 위해 로그 파일을 구성하는 방법과 로그 파일에 포함된 정보를 처리하는 방법에 대한 여러 팁을 제공합니다.

이 기사는 기술적으로 PHP 개발자를 위한 로깅에 중점을 두고 있지만 여기에 제공된 정보의 대부분은 기술에 구애받지 않으며 다른 언어 및 기술 스택과도 관련이 있습니다.

참고: 이 기사는 Unix 셸에 대한 기본적인 지식이 있다고 가정합니다. 이 지식이 부족한 사람들을 위해 Unix 시스템에서 로그 파일에 액세스하고 읽는 데 필요한 몇 가지 명령을 소개하는 부록이 제공됩니다.

PHP 로그 파일 예제 프로젝트

이 기사의 토론 목적을 위한 예제 프로젝트로 Symfony Standard를 작업 프로젝트로 사용하고 rsyslogd , nginx 및 PHP-FPM 을 사용하여 Debian 7 Wheezy에 설정할 것입니다.

 composer create-project symfony/framework-standard-edition my "2.6.*"

이것은 우리에게 멋진 UI로 작동하는 테스트 프로젝트를 신속하게 제공합니다.

로그 파일 구성을 위한 팁

다음은 가치를 극대화하는 데 도움이 되도록 로그 파일을 구성하는 방법에 대한 몇 가지 지침입니다.

오류 로그 구성

오류 로그는 가장 기본적인 로깅 형식을 나타냅니다. 즉, 문제가 발생할 때 추가 정보 및 세부 정보를 캡처합니다. 따라서 이상적인 세계에서는 오류가 없고 오류 로그가 비어 있기를 원할 것입니다. 그러나 문제가 발생하면(항상 발생하는 것처럼) 오류 로그는 디버깅 추적에서 수행하는 첫 번째 중지 중 하나여야 합니다.

오류 로그는 일반적으로 구성하기가 매우 쉽습니다.

우선 모든 오류 및 충돌 메시지는 사용자에게 표시되는 것과 정확히 동일한 형식으로 오류 로그에 기록될 수 있습니다. 몇 가지 간단한 구성을 사용하면 최종 사용자는 사이트에서 이러한 추악한 오류 추적을 볼 필요가 없으며 devops는 여전히 시스템을 모니터링하고 이러한 오류 메시지를 모든 세부 사항에서 검토할 수 있습니다. PHP에서 이러한 종류의 로깅을 설정하는 방법은 다음과 같습니다.

 log_errors = On error_reporting = E_ALL error_log = /path/to/my/error/log

사용자에게 표시되는 심각한 수준의 오류 세부 정보를 방지하기 위해 라이브 사이트의 로그 파일에 포함해야 하는 또 다른 두 줄은 다음과 같습니다.

 display_errors = Off display_startup_errors = Off

시스템 로그( syslog ) 구성

오픈 소스 세계에는 다음을 포함하여 일반적으로 호환되는 syslog 데몬 구현이 많이 있습니다.

  • syslogd 및 sysklogd – BSD 제품군 시스템, CentOS, Mac OS X 등에서 가장 자주 볼 수 있습니다.
  • syslog-ng – 최신 Gentoo 및 SuSE 빌드의 기본값
  • rsyslogd – Debian 및 Fedora 운영 체제 제품군에서 널리 사용

(참고: 이 기사에서는 예제에 rsyslogd 를 사용할 것입니다.)

기본 syslog 구성은 일반적으로 시스템 전체의 로그 파일(일반적으로 /var/log/syslog ; 배포판에 따라 /var/log/messages 또는 /var/log/system.log 일 수도 있음)에서 로그 메시지를 캡처하는 데 적합합니다. 사용 중입니다).

시스템 로그는 여러 로그 기능을 제공하며 그 중 8개( LOG_LOCAL0 ~ LOG_LOCAL7 )는 사용자 배포 프로젝트용으로 예약되어 있습니다. 예를 들어 다음은 로깅 수준(예: 오류, 경고, 정보, 디버그)에 따라 4개의 개별 로그 파일에 쓰도록 LOG_LOCAL0 을 설정하는 방법입니다.

 # /etc/rsyslog.d/my.conf local0.err /var/log/my/err.log local0.warning /var/log/my/warning.log local0.info -/var/log/my/info.log local0.debug -/var/log/my/debug.log

이제 LOG_LOCAL0 기능에 로그 메시지를 작성할 때마다 오류 메시지는 /var/log/my/err.log 로 이동하고 경고 메시지는 /var/log/my/warning.log 로 이동하는 식으로 계속됩니다. 그러나 syslog 데몬은 "이 수준 이상"의 규칙에 따라 각 파일에 대한 메시지를 필터링합니다. 따라서 위의 예에서 모든 오류 메시지는 구성된 4개의 모든 파일에 표시되고 경고 메시지는 오류 로그를 제외한 모든 파일에 표시되며 정보 메시지는 정보 및 디버그 로그에 표시되고 디버그 메시지는 debug.log 로만 이동합니다. .

한 가지 추가 중요 사항; 위의 구성 파일 예제에서 정보 및 디버그 수준 파일 앞의 - 기호는 해당 파일에 대한 쓰기가 비동기식으로 수행되어야 함을 나타냅니다(이러한 작업은 차단되지 않음). 이것은 일반적으로 정보 및 디버그 로그에 대해 문제가 없지만(대부분의 경우 권장됨) 오류 로그(및 대부분의 경우 경고 로그)에 대한 쓰기를 동기식으로 하는 것이 가장 좋습니다.

덜 중요한 수준의 로깅을 종료하려면(예: 프로덕션 서버에서) 관련 메시지를 /dev/null (즉, 아무데도 없음)로 리디렉션하면 됩니다.

 local0.debug /dev/null # -/var/log/my/debug.log

특히 이 기사의 뒷부분에서 논의할 일부 PHP 로그 파일 구문 분석을 지원하는 데 유용한 특정 사용자 정의는 탭을 로그 메시지의 구분 문자로 사용하는 것입니다. 이것은 /etc/rsyslog.d 에 다음 파일을 추가하여 쉽게 수행할 수 있습니다.

 # /etc/rsyslog.d/fixtab.conf $EscapeControlCharactersOnReceive off

마지막으로, 구성 변경 사항을 적용한 후 syslog 데몬을 다시 시작하는 것을 잊지 마십시오.

 service rsyslog restart

서버 로그 구성

쓸 수 있는 애플리케이션 로그 및 오류 로그와 달리 서버 로그는 각 요청에 대해 해당 서버 데몬(예: 웹 서버, 데이터베이스 서버 등)에 의해 독점적으로 작성됩니다. 이러한 로그에 대한 유일한 "제어"는 서버에서 로깅 기능을 구성하도록 허용하는 정도입니다. 이러한 파일을 자세히 살펴봐야 할 수 있지만 서버에서 "내부"가 어떻게 진행되고 있는지 명확하게 파악할 수 있는 유일한 방법인 경우가 많습니다.

MySQL 스토리지 백엔드가 있는 nginx 환경에 Symfony Standard 예제 애플리케이션을 배포해 보겠습니다. 다음은 사용할 nginx 호스트 구성입니다.

 server { server_name my.log-sandbox; root /var/www/my/web; location / { # try to serve file directly, fallback to app.php try_files $uri /app.php$is_args$args; } # DEV # This rule should only be placed on your development environment # In production, don't include this and don't deploy app_dev.php or config.php location ~ ^/(app_dev|config)\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; } # PROD location ~ ^/app\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; # Prevents URIs that include the front controller. This will 404: # http://domain.tld/app.php/some-path # Remove the internal directive to allow URIs like this internal; } error_log /var/log/nginx/my_error.log; access_log /var/log/nginx/my_access.log; }

위의 마지막 두 지시문과 관련하여: access_log 는 일반 요청 로그를 나타내고 error_log 는 오류를 나타냅니다. 응용 프로그램 오류 로그와 마찬가지로 문제에 대한 경고를 추가 모니터링하여 신속하게 대응할 수 있도록 설정할 가치가 있습니다.

참고: 이것은 예시 목적으로만 제공되는 의도적으로 지나치게 단순화된 nginx 구성 파일입니다. 보안과 성능에는 거의 관심을 기울이지 않으며 "실제" 환경에서 있는 그대로 사용해서는 안 됩니다.

이것은 브라우저에 http://my.log-sandbox/app_dev.php/ 를 입력하고 Enter 키를 누른 후 /var/log/nginx/my_access.log 에 있는 것입니다.

 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /app_dev.php/ HTTP/1.1" 200 6715 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/body.css HTTP/1.1" 200 6657 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/structure.css HTTP/1.1" 200 1191 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/css/demo.css HTTP/1.1" 200 2204 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-quick-tour.gif HTTP/1.1" 200 4770 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-demo.gif HTTP/1.1" 200 4053 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-configure.gif HTTP/1.1" 200 3530 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /favicon.ico HTTP/1.1" 200 6518 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:30 +0300] "GET /app_dev.php/_wdt/e50d73 HTTP/1.1" 200 13265 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36"

이것은 한 페이지를 제공하기 위해 브라우저가 실제로 9개의 HTTP 호출을 수행한다는 것을 보여줍니다. 그러나 그 중 7개는 단순하고 가벼운 정적 콘텐츠에 대한 요청입니다. 그러나 여전히 네트워크 리소스를 사용하므로 다양한 스프라이트 및 축소 기술을 사용하여 최적화할 수 있습니다.

이러한 최적화는 다른 기사에서 논의되지만 여기서 중요한 것은 정적 콘텐츠에 대한 다른 location 지시문을 사용하여 요청을 별도로 기록할 수 있다는 것입니다.

 location ~ \.(jpg|jpeg|gif|png|ico|css|zip|tgz|gz|rar|bz2|pdf|txt|tar|wav|bmp|rtf|js)$ { access_log /var/log/nginx/my_access-static.log; }

nginx location 는 간단한 정규식 일치를 수행하므로 사이트에 발송할 것으로 예상되는 만큼 많은 정적 콘텐츠 확장을 포함할 수 있습니다.

이러한 로그를 구문 분석하는 것은 애플리케이션 로그를 구문 분석하는 것과 다르지 않습니다.

언급할 가치가 있는 기타 로그

언급할 가치가 있는 두 개의 다른 PHP 로그는 디버그 로그와 데이터 저장 로그입니다.

디버그 로그

nginx 로그의 또 다른 편리한 점은 디버그 로그입니다. config의 error_log 줄을 다음으로 교체하여 이를 켤 수 있습니다(nginx 디버그 모듈이 설치되어 있어야 함).

 error_log /var/log/nginx/my_error.log debug;

Apache 또는 사용하는 다른 웹 서버에 동일한 설정이 적용됩니다.

또한 디버그 로그는 error_log 지시문에 구성되어 있어도 오류 로그와 관련이 없습니다 .

디버그 로그가 실제로 장황할 수 있지만(예를 들어 단일 nginx 요청으로 127KB의 로그 데이터가 생성됨!) 여전히 매우 유용할 수 있습니다. 로그 파일을 탐색하는 것은 번거롭고 지루할 수 있지만 종종 디버깅 프로세스를 가속화하는 데 크게 도움이 되는 단서와 정보를 신속하게 제공할 수 있습니다.

특히 디버그 로그는 nginx 구성, 특히 location 일치 및 rewrite 체인과 같은 가장 복잡한 부분을 디버깅하는 데 실제로 도움이 될 수 있습니다.

물론 프로덕션 환경에서 디버그 로그를 활성화하면 안 됩니다. 그들이 사용하는 공간의 양과 저장하는 정보의 양은 서버에 많은 I/O 로드를 의미하므로 전체 시스템의 성능을 크게 저하시킬 수 있습니다.

데이터 저장 로그

디버깅에 유용한 또 다른 유형의 서버 로그는 데이터 저장소 로그입니다. MySQL에서는 다음 행을 추가하여 이를 켤 수 있습니다.

 [mysqld] general_log = 1 general_log_file = /var/log/mysql/query.log

이러한 로그에는 데이터베이스 요청을 시간순으로 처리하는 동안 시스템에서 실행하는 쿼리 목록이 포함되어 있어 다양한 디버깅 및 추적 요구 사항에 도움이 될 수 있습니다. 그러나 성능에 영향을 미치는 불필요한 추가 I/O 로드를 생성하므로 프로덕션 시스템에서 활성화된 상태로 유지해서는 안 됩니다.

로그 파일에 쓰기

PHP 자체는 로그 파일을 열고, 쓰고, 닫는 기능을 제공합니다( 각각 openlog() , syslog() 및 closelog() ).

또한 Monolog(Symfony 및 Laravel 사용자에게 인기 있음)와 같은 PHP 개발자를 위한 수많은 로깅 라이브러리와 CakePHP에 통합된 로깅 기능과 같은 다양한 프레임워크별 구현이 있습니다. 일반적으로 Monolog와 같은 라이브러리는 syslog() 호출을 래핑할 뿐만 아니라 다른 백엔드 기능 및 도구를 사용할 수도 있습니다.

다음은 로그에 쓰는 방법의 간단한 예입니다.

 <?php openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'It works!');

openlog 에 대한 우리의 전화:

  • 스크립트의 수명 내에서 각 시스템 로그 메시지 앞에 고유 식별자를 추가하도록 PHP를 구성합니다.
  • 첫 번째 syslog() 호출이 발생할 때까지 syslog 연결 열기를 지연하도록 설정합니다.
  • LOG_LOCAL0 을 기본 로깅 기능으로 설정합니다.

위의 코드를 실행한 후의 로그 파일 내용은 다음과 같습니다.

 # cat /var/log/my/info.log Mar 2 00:23:29 log-sandbox 54f39161a2e55: It works!

PHP 로그 파일의 가치 극대화

이제 우리는 이론과 기본 사항을 잘 알고 있으므로 샘플 Symfony Standard 프로젝트를 가능한 한 적게 변경하여 로그에서 얼마나 많은 것을 얻을 수 있는지 봅시다.

먼저 src/log-begin.php (로그를 제대로 열고 구성하기 위해) 및 src/log-end.php (성공적인 완료에 대한 정보를 기록하기 위해) 스크립트를 생성해 보겠습니다. 단순함을 위해 모든 메시지를 정보 로그에 기록합니다.

 # src/log-begin.php <?php define('START_TIME', microtime(true)); openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'BEGIN'); syslog(LOG_INFO, "URI\t{$_SERVER['REQUEST_URI']}"); $browserHash = substr(md5($_SERVER['HTTP_USER_AGENT']), 0, 7); syslog(LOG_INFO, "CLIENT\t{$_SERVER['REMOTE_ADDR']}\t{$browserHash}"); <br /> # src/log-end.php <?php syslog(LOG_INFO, "DISPATCH TIME\t" . round(microtime(true) - START_TIME, 2)); syslog(LOG_INFO, 'END');

그리고 app.php 에서 다음 스크립트를 요구합시다.

 <?php require_once(dirname(__DIR__) . '/src/log-begin.php'); syslog(LOG_INFO, "MODE\tPROD"); # original app.php contents require_once(dirname(__DIR__) . '/src/log-end.php');

개발 환경의 경우 app_dev.php 에서도 이러한 스크립트가 필요합니다. 그렇게 하는 코드는 MODE 를 PROD 대신 DEV 로 설정한다는 점을 제외하고 위와 동일합니다.

또한 어떤 컨트롤러가 호출되는지 추적하기를 원하므로 Acme\DemoBundle\EventListener\ControllerListener 에 ControllerListener::onKernelController() 메서드 시작 부분에 한 줄을 더 추가하겠습니다.

 syslog(LOG_INFO, "CONTROLLER\t" . get_class($event->getController()[0]));

이러한 변경 사항은 총 15줄의 추가 코드에 불과하지만 집합적으로는 풍부한 정보를 얻을 수 있습니다.

로그 파일의 데이터 분석

우선 각 페이지 로드를 처리하는 데 필요한 HTTP 요청 수를 살펴보겠습니다.

다음은 로깅을 구성한 방식을 기반으로 한 요청에 대한 로그 정보입니다.

 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: BEGIN Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ Mar 3 12:04:20 log-sandbox 54f58724b1ccc: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:20 log-sandbox 54f58724b1ccc: MODE DEV Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController Mar 3 12:04:25 log-sandbox 54f58724b1ccc: DISPATCH TIME 4.51 Mar 3 12:04:25 log-sandbox 54f58724b1ccc: END Mar 3 12:04:25 log-sandbox 54f5872967dea: BEGIN Mar 3 12:04:25 log-sandbox 54f5872967dea: URI /app_dev.php/_wdt/59b8b6 Mar 3 12:04:25 log-sandbox 54f5872967dea: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:25 log-sandbox 54f5872967dea: MODE DEV Mar 3 12:04:28 log-sandbox 54f5872967dea: CONTROLLER Symfony\Bundle\WebProfilerBundle\Controller\ProfilerController Mar 3 12:04:29 log-sandbox 54f5872967dea: DISPATCH TIME 4.17 Mar 3 12:04:29 log-sandbox 54f5872967dea: END

이제 우리는 각 페이지 로드가 실제로 두 개의 HTTP 요청으로 제공된다는 것을 압니다.

사실 여기에서 언급할 가치가 있는 두 가지 사항이 있습니다. 첫째, 페이지 로드당 두 개의 요청은 개발 모드에서 Symfony를 사용하기 위한 것입니다(이 기사 전체에서 수행했습니다). /app-dev.php/ URL 청크를 검색하여 개발 모드 호출을 식별할 수 있습니다. 둘째, 각 페이지 로드가 Symfony 앱에 대한 두 개의 후속 요청과 함께 제공된다고 가정해 보겠습니다. 앞서 nginx 액세스 로그에서 보았듯이 실제로는 더 많은 HTTP 호출이 있으며 그 중 일부는 정적 콘텐츠에 대한 것입니다.

자, 이제 데모 사이트에서 약간의 서핑을 하고(로그 파일에 데이터를 구축하기 위해) 이 로그에서 무엇을 더 배울 수 있는지 봅시다.

로그 파일이 시작된 이후 총 몇 개의 요청이 처리되었습니까?

 # grep -c BEGIN info.log 10

그 중 하나가 실패했습니까(스크립트가 끝에 도달하지 않고 종료되었습니까?)?

 # grep -c END info.log 10

BEGIN 및 END 레코드 수가 일치하므로 모든 호출이 성공했음을 알 수 있습니다. (만약 PHP 스크립트가 성공적으로 완료되지 않았다면 src/log-end.php 스크립트 실행에 도달하지 못했을 것입니다.)

사이트 루트에 대한 요청 비율은 얼마입니까?

 # `grep -cE "\s/app_dev.php/$" info.log` 2

이것은 사이트 루트에 2개의 페이지 로드가 있음을 알려줍니다. 이전에 (a) 페이지 로드당 앱에 대한 2개의 요청이 있고 (b) 총 10개의 HTTP 요청이 있다는 것을 배웠으므로 사이트 루트에 대한 요청의 비율은 40%(즉, 2x2/10)였습니다.

사이트 루트에 대한 요청을 처리하는 컨트롤러 클래스는 무엇입니까?

 # grep -E "\s/$|\s/app_dev.php/$" info.log | head -n1 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ # grep 54f58724b1ccc info.log | grep CONTROLLER Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController

여기에서는 요청의 고유 ID를 사용하여 해당 단일 요청과 관련된 모든 로그 메시지를 확인했습니다. 따라서 사이트 루트에 대한 요청을 처리하는 컨트롤러 클래스가 Acme\DemoBundle\Controller\WelcomeController 확인할 수 있었습니다.

서브넷 192.168.0.0/16 의 IP를 가진 클라이언트가 사이트에 액세스했습니까?

 # grep CLIENT info.log | cut -d":" -f4 | cut -f2 | sort | uniq 192.168.56.1

이 간단한 테스트 사례에서 예상한 대로 내 호스트 컴퓨터만 사이트에 액세스했습니다. 이것은 물론 매우 단순한 예이지만 (사이트에 대한 트래픽 소스를 분석할 수 있는) 시연하는 기능은 분명히 매우 강력하고 중요합니다.

내 사이트에 대한 트래픽 중 FireFox에서 발생한 트래픽은 얼마입니까?

Firefox 사용자 에이전트의 해시로 1b101cd 를 사용하면 이 질문에 다음과 같이 대답할 수 있습니다.

 # grep -c 1b101cd info.log 8 # grep -c CLIENT info.log 10

답: 80%(즉, 8/10)

느린 응답을 가져온 요청의 비율은 얼마입니까?

이 예에서는 응답을 제공하는 데 5초 이상 걸리는 것으로 "느림"을 정의합니다. 따라서:

 # grep "DISPATCH TIME" info.log | grep -cE "\s[0-9]{2,}\.|\s[5-9]\." 2

답: 20%(즉, 2/10)

GET 매개변수를 제공한 사람이 있습니까?

 # grep URI info.log | grep \?

아니요, Symfony 표준은 URL 슬러그만 사용하므로 여기에서 아무도 사이트를 해킹하려고 시도하지 않았음을 알려줍니다.

이는 로그 파일을 창의적으로 활용하여 귀중한 사용 정보와 기본 분석을 산출하는 방법에 대한 비교적 기초적인 몇 가지 예에 불과합니다.

기타 염두에 두어야 할 사항

보안 유지

또 다른 주의 사항은 보안을 위한 것입니다. 요청을 기록하는 것이 좋은 생각이라고 생각할 수도 있습니다. 대부분의 경우 실제로 그렇습니다. 그러나 잠재적으로 민감한 사용자 정보를 로그에 저장하기 전에 제거하는 데 극도로 주의하는 것이 중요합니다.

로그 파일 팽창 방지

로그 파일은 항상 정보를 추가 하는 텍스트 파일이기 때문에 지속적으로 증가하고 있습니다. 이것은 잘 알려진 문제이므로 로그 파일 증가를 제어하는 ​​몇 가지 상당히 표준적인 접근 방식이 있습니다.

가장 쉬운 방법은 로그를 회전하는 것 입니다. 로그 회전은 다음을 의미합니다.

  • 추가 쓰기를 위해 주기적으로 로그를 새 빈 파일로 교체
  • 기록을 위해 이전 파일 저장
  • 디스크 공간을 확보하기에 충분히 "오래된" 파일 제거
  • 이러한 파일 변경이 발생할 때 애플리케이션이 중단되지 않은 로그에 쓸 수 있는지 확인

이에 대한 가장 일반적인 솔루션은 대부분의 *nix 배포판이 사전 설치된 상태로 배송되는 logrotate 입니다. 로그 회전을 위한 간단한 구성 파일을 살펴보겠습니다.

 /var/log/my/debug.log /var/log/my/info.log /var/log/my/warning.log /var/log/my/error.log { rotate 7 daily missingok notifempty delaycompress compress sharedscripts postrotate invoke-rc.d rsyslog rotate > /dev/null endscript }

또 다른 고급 접근 방식은 rsyslogd 자체가 현재 날짜 및 시간을 기반으로 동적으로 생성된 메시지를 파일에 작성하도록 하는 것입니다. 이를 위해서는 여전히 오래된 파일을 제거하기 위한 맞춤형 솔루션이 필요하지만 devops가 각 로그 파일의 시간 프레임을 정확하게 관리할 수 있습니다. 우리의 예:

 $template DynaLocal0Err, "/var/log/my/error-%$NOW%-%$HOUR%.log" $template DynaLocal0Info, "/var/log/my/info-%$NOW%-%$HOUR%.log" $template DynaLocal0Warning, "/var/log/my/warning-%$NOW%-%$HOUR%.log" $template DynaLocal0Debug, "/var/log/my/debug-%$NOW%-%$HOUR%.log" local1.err -?DynaLocal0Err local1.info -?DynaLocal0Info local1.warning -?DynaLocal0Warning local1.debug -?DynaLocal0Debug

이런 식으로 rsyslog 는 매시간 개별 로그 파일을 생성하며, 이를 회전하고 데몬을 다시 시작할 필요가 없습니다. 이 솔루션을 수행하기 위해 5일이 지난 로그 파일을 제거하는 방법은 다음과 같습니다.

 find /var/log/my/ -mtime +5 -print0 | xargs -0 rm

원격 로그

프로젝트가 성장함에 따라 로그에서 정보를 구문 분석하는 데 점점 더 많은 리소스가 소모됩니다. 이것은 추가 서버 로드를 생성한다는 의미일 뿐만 아니라; 이는 또한 로그를 구문 분석할 때 CPU 및 디스크 드라이브에 최대 부하를 생성하여 사용자의 서버 응답 시간을 저하시킬 수 있음을 의미합니다(최악의 경우 사이트가 다운될 수도 있음).

이 문제를 해결하려면 중앙 집중식 로깅 서버 를 설정하는 것이 좋습니다. 이를 위해 필요한 것은 UDP 포트 514(기본값)가 열려 있는 다른 상자뿐입니다. rsyslogd 가 연결을 수신하도록 하려면 구성 파일에 다음 행을 추가하십시오.

 $UDPServerRun 514

이렇게 하면 클라이언트를 설정하는 것이 다음과 같이 쉽습니다.

 *.* @HOSTNAME:514

(여기서 HOSTNAME 은 원격 로깅 서버의 호스트 이름입니다).

결론

이 기사는 로그 파일이 이전에 상상했던 것보다 훨씬 더 가치 있는 정보를 제공할 수 있는 몇 가지 창의적인 방법을 보여주었지만 가능한 것의 표면만 긁었다는 점을 강조하는 것이 중요합니다. 기록할 수 있는 범위, 범위 및 형식은 거의 무한합니다. 즉, 로그에서 추출하려는 사용 또는 분석 데이터가 있는 경우 이후에 쉽게 구문 분석 및 분석할 수 있는 방식으로 기록하기만 하면 됩니다. 게다가 그 분석은 종종 grep , sed 또는 awk 와 같은 표준 Linux 명령줄 도구를 사용하여 수행할 수 있습니다.

실제로 PHP 로그 파일은 엄청난 이점을 제공할 수 있는 가장 강력한 도구입니다.

자원

GitHub의 코드: https://github.com/isanosyan/toptal-blog-logs-post-example

부록: Unix 셸에서 로그 파일 읽기 및 조작

다음은 로그 파일을 읽고 조작하는 데 익숙해야 하는 좀 더 일반적인 *nix 명령줄 도구에 대한 간략한 소개입니다.

  • cat 는 아마도 가장 단순한 것입니다. 전체 파일을 출력 스트림에 인쇄합니다. 예를 들어 다음 명령은 콘솔에 logfile1 을 인쇄합니다.

     cat logfile1

  • > 문자를 사용하면 예를 들어 다른 파일로 출력을 리디렉션할 수 있습니다. 쓰기 모드에서 대상 스트림을 엽니다(대상 콘텐츠 삭제를 의미함). tmpfile 의 내용을 logfile1 의 내용으로 바꾸는 방법은 다음과 같습니다.

     cat logfile1 > tmpfile

  • >> 출력을 리디렉션하고 추가 모드에서 대상 스트림을 엽니다. 대상 파일의 현재 내용은 유지되고 맨 아래에 새 줄이 추가됩니다. 이것은 logfile1 내용을 tmpfile 에 추가합니다:

     cat logfile1 >> tmpfile

  • grep 은 일부 패턴으로 파일을 필터링하고 일치하는 행만 인쇄합니다. 아래 명령은 Bingo 메시지가 포함된 logfile1 인쇄합니다.

     grep Bingo logfile1

  • cut 은 단일 열의 내용을 인쇄합니다(1부터 시작하는 숫자로). 기본적으로 탭 문자를 열 사이의 구분 기호로 검색합니다. 예를 들어 YYYY-MM-DD HH:MM:SS 형식의 타임스탬프로 가득 찬 파일이 있는 경우 연도만 인쇄할 수 있습니다.

     cut -d"-" -f1 logfile1

  • head 는 파일의 첫 번째 줄만 표시합니다.

  • tail 은 파일의 마지막 줄만 표시합니다.

  • sort 는 출력에서 ​​줄을 정렬합니다.

  • uniq 는 중복 라인을 걸러냅니다.

  • wc 는 단어(또는 -l 플래그와 함께 사용되는 경우 행)를 계산합니다.

  • | (즉, "파이프" 기호) 한 명령의 출력을 다음 명령의 입력으로 제공합니다. 파이프는 명령을 결합하는 데 매우 편리합니다. 예를 들어 다음은 타임스탬프 세트 내에서 발생하는 2014년 월을 찾는 방법입니다.

     grep -E "^2014" logfile1 | cut -d"-" -f2 | sort | uniq

여기서 우리는 먼저 "starts with 2014" 정규 표현식에 대해 라인을 매치한 다음 개월을 줄입니다. 마지막으로 sort 과 uniq 의 조합을 사용하여 발생 항목을 한 번만 인쇄합니다.