그누보드5 디버깅 플러그인 개발 후기

그누보드5에는 내장된 'debugbar' 플러그인으로 간단한 형태로 DB 쿼리 목록이나 자체 지원하는 Hook 시스템의 상태를 확인할 수 있는 기능을 제공합니다. 실행된 쿼리와 소요시간, 메모리 사용량 그리고 내장된 Hook이 몇 회 호출되었고 어떤 Listener가 등록되어 있는지 확인할 수 있죠.

사이트 하단으로 스크롤을 내려 "디버그"라는 버튼을 누르면 쿼리와 Hook 목록을 볼 수 있습니다.

그누보드5에서 지원하는 디버깅 기능은 사실 이것이 전부입니다.

 

그누보드5 파일 중 config.php 파일을 수정하여 G5_DEBUG 상수의 값을 변경하면 이 기능을 활성화 할 수 있죠.

define('G5_DEBUG', true);

'debugbar'라는 이름에서 볼 수 있듯이 PHP Debug Bar를 흉내낸 기능입니다.
다만, 제공하는 기능은 위 두가지 정도입니다.

그누보드5는 여전히 PHP 5.2 버전을 지원하기 때문에 PHP 7.1 이상을 요구하는 PHP Debug Bar를 내장 시킬 수는 없었겠죠.

붙여 볼까?

나는 서드파티 개발자이니까 요구 PHP 지원 버전에 상관없이 PHP Debug Bar를 붙여 보기로 했습니다.

사실 이걸 목표로 잡고한 것은 아닌데 다른 플러그인을 개발하는 도중에 var_dump()를 이용한 디버깅이 너무 답답하고 한계가 있어서 머리도 식힐겸(?) 간단하게 만들어 보기로 했습니다.

확장 기능 시스템을 알아보자

우선, 그누보드의 확장 기능은 단지 'plugin' 이름을 가진 폴더가 있고, "그누보드 플러그인 개발"이라는 것은 이 폴더에 파일을 두고 개발하게 됩니다.

plugin 폴더에 어떤 기능을 만들었다해도 임의로 include 하기 전에는 아무것도 로드되지 않으며, 어떤 동작도 하지 않습니다. 단지 "플러그인"이라는 이름의 확장기능을 개발하면 이 폴더에 넣기로 하자는 암묵적인 약속입니다.

그누보드5에서 자동으로 로드해주는 기능이 하나 있는데 'extend' 폴더입니다.
이 폴더에 '*.extend.php' 파일을 생성해두면 파일의 이름 순으로 자동으로 파일을 include 합니다. plugin 폴더에 기능을 구현하고 자동으로 로드하기위해 extend 폴더에 파일을 생성해서 플러그인의 기능을 호출해줘야하는 방식입니다.

// /extend/my_plugin.extend.php
include G5_PLUGIN_PATH . '/my_plugin/index.php';

 

그누보드5의 Hook 사용하기

플러그인 내의 파일을 자동으로 로드시켰지만 화면에 PHP Debug Bar를 표시해야겠죠.

그누보드5는 객체지향구조를 갖추지 않았고 대부분이 선형의 절차지향 방식을 사용하고 있고, 기능을 확장하는 방법은 그누보드5가 지원하는 Hook이 유일한 확장 시스템 입니다.

그누보드 5.4 버전에서 Hook이 처음 추가되었으며 그누보드5 Hook 매뉴얼에서는 아래와 같이 소개하고 있습니다.

후킹( hooking )이라고 불릴수 있습니다.
또는 인터셉터 라고도 할수 있습니다.
( 구글에서 인터셉터를 검색해 보세요. )

이 Hook을 사용하려면 먼저 어떤 event를 사용해야할지 찾아봐야겠죠. 따로 목록을 제공하지는 않고 전체 파일에서 'run_event'를 검색해서 찾아보면 90여개, 중복을 제거하면 80여개의 이벤트를 찾을 수 있습니다. 이 이벤트들 중 가장 먼저 실행되는건 'common_header'입니다.

그렇긴 한데 사실은 'sql_query_after' 이벤트가 가장 먼저 발생합니다. 변수나 설정을 초기화하면서 DB에서 설정 값을 가져오면서 'sql_query_after' 이벤트가 발생하기 때문이죠. 그렇다고해서 'sql_query_after'를 이용하기 보다는 'common_header'를 이용하는 것이 맞겠죠.

