Open Source RDBMS - Seamless, Scalable, Stable and Free

한국어 | Login |Register

Versions available for this page: CUBRID 8.2.1 |  CUBRID 8.3.0 |  CUBRID 8.3.1 |  CUBRID 8.4.0 |  CUBRID 8.4.1 |  CUBRID 8.4.3 |  CUBRID 9.0.0 | 

브로커 로그

브로커 구동과 관련된 로그에는 접속 로그, 에러 로그, SQL 로그가 있다. 각각의 로그는 설치 디렉터리의 log 디렉터리에서 확인할 수 있으며, 저장 디렉터리의 변경은 브로커 환경 설정 파일(cubrid_broker.conf)의 LOG_DIR 파라미터와 ERROR_LOG_DIR 파라미터를 통해 설정할 수 있다.

접속 로그 확인

접속 로그 파일은 응용 클라이언트 접속에 관한 정보를 기록하며, broker_name.access의 이름으로 log/broker/ 디렉터리에 저장된다. 또한, 브로커 환경 설정 파일에서 LOG_BACKUP 파라미터가 ON으로 설정된 경우, 브로커의 구동이 정상적으로 종료되면 접속 로그 파일에 종료된 날짜와 시간 정보가 추가되어 로그 파일이 저장된다. 예를 들어, broker1이 2008년 6월 17일 오후 12시 27분에 정상 종료되었다면, broker1.access.20080617.1227 이라는 접속 로그 파일이 생성된다. 다음은 접속 로그의 예제를 보여준다.

다음은 log 디렉터리에 생성된 접속 로그 파일의 예제와 설명이다.

1 192.168.1.203 - - 972523031.298 972523032.058 2008/06/17 12:27:46~2008/06/17 12:27:47 7118 - -1

2 192.168.1.203 - - 972523052.778 972523052.815 2008/06/17 12:27:47~2008/06/17 12:27:47 7119 ERR 1025

1 192.168.1.203 - - 972523052.778 972523052.815 2008/06/17 12:27:49~2008/06/17 12:27:49 7118 - -1

  • 1 : 브로커의 응용서버에 부여된 ID
  • 192.168.1.203 : 응용 클라이언트의 IP 주소
  • 972523031.298 : 클라이언트의 요청 처리를 시작한 시각의 UNIX 타임스탬프 값
  • 2008/06/17 12:27:46 : 클라이언트 요청을 처리 시작한 시각
  • 972523032.058 : 클라이언트의 요청 처리를 완료한 시각의 UNIX 타임스탬프 값
  • 2008/06/17 12:27:47 : 클라이언트의 요청을 처리 완료한 시각
  • 7118 : 응용서버의 프로세스 ID
  • -1 : 요청 처리 중 발생된 에러가 없음
  • ERR 1025 : 요청 처리 중 발생된 에러가 있고, 에러 정보는 에러 로그 파일의 offset=1025에 존재함
에러 로그 확인

에러 로그 파일은 응용 클라이언트의 요청을 처리하는 도중에 발생된 에러에 관한 정보를 기록하며, broker_name_app_server_num.err의 이름으로 저장된다.

다음은 에러 로그의 예제와 설명이다.

Time: 02/04/09 13:45:17.687 - SYNTAX ERROR *** ERROR CODE = -493, Tran = 1, EID = 38

Syntax: Unknown class "unknown_tbl". select * from unknown_tbl

  • Time: 02/04/09 13:45:17.687 : 에러 발생 시각
  • - SYNTAX ERROR : 에러의 종류(SYNTAX ERROR, ERROR 등)
  • *** ERROR CODE = -493 : 에러 코드
  • Tran = 1 : 트랜잭션 ID. -1은 트랜잭션 ID를 할당 받지 못한 경우임.
  • EID = 38 : 에러 ID. SQL 문 처리 중 에러가 발생한 경우, 서버나 클라이언트 에러 로그와 관련이 있는 SQL 로그를 찾을 때 사용함.
  • Syntax:…  : 에러 메시지
SQL 로그 관리

SQL 로그 파일은 응용 클라이언트가 요청하는 SQL을 기록하며, broker_name_app_server_num.sql.log라는 이름으로 저장된다. SQL 로그는 SQL_LOG 파라미터 값이 ON인 경우에 설치 디렉터리의 log/broker/sql_log 디렉터리에 생성된다. 이 때, 생성되는 SQL 로그 파일의 크기는 SQL_LOG_MAX_SIZE 파라미터의 설정값을 초과할 수 없으므로 주의한다. CUBRID는 SQL 로그를 관리하기 위한 유틸리티로서 broker_log_top, broker_log_converter, broker_log_runner를 제공하며, 이 유틸리티는 SQL 로그가 존재하는 디렉터리에서 실행해야 한다.

