캘리퍼는 유연한 다중 타겟 로깅 메커니즘을 제공하기 위해 winston로깅 모듈을 빌드한다. 캘리퍼 로깅 하위 시스템과 상호작용할 때 세 가지 서로 다른 측면이 있다:
1. 로깅 스타일 커스터마이징
2. 로깅 타겟 구성
3. 나만의 로거 만들기
처음 두 포인트는 캘리퍼 런타임 구성 메커니즘을 통해 달성할 수 있다. 그러므로 이 페이지를 읽기 전에 런타임 설정을 오버라이딩 하는 여러 방법들을 알고 있는지 먼저 확인하자. 아래 예시는 오직 커맨드라인을 통해 옵션들을 설정한다. 당연히 다른 설정 소스도 사용할 수 있다.
로깅에 대응되는 런타임 구성 설정은 caliper-logging
키 계층 아래에 있다. 일반적인 설정 구조를 위해 캘리퍼와 번들로 제공되는 기본 구성 파일에서 caliper-logging
섹션을 보자.
로깅 스타일의 두가지 주요한 측면은 메시지 구성과, 적용되면 메시지 모양을 수정하는 다양한 형식들이다. 각각 대응되는 속성은 caliper.logging.template
프로퍼티와 전체 caliper.logging.formats
프로퍼티 계층이다.
caliper.logging.formats
계층은 모든 리프 프로퍼티를 커맨드 라인 또는 환경 변수로 하나씩 오버라이딩 할 수 있다는 점에서 특별하다. 나중에 살펴보겠지만, 로깅 타겟 설정의 경우에는 그렇지 않다.
주의
다음 스타일 설정이 모든 지정된 로깅 타겟에 적용된다.
메시지 구조는 caliper.logging.template
프로퍼티로 쉽게 커스터마이징 할 수 있다. 이것은 특정한 값들에 대한 사전정의된 플레이스홀더를 가지고 있는 단순한 문자열이다. 일부 플레이스홀더는 연관된 포맷이 적용된 경우에만 사용가능하다.
기본 구조부터 살펴보자:
caliper:
logging:
template: '%timestamp% %level% [%label%] [%module%] %message% (%metadata%)'
현재 아래 플레이스홀더를 사용할 수 있다.
Placeholder | Required format | Description |
---|---|---|
%timestamp% | timestamp | 로그 메시지 타임스탬프로 대체된다. |
%level% | - | 로그 메시지 심각도(info, warn, error 등)으로 대체된다. |
%label% | label | 프로세스 레이블로 대체된다. |
%module% | - | 메시지를 기록한 모듈 이름으로 대체된다. |
%message% | - | 실제 메시지로 대체된다. |
%metadata% | - | 추가 로깅 arguments의 문자열 표현으로 대체된다. |
caliper-logging-template
설정키를 변경함으로써 이 템플릿을 오버라이딩할 수 있다. 예를 들어, 커맨드라인에서 --caliper-logging-template="%time%: %message%"
를 입력할 수 있다.
주의
- 템플릿에 공백이 포함될 수 있으므로 반드시 두 개의 큰따옴표를 사용해야 한다.
- 모든 포맷이 적용된 후 이 템플릿이 적용된다.
- 단순한 컬러링 시나리오의 경우(또는 컬러링이 비활성화된 경우) 이 방법으로 공백과 다른 대괄호를 추가해도 좋다. 하지만 전체 로그 메시지 또는 추가 문자로 둘러싸여야 하는 부분을 컬러링하는 경우, 이 방법은 비일관적인 결과를 낳는다. 고급 메시지 포맷 시나리오는 팁&트릭을 참고하자.
로깅 하위시스템은 로그 메시지를 수정하기 위해 윈스톤의 포맷 메커니즘에 의존한다. 관련 설정은 caliper.logging.formats
프로퍼티 아래에 위치한다.
이 포맷들 각각은 프로퍼티를 false
로 지정해 쉽게 비활성화할 수 있다. 예를 들어 colorize
포맷을 비활성화하려면 관련 프로퍼티인 caliper.logging.formats.colorize
를 false
로 지정한다. 커맨드 라인에서는 --caliper-logging-formats-colorize=false
로 사용할 수 있다.
유사하게, 모든 하위 프로퍼티는 손쉽게 오버라이딩 될 수 있다. 예를 들어 caliper.logging.formats.colorize.colors.info
를 커맨드 라인에서 지정할 수 있다: --caliper-logging-formats-colorize-colors-info=blue
.
아래 포맷과 그 옵션들(하위 프로퍼티들)이 지원된다.
주의
여러 포맷들이 제시된 순서에 따라 적용되며 이는 중요하다(이유는 팁 & 트릭 섹션을 참조하자).
특정한 포맷으로 타임스탬프를 메시지에 추가한다. 포맷 문자열은 반드시 fecha 패키지 규칙을 준수해야 한다.
예: --caliper-logging-formats-timestamp="YYYY.MM.DD-HH:mm:ss.SSS"
참고
이 포맷은 메시지에
timestamp
속성을 사용가능하게 한다. 따라서 이는 메시지 템플릿 대에서 참조되거나, 메시지 속성에 접근가능한 다른 포맷에서 참조될 수 있다.
커스텀 레이블을 메시지에 추가한다. 이는 로그 수집 후 여러 캘리퍼 인스턴스 (또는 분산된 클라이언트 인스턴스) 구별에 유용하다.
예: --caliper-logging-formats-label="caliper-test-1"
참고
이 포맷은 메시지에
label
속성을 사용가능하게 한다. 따라서 이는 메시지 템플릿 대에서 참조되거나, 메시지 속성에 접근가능한 다른 포맷에서 참조될 수 있다.
메시지를 JSON 문자열로 출력한다. 다른 툴에 의해 자동적으로 처리될 파일 기반 로그에 유용하다. 이 포맷은 space
하위 프로퍼티를 옵션으로 허용하는데, 이는 JSON.stringify
함수의 space
파라미터에 해당한다.
예: --caliper-logging-formats-json="{space:0}"
참고
- 이 포맷 활성화는 구성 파일에서 더 쉽다. 팁 & 트릭 섹션을 보자.
space
를 0이 아닌 숫자로 설정하면 여러 줄 들여쓰기를 가진 JSON 출력을 효과적으로 형성한다. 이것은 콘솔을 약간 "스팸"할 수 있다(추가 새 줄에 신경쓰지 않는 이상 로그파일에서는 문제가 되지 않는다).- 이 포맷이 활성화되면 나머지 포맷은 적용되지 않는다. 그것들의 목적은 기본적으로 콘솔 로그 가독성을 높이는 것이기 때문이다.
모든 로그 수준 문자열을 같은 길이로 만든다. 즉, "info"와 "warn"에 추가 공백을 더해서 "error", "debug"와 같은 길이로 만든다.
예시: --caliper-logging-formats-pad=true
로그의 메시지 파트 앞 쪽에 탭("\t")
을 붙여(prepend) 다른 로그들의 메시지를 같은 위치에서 시작하도록 정렬한다.
예시: --caliper-logging-formats-align=true
참고
메시지 포맷이 가변 길이를 가진 다른 정보를 포함할 경우(예: 모듈 이름), 메시지가 어긋나게 된다. 따라서 이것은 단순히 콘솔 메시지를 더 가독성 높게 만드는 "가장 효율적인" 방법이다.
메시지의 여러 속성에 대한 문자열 포맷팅 옵션을 정의한다. 각 메시지 속성에 값을 재형성하는 "포맷 문자열"이 제공된다. 포맷 스트링은 오리지널 값을 참조하기 위해 %attribute%
플레이스홀더를 사용할 수 있다.
포맷 스트링은 아래 메시지 속성으로 지정될 수 있다:
예를 들어, 로그의 레벨 정보를 커스터마이징하기 위해서는 정보를 LEVEL[<level>]
문자열로 묶는다:
--caliper-logging-formats-attributeformat-level="LEVEL[%attribute%]"
참고
속성이 문자열이 아닐 경우(메타데이터 속성의 경우 가능하다), 첫 속성 값이
JSON.stringify
를 사용해 문자열로 변환되고, 포맷 문자열에 삽입된다.
메시지의 다른 속성들에 컬러 코딩을 적용한다. 컬러링 활성화/비활성화는 속성 기반으로 지정된다. 아래 하위 프로퍼티가 해당되는 속성의 컬러링을 활성화/비활성화 하기 위해 true/false
로 설정된다:
예를 들어 메시지의 모든 부분을 채색하려면 --caliper-logging-formats-colorize-all=true
를 사용한다.
또한, 이포맷은 colors
속성을 노출시킨다. 이것은 info
, error
, warn
, debug
레벨에 대한 컬러링 정보를 가지고 있다. 한 레벨에 대한 값은 colors패키지에서 제공하는 색상과 스타일로 설정될 수 있다. 여러 스타일을 적용하기 위해서는 값을 공백으로 분할한다.
예를 들어, 에러 수준 로그를 강조하기 위해서는 다음과 같이 할 수 있다: --caliper-logging-formats-colorize-colors-error="white bgRed bold italic"
참고
colors
패키지는 매력적인 스타일들을 제공하지만 눈을 위해 과도하게 사용하지 않는 것이 좋다. 단순한 스타일을 유지하자.
로그 메시지의 소스와 대상들은 winston의 전송 로그 메커니즘 덕에 분리된다. 이는 로그 메시지가 쉽게 여러 위치(콘솔이나 다른 로그 파일들)에 기록될 수 있음을 뜻한다. 게다가, 이것은 로그 메시지를 생성하는 모듈을 완전히 투영한다.
여러 대상들은 caliper.logging.targets
프로퍼티 하에서 지정된다. caliper.logging.targets
섹션은 아래 일반적인 형태를 가진다:
caliper:
logging:
targets:
mylogger1:
target: console
enabled: true
options:
# console target-specific options
mylogger2:
target: file
enabled: true
options:
# file target-specific options
caliper.logging.target
의 각 하위 프로퍼티는 주어진 로깅 타겟에 대한 임시 이름이다(mylogger1
, mylogger2
등).
각 대상은 반드시 아래 프로퍼티를 지정해야 한다:
target
: 지원하는 대상에 대한 식별자. 아래 테이블을 보자.enabled
: 대상이 활성화되었는지 여부를 가리킴. 기본값은 true
이다.options
: 이 오브젝트는 옵션으로서 특정한 winston 전송 로그에 있는 그대로(as-is) 전송된다. 각 전송 로그에 지원되는 옵션은 아래 테이블을 보자.아래 target 값(즉, 전송 로그)이 지원된다. 각 전송 로그에 대한 공식 문서는 링크를 클릭하자.
target | 가능한 옵션들 |
---|---|
console | Console Transport |
file | File Transport |
daily-rotate-file | Daily Rotating File Transport |
caliper.logging.targets
섹션의 설정 키/프로퍼티는 (caliper.logging.formats
섹션의 프로퍼티처럼) 일대 일로 오버라이징 되지 않지만 enabled
프로퍼티는 예외이다. 로거를 쉽게 비활성화 하기 위해 (프로퍼티 계층에서 타겟의 이름을 사용해) enabled
프로퍼티를 false
로 지정할 수 있다.
예를 들어, mylogger1
타겟을 비활성화 하기 위해서는 아래 방법들이 가능하다:
--caliper-logging-targets-mylogger1-enabled=false
export CALIPER_LOGGING_TARGETS_MYLOGGER1_ENABLED=false
참고
이를 위해서는 반드시 타겟 이름을 소문자(또는/그리고 숫자들)로 설정해야 한다.
하지만 만약 한 전송 로그의 옵션 하나를 수정하고 싶을 땐 어떻게 해야 할까? 이를 위해 구성 파일을 이용할 수 있다.
다음 예시에서는 기본 파일 로거를 비활성화하고, 콘솔 타겟의 로깅 레벨을 수정하고, 새 daily-rotate-file
로거를 추가한다. 이 모든 것들을 단일 구성 파일에서 적용시킬 수 있다.
caliper:
logging:
targets:
console:
options:
# we don't care about info level messages anymore
level: warn
file:
# we disable this
enabled: false
rotatingfile:
target: daily-rotate-file
# enabled by default
options:
# we log every message this way
level: debug
# start a new log file every hour
datePattern: 'YYYY-MM-DD-HH'
# compress old log files after rotating
zippedArchive: true
# include the hour-precision date in the file names
filename: 'caliper-%DATE%.log'
# options for opening the file for writing
options:
# append mode
flags: a
# make the file readable/writable by anyone
mode: 0666
워크스페이스 디렉토리에 caliper.yaml
으로 위 내용을 저장할 경우, 캘리퍼가 이것을 자동으로 가져갈 것이다.
참고 : 위 파일 내용에 대한 몇몇 설명
- 오버라이딩 하고 싶은 프로퍼티들만을 설정했다. 기본 구성 파일은 위 구성 파일과 머지되고, 후자(위 구성 파일)가 우선순위를 가진다.
- 제공된 전송(로그) 옵션은 캘리퍼에서 검증되지 않는다. 그것은 단순히 지정된 전송로그를 통해 전달될 뿐이다. 전송 로그를 올바른 방식으로 구성하는 것은 당신의 역할이다.
- 파일 로거를 커맨드라인이나 환경변수를 통해서도 비활성화할 수 있다. 이것을 구성 파일에서 한 이유는 아래 팁 & 트릭 섹션에서 설명한다.
캘리퍼의 여러 모듈들은 로깅을 위해 구성된 타겟들을 자동으로 사용할 것이다. 또한, 유저 테스트 모듈도 비즈니스 로직과 관련된 런타임 이벤트를 기록하기 위한 로거 인스턴스를 생성할 수 있다.
나만의 로거 인스턴스를 생성하기 위해서 아래 API를 사용한다:
const logger = require('@hyperledger/caliper-core').CaliperUtils.getLogger('my-module');
// ...
logger.debug('My custom debug message', metadataObject1, metadataObject2);
로거 인스턴스가 생성되면 로그 메시지와 "메타데이터"로 간주되는 추가 오브젝트를 파라미터로 가지는 info
, warn
, debug
, error
함수가 노출된다. 이 "메타데이터"는 일반적으로 디버그 로그 레벨에 유용하다. 복잡한 입력 파라미터/오브젝트에 기반한 동작을 수행할 경우 함수를 시작할 때 다음을 기록할 수 있다.
function complexCalculation(complexInput) {
logger.debug('Starting complex calculation. Input: ', complexInput);
// complex calculation
}
"메타데이터"는 메시지 템플릿 섹션에서 다룬 것 처럼, %metadata%
플레이스홀더 위치에 나타난다.
참고
대량의 메타데이터 오브젝트를 전달하는 것은 루프 또는 hot path에서 일어날 경우 로깅 퍼포먼스를 저하시킬 수 있다. 디버그 레벨은 일반적으로 프로덕션 코드에서 사용되지 않으므로, "메타데이터"로깅은 디버그 메시지에만 사용하는 것이 좋다.
윈스턴 포맷은 로그 메시지의 임의 조작을 허용하는 강력한 기능이다. 사용자 관점에서 로그 메시지는 콘솔에 나타나거나 파일에 저장되는 간단한 문자열이다. 하지만 이 문서에서 설명된 로깅 스타일을 완전히 활용하기 위해서는 그 아래에서 무엇이 일어나고 있는지 알 필요가 있다.
참고
이 섹션의 남은 부분에서 로그 메시지를 로그로 표현할 것이다.
로그는 logger.info(...)
또는 유사한 함수를 호출할 때 생성되는 아이템/오브젝트로 간주된다. 로그는 이를 위해 몇몇 속성들을 가지고 있다. 모든 로그가 level
과 message
속성을 가지고, 이 속성들은 로그의 심각도와 로그에 대한 설명을 포함한다. 추가적으로, 캘리퍼는 캘리퍼 API를 통해 생성된 모든 로거의 로그메시지에 module
속성을 자동으로 추가한다. 이것은 로그를 발행하는 모듈의 이름을 나타낸다.
예시를 통해 포맷 파이프라인을 설명해 보자.
아래 caliper.logging
구성이 사용되었다고 가정한다:
template: '%timestamp%%level%%label%%module%%message%%metadata%'
formats:
timestamp: 'YYYY.MM.DD-HH:mm:ss.SSS'
label: caliper
json: false
pad: true
align: false
attributeformat:
level: ' %attribute%'
label: ' [%attribute%]'
module: ' [%attribute%] '
metadata: ' (%attribute%)'
colorize:
all: true
colors:
info: green
error: red
warn: yellow
debug: grey
이는 아래 포맷이 모든 로그에 적용됨을 뜻한다:
더 나아가, 아래 코드로 로그를 초기화한다고 가정하자:
const logger = require('@hyperledger/caliper-core').CaliperUtils.getLogger('my-module');
// ...
logger.info('Doing operation X with:', 'someSetting', 'anotherSetting');
logger.info
호출은 아래 속성을 가진 초기 로그를 생성한다:
level: 'info'
message: 'Doing operation X with:'
로그가 포맷 파이프라인에 들어가기 전에, 캘리퍼는 모듈 이름을 추가하고 추가 파라미터들을 메타데이터로써 수집한다. 이제 로그는 아래 속성을 가진다:
level: 'info'
message: 'Doing operation X with:'
module: 'my-module'
metadata: ['someSetting', 'anotherSetting']
이것은 포맷 파이프라인에 들어가는 초기 로그 엔티티이다. 모든 활성화된 포맷은 "단지" 로그 속성들의 변환이다. 포맷은 존재하는 속성 값을 조정하고 임시 속성을 추가/삭제할 수 있다.
파이프라인의 첫 단계는 타임스탬프 포맷이다. 이것은 현재 시간값을 가지는 타임스탬프 속성 지정된 포맷으로 추가한다. 이 단계 다음에 로그는 다음과 같이 보인다:
level: 'info'
message: 'Doing operation X with:'
module: 'my-module'
metadata: ['someSetting', 'anotherSetting']
timestamp: '2019.10.07-12:45:47.962'
라벨 포맷이 존재한다면 다음 단계에서는 지정된 값(이 경우 캘리퍼)을 가지는 라벨 속성을 추가한다.
level: 'info'
message: 'Doing operation X with:'
module: 'my-module'
metadata: ['someSetting', 'anotherSetting']
timestamp: '2019.10.07-12:45:47.962'
label: 'caliper'
다음 단계는 패딩 포맷이다. 이것은 모든 로깅 레벨 문자열이 동일한 길이를 가지는지를 확인한다. 즉, 레벨 속성에 여분의 공백을 추가한다.
level: 'info '
message: 'Doing operation X with:'
module: 'my-module'
metadata: ['someSetting', 'anotherSetting']
timestamp: '2019.10.07-12:45:47.962'
label: 'caliper'
다음 단계는 속성 포매터이다. 이 포매터는 문자열 탬플릿 기반으로 로그의 여러 속성을 수정하기 위해 구성된다:
이 단계 다음에 로그는 다음과 같이 보인다:
level: ' info '
message: 'Doing operation X with:'
module: ' [my-module] '
metadata: ' (["someSetting", "anotherSetting"])'
timestamp: '2019.10.07-12:45:47.962'
label: ' [caliper]'
참고 : 몇 가지 설명
- 메타데이터는 문자열이 아니라 배열이다. 그러므로 포매팅이 적용되기 이전에 문자열화되었다.
- 메시지와 타임스탬프는 변화하지 않는다.
다음 단계는 채색 포맷이다. 여기서는 구성된 값으로 색상/스타일 코드를 추가한다. all
이 참이고 로그 레벨은 info이므로, 모든 속성은 초록 색상 코드로 둘러싸인다(가독성을 위해 <green>
으로 표시한다):
level: '<green> info <green>'
message: '<green>Doing operation X with:<green>'
module: '<green> [my-module] <green>'
metadata: '<green> (["someSetting", "anotherSetting"])<green>'
timestamp: '<green>2019.10.07-12:45:47.962<green>'
label: '<green> [caliper]<green>'
파이프라인의 마지막 단계는 (json포맷이 비활성화되어있으므로) 콘솔이나 파일에 나타날 최종 메시지를 생성하기 위해 속성을 로깅 탬플릿으로 대체한다. 결과는 아래 순서에 따른 로그 속성 나열이 된다.
1. timestamp
2. level
3. label
4. module
5. message
6. metadata
결과는 아래와 같다:
2019.10.07-12:45:47.962 info [caliper] [my-module] Doing operation X with: (["someSetting", "anotherSetting"])
참고
탬플릿 문자열에 다른 문자 추가를 시도해 보자. 그러면 그것들은 채색되지 않음에 놀랄 것이다. 사실, 이것은 놀랄 만한 일이 아니다. 탬플릿 문자열은 채색 포맷 이후에 "평가" 된다. 이 추가 문자는 로그의 어떤 속성의 일부분도 아니므로, 채색되지 않는다.
로깅 설정은 로그 분석 요구사항에 의해 결정된다. 이는 몇몇 로깅 스타일과 대상을 이식할 때 해당 설정들이 거의 바뀌지 않음을 뜻한다.
이를 위해서는 로깅 스타일 설정을 커맨드라인이나 환경변수에서 오버라이딩하는 기능은 편리하지만, 이상적인 설정을 찾으면 그를 구성 파일에 저장할 가치가 있다.
이를 위한 가장 쉬운 방법은 프로젝트 수준 구성 파일을 이용하는 것이다. 아래를 caliper.yaml
으로 명명하고 워크스페이스 루프에 두면, 캘리퍼는 자동으로 설정을 적용할 것이다.
참고
구성파일을 불러오는 다른 방법들도 있다. 런타임 구성 페이지에서 다루었다.
caliper:
logging:
# no need for timestamp and label
template: '%level% [%module%]: %message% %meta%'
formats:
# color codes look ugly in log files
colorize: false
# don't need these, since won't appear in the template
label: false
timestamp: false
targets:
file:
options:
# bump the log level from debug to warn, only log the critical stuff in this file
level: warn
filename: 'critical.log'
rotatingfile:
target: daily-rotate-file
enabled: true
options:
level: debug
datePattern: 'YYYY-MM-DD-HH'
zippedArchive: true
filename: 'debug-%DATE%.log'
options:
flags: a
mode: 0666
The Caliper codebase is released under the Apache 2.0 license. Any documentation developed by the Caliper Project is licensed under the Creative Commons Attribution 4.0 International License. You may obtain a copy of the license, titled CC-BY-4.0, at http://creativecommons.org/licenses/by/4.0/.