하지만 이 플러그인은 사이트에 어떤 기능을 제공하는 것이 아니고 가장 늦게 실행되어 모든 과정이 끝난후에 데이터를 수집하고 출력해야하기 때문에 가장 늦은 시점의 이벤트를 찾아보니 'tail_sub'입니다. 그누보드5에 내장된 'debugbar'도 이 이벤트를 사용하고 있습니다. HTML의 body 태그를 닫기 직전에 발생하는 이벤트입니다.

add_event('tail_sub', 'listener_my_plugin_tail_sub');

function listener_my_plugin_tail_sub()
{
    // ...
}

 

제게 필요한 'tail_sub' 이벤트에 리스너를 등록해서 모든(사실은 대부분)의 동작이 끝나기 직전에 PHP Debug Bar 동작에 필요한 코드를 호출하고 화면에 출력하는데 성공했습니다. 많은 것이 생략되었지만 적절한 이벤트를 잡아서 아무튼 이렇게 저렇게해서 동작시켰죠.

쿼리 목록을 수집해서 출력해보자 - 또다른 Hook 사용

그누보드5에서 제공하는 DB... 그누보드5는 전통 방식(?)의 mysql/mysqli 함수를 사용해서 DB에 질의할 수 있습니다. PDO나 ORM 구조는 갖추지 못했습니다. 일반적인 질의에 sql_query() 함수를 사용하는데 이 함수에서 질의를 실행하고 결과를 받은 후에 'sql_query_after' 이벤트를 발생시킵니다. 이 이벤트에 리스너를 등록해두면 실행한 쿼리 목록을 받아올 수 있죠.

'tail_sub' 이벤트와는 달리 리스너에 parameter를 전달해주는데 이 파라메터를 받기위해서는 add_event()에서 네번째 파라메터의 값을 설정해야 합니다.

add_event('sql_query_after', 'listener_my_plugin_sql_query_after', G5_HOOK_DEFAULT_PRIORITY, 4);

function listener_my_plugin_sql_query_after($result, $sql, $start_time, $end_time)
{
    // ...
}

add_event() 함수의 세번째 파라메터는 우선 순위(기본 값인 G5_HOOK_DEFAULT_PRIORITY 상수의 값은 int 8), 네번째는 넘겨 받을 파라메터의 갯수(int)입니다. 'sql_query_after' 이벤트는 파라메터 4개를 전달합니다(코드 참조). Hook은 이런식으로 이벤트를 찾아서 전달해주는 파라메터 갯수를 확인하고 리스너를 등록하면 됩니다.

$result는 mysql_query() 또는 mysqli_qeury()의 반환 값이고 $sql은 실행된 쿼리 구문입니다. $start_time, $end_time은 질의 실행 직전, 직후에 microtime(true)을 이용한 시간 측정 값이고요. 이렇게 전달 받은 데이터로 오류가 있으면 오류메시지와 어디에서 호출된 것인지 찾기 쉽도록 파일의 경로와 라인, 포함된 함수나 메소드의 이름까지 표기해서 이쁘게 다듬어서 PHP Debug Bar 패널에 쿼리 목록을 출력했습니다. 이렇게 저렇게해서요.

 

플러그인 개발 끝

• plugin 폴더에 내 폴더 하나 만들어서 기능 구현하기
• extend 폴더에 *.extend.php 파일 만들어서 내 플러그인의 파일 include 하기
• 적절한 Hook 이벤트를 찾아서 플러그인을 동작시킬 리스너를 등록하기

간단하게 보자면 이렇죠. 아마 다른 플러그인들을 개발할 때도 이 단순한 과정은 크게 다르지 않을겁니다. 비록 잘 갖춰진 확장 시스템은 아니지만 적절한 Hook 이벤트만 찾을 수 있다면 기능을 덧붙이는데는 큰 어려움은 없습니다.

 

다만, 좀 아쉬운 것들이 있습니다

extend, plugin 구조

extend 폴더에 들어있는 파일들의 이름 순서로 파일이 include 되다보니 가장 빨리 로드되기 위해서 '0000000000000_my_plugin.extend.php', '_050_my_plugin.extend.php', '______my_plugin.extend.php' 이런식으로 다른 확장 기능들과 파일명으로 경쟁(?)해야 합니다. 이건 파일명이 아니더라도 비슷한 구조에서는 마찬가지이긴한데 우선 순위를 조정할 수 있는 기능을 제공하는 반면에 그누보드의 extend는 파일명이 유일한 우선순위를 조정하는 방법입니다.