다음은 SQL 로그 파일의 예제와 설명이다.

02/04 13:45:17.687 (38) prepare 0 insert into unique_tbl values (1)

02/04 13:45:17.687 (38) prepare srv_h_id 1

02/04 13:45:17.687 (38) execute srv_h_id 1 insert into unique_tbl values (1)

02/04 13:45:17.687 (38) execute error:-670 tuple 0 time 0.000, EID = 39

02/04 13:45:17.687 (0) auto_rollback

02/04 13:45:17.687 (0) auto_rollback 0

*** 0.000

 

02/04 13:45:17.687 (39) prepare 0 select * from unique_tbl

02/04 13:45:17.687 (39) prepare srv_h_id 1 (PC)

02/04 13:45:17.687 (39) execute srv_h_id 1 select * from unique_tbl

02/04 13:45:17.687 (39) execute 0 tuple 1 time 0.000

02/04 13:45:17.687 (0) auto_commit

02/04 13:45:17.687 (0) auto_commit 0

*** 0.000

  • 02/04 13:45:17.687 : 응용 클라이언트의 요청 시각
  • (39) : SQL 문 그룹의 시퀀스 번호이며, prepared statement pooling을 사용하는 경우, 파일 내에서 SQL 문마다 고유(unique)하게 부여된다.
  • prepare 0 : prepared statement인지 여부
  • prepare srv_h_id 1 : 해당 SQL 문을 srv_h_id 1로 prepare한다.
  • (PC) : 플랜 캐시에 저장되어 있는 내용을 사용하는 경우에 출력된다.
  • SELECT... : 실행 SQL 문. Statement pooling한 경우, WHERE 절의 binding 변수가 ?로 표시된다.
  • Execute 0 tuple 1 time 0.000 : 1개의 row가 실행되고, 소요 시간은 0.000초
  • auto_commit/auto_rollback : 자동으로 커밋되거나, 롤백되는 것을 의미한다. 두 번째 auto_commit/auto_rollback은 에러 코드이며, 0은 에러가 없이 트랜잭션이 완료되었음을 뜻한다.

broker_log_top 유틸리티는 특정 기간 동안 생성된 SQL 로그를 분석하여 실행 시간이 긴 순서대로 각 SQL 문과 실행 시간에 관한 정보를 파일에 출력하며, 분석된 결과는 각각 log.top.q 및 log.top.res에 저장된다.

broker_log_top 유틸리티는 롱 쿼리(long query)를 분석할 때 유용하며, 구문은 다음과 같다.

broker_log_top [options] sql_log_file_list

options : {-t | -F  from_date | -T  to_date}

-t 옵션이 주어지면 트랜잭션 단위로 결과를 출력한다.

-F-T 옵션이 주어지면 날짜 범위를 지정하여 일부 SQL 문만 선별적으로 분석한다. 입력 형식은 MM[/DD[ hh[:mm[:ss[.msec]]]]]이며 []로 감싼 부분은 생략할 수 있다. 생략하면 DD는 01을 입력한 것과 같고, hh, mm, ss, msec은 0을 입력한 것과 같다.

-- 밀리초까지 검색 범위를 설정

broker_log_top -F "01/19 15:00:25.000" -T "01/19 15:15:25.180" log1.log

 

-- 아래의 옵션 값에서 시간 형식이 생략된 부분은 기본값 0으로 정해짐. 즉, -F "01/19 00:00:00.000" -T "01/20 00:00:00.000"을 입력한 것과 같음.

broker_log_top -F "01/19" -T "01/20" log1.log

옵션을 모두 생략하면, 모든 로그에 대해 SQL 문 단위로 결과를 출력한다.

다음 예제는 11월 11일부터 11월 12일까지 생성된 SQL 로그에 대해 실행 시간이 긴 SQL문을 확인하기 위하여 broker_log_top 유틸리티를 실행한 화면이다. 기간을 지정할 때, 월과 일은 빗금(/)으로 구분한다. Windows에서는 "*.sql.log"를 인식하지 않으므로 SQL 로그 파일들을 공백(space)으로 구분해서 나열해야 한다.

--Linux에서 broker_log_top 실행

% broker_log_top -F "11/11" -T "11/12" -t *.sql.log

 

query_editor_1.sql.log

query_editor_2.sql.log

query_editor_3.sql.log

query_editor_4.sql.log

query_editor_5.sql.log

 

--Windows에서 broker_log_top 실행

% broker_log_top -F "11/11" -T "11/12" -t query_editor_1.sql.log query_editor_2.sql.log query_editor_3.sql.log query_editor_4.sql.log query_editor_5.sql.log

위 예제를 실행하면 SQL 로그 분석 결과가 저장되는 log.top.qlog.top.res 파일이 동일한 디렉터리에 생성된다. log.top.q에서 각 SQL 문 및 SQL 로그 상의 라인 번호를 확인할 수 있고, log.top.res에서 각 SQL 문에 대한 최소 실행 시간, 최대 실행 시간, 평균 실행 시간, 쿼리 실행 수를 확인할 수 있다.

--log.top.q 파일의 내용

[Q1]-------------------------------------------

broker1_6.sql.log:137734

11/11 18:17:59.396 (27754) execute_all srv_h_id 34 select a.int_col, b.var_col from dml_v_view_6 a, dml_v_view_6 b, dml_v_view_6 c , dml_v_view_6 d, dml_v_view_6 e where a.int_col=b.int_col and b.int_col=c.int_col and c.int_col=d.int_col and d.int_col=e.int_col order by 1,2;

11/11 18:18:58.378 (27754) execute_all 0 tuple 497664 time 58.982

.

.

[Q4]-------------------------------------------

broker1_100.sql.log:142068

11/11 18:12:38.387 (27268) execute_all srv_h_id 798 drop table list_test;

11/11 18:13:08.856 (27268) execute_all 0 tuple 0 time 30.469

 

--log.top.res 파일의 내용

max       min       avg   cnt(err)

-----------------------------------------------------

[Q1]        58.982    30.371    44.676    2 (0)

[Q2]        49.556    24.023    32.688    6 (0)

[Q3]        35.548    25.650    30.599    2 (0)

[Q4]        30.469     0.001     0.103 1050 (0)

설치 디렉터리의 log/broker/sql_log 디렉터리에 생성된 SQL 로그 파일에 기록된 질의를 별도의 입력 파일로 저장하기 위하여 broker_log_converter 유틸리티를 실행한다. broker_log_converter 유틸리티의 구문은 다음과 같다.

broker_log_converter  SQL_log_file  output_file

다음 예제는 query_editor_1.sql.log 파일에 저장된 질의를 query_convert.in 파일로 변경한다.

% broker_log_converter query_editor_1.sql.log query_convert.in

broker_log_converter 유틸리티에 의해 생성된 질의 파일에 저장된 질의를 재실행하기 위하여 broker_log_runner 유틸리티를 실행한다. broker_log_runner 유틸리티의 구문은 다음과 같으며, 예제는 query_convert.in 파일에 저장된 질의를 demodb에서 재실행하며, 브로커 IP가 192.168.1.10이고, 브로커 포트는 30000인 환경임을 가정한다.

broker_log_runner options input_file

options : -I cas_ip -P cas_port  -d dbname  [-u dbuser [-p dbpasswd ]]  [-t num_thread] [-r repeat_count] [Q] [ -o result_file

broker_log_runner 유틸리티의 옵션

옵션

설명

-I broker_ip

CUBRID 브로커의 IP주소 또는 호스트 이름

-P broker_port

CUBRID 브로커의 포트 번호

-d dbname

질의를 실행할 데이터베이스 이름

-u dbuser

데이터베이스 사용자 이름 (기본값: public)

-p dbpasswd

데이터베이스 암호

-t numthread

스레드의 개수(기본값: 1)

-r repeat_count

질의가 수행될 횟수(기본값: 1)

-Q

result_file에 질의 계획을 저장

-o result_file

수행 결과를 저장할 파일 이름

% broker_log_runner -I 192.168.1.10  -P 30000 -d demodb -t 2 query_convert.in

cas_ip = 192.168.1.10

cas_port = 30000

num_thread = 2

repeat = 1

dbname = demodb

dbuser = public

dbpasswd =

exec_time : 0.001

exec_time : 0.000

0.000500 0.000500 –

 

% broker_log_runner -I 192.168.1.10  -P 30000 -d demodb –o result –Q query_convert.in

 …

%cat result.0

-------------- query -----------------

SELECT * FROM athlete where code=10099;

 

cci_execute:1

---------- query plan --------------

Join graph segments (f indicates final):

seg[0]: [0]

seg[1]: code[0] (f)

seg[2]: name[0] (f)

seg[3]: gender[0] (f)

seg[4]: nation_code[0] (f)

seg[5]: event[0] (f)

Join graph nodes:

node[0]: athlete athlete(6677/107) (sargs 0)

Join graph terms:

term[0]: (athlete.code=10099) (sel 0.000149768) (sarg term) (not-join eligible) (indexable code[0]) (loc 0)

 

Query plan:

 

iscan

    class: athlete node[0]

    index: pk_athlete_code term[0]

    cost:  fixed 0(0.0/0.0) var 0(0.0/0.0) card 1

 

Query stmt:

 

select athlete.code, athlete.[name], athlete.gender, athlete.nation_code, athlete.event from athlete athlete where (athlete.code= ?:0 )

 

 

---------- query result --------------

10099|Andersson Magnus|M|SWE|Handball|

-- 1 rows ----------------------------