또한 plugin 폴더와 extend 폴더가 같은 레벨로 서로 분리되어있기 때문에 배포할 때 따로 나눠서 배포하거나 extend, plugin 폴더를 포함한 구조로 압축해서 배포해야합니다. 저는 그래서 플러그인 폴더에 *.extend.php 파일을 같이 묶어서 알아서 extend 폴더로 복사해서 사용하라고 안내했습니다. 사실 *.extend.php 파일과 구현한 플러그인의 폴더를 extend 폴더에 다 집어 넣고 동작시켜도 되겠지만 그렇게 하지 않는 게 암묵적인 룰인 것 같습니다.

너무 늦게 호출된 Hook

늦었다보기다는 extend 폴더 내의 파일이 include 되기전에 실행되는 여러 초기화 과정에서 DB 질의가 4~5개 가량 있는데 이벤트 리스너를 등록하기 전에 질의되므로 'sql_query_after' 이벤트로는 수집할 수 없었습니다. 또한, 다른 플러그인이 먼저 실행되어 질의가 실행되면 그것 또한 놓치게 되죠. 그래서 위와 같이 '_0_kg_debugbar.extend.php' 이런식의 파일 이름을 사용해야했습니다.

또한, HTML 응답의 끝으로 'html_process::end()'가 가장 마지막에 실행되는데 의아하게도 여기에 몇 개의 DB 질의가 있었습니다. 이건 Hook이 등록되어 있어도 이미 내 플러그인은 수집한 쿼리를 화면에 출력하고 끝마친 이후이기 때문에 더 할수 있는 것도 없이 누락되어 버렸죠. 이건 좀 특이한 경우이긴합니다. 그게 왜 거기에서 실행되냐고...

파라메터를 누락하는 이벤트

'sql_query_after' 이벤트를 수신하는 경우에 한정된 문제이긴한데, 그누보드5의 자체 디버그 기능을 켜지 않으면 질의 시작/종료 시간을 전달해주지 않았습니다.

PHP 4버전에서 microtime()의 as_float 파라메터를 지원하지 않았던 시절에 사용했던 반환 값을 쪼개고 더하고하는 코드가 아직 남아있고 그걸 실행시키는게 부담(?)이 돼서인지 디버그 모드가 켜져있을 때만 소요 시간을 측정하고 있었습니다. microtime(true)으로만 변경해도 될텐데, 아무튼 요청은 해두었는데 결과가 어떻게 될지는 모르겠네요.

그누보드의 내장 디버깅 툴은 오류를 감춥니다

왜인지 모르겠지만 가능한 출력을 최소화하려고 노력한 흔적이 보였습니다.

오류가 발생한 실패한 쿼리는 목록에 보여주지 않도록 처리되어 있었고, Hook 목록 또한 리스너가 등록되었지만 이벤트가 발생하지 않았다면 이 또한 감추도록 처리되어 있었습니다. 리스너가 제대로 등록되었는지, 실패한 쿼리가 있는지 확인하려해도 할 수 없었고 오로지 잘 실행된 이쁜 결과물만 출력해주고 있었습니다. 참 이상하죠.

 

그래서 결과물

앞에서 과정을 보여줬던 실행된 쿼리 목록을 보여주는 기능만 담아서 첫번째 버전을 배포했습니다.

아직 기능은 고작 하나 뿐이고 추가 개발하던 것들과 급하게 분리하여 배포하느라 정리되지 않았지만 피드백을 받을 수 있기를 희망하면서 일단은 배포했습니다. 있어야 할만한 기능이나 괜찮은 기능들을 추가해서 다음 버전을 준비하고 있습니다.

PHP Debug Bar 플러그인 v0.1.0 > SIR

 

공개 저장소는 https://github.com/kkigomi/kg_debugbar 입니다.

실제 개발하는 저장소는 따로 있고 이 저장소에는 배포본의 코드만 담고있습니다. 플러그인 사용자가 composer를 사용해서 설치하는 것이 아니고 vendor 폴더까지 포함해야하므로 vendor 폴더에서 샘플 코드 및 테스트 코드 등 동작에 필요하지 않거나 접근하여 실행할 수 있는 파일들을 걸러내기위해 따로 분리해서 배포 전 테스트와 배포본 생성에 사용하고 있습니다.

GitHub - kkigomi/kg_debugbar: 그누보드 PHP Debug Bar 플러그인

이 포스팅은 쿠팡 파트너스 활동의 일환으로, 이에 따른 일정액의 수수료를 제공받습니다.