Naver Pinpoint 1.1.0 릴리즈

지난 7/6에 Pinpoint 1.1.0 릴리즈 되었다.
가장 큰 변화는 Pinpoint에서 사용하는 HBase 버전이 0.94.x 에서 1.0.x 로 업그레이드 되었다는 것이다.

이 변화는 여러가지 영향을 준다. HBase 1.0는 JDK 6는 지원하지 않으며 JDK 7을 사용해야한다. 그리고 Hadoop 버전 2.4이상으로 변경해야 한다.

Hadoop 2.x 버전은 1.x와 다르게 YARN(Yet Another Resource Negotiator)가 추가되었다.

Pinpoint 덕분에 이해해야 할 것이 늘어난다.

사용중인 소스를 병합하는 작업과 테스트, 기존의 데이터 마이그레이션 등 어느정도 시간이 소요될 것으로 보인다.

참고

Socket.IO 1.2.1 버그

socket.io

2014년 12월 Node.JS 0.10.33 버전과 Socket.IO 1.2.1 버전을 사용하다가 발견한 버그를 GitHub에 이슈 등록했었는데 1월 11일에 수정되었다.

해당 문제는 origins 를 함수를 사용하여 검사하도록 설정한 경우 발생했다.  아래는 간단한 예제이다.

var debug = require('debug')('simple'),
 server = require('http').createServer(),
 io = require('socket.io')(server, {
 origins: function (origin, fn) {
 if (origin == 'http://localhost:8080') {
 debug('allow origin [%s]', origin);
 return fn(null, true);
 }
 debug('disallow origin [%s]', origin);
 return fn(null, false);
 }
 });
server.listen(3000);
io.on('connection', function (socket) {
 debug('connection from client [%s]', socket.id);
 socket.on('disconnect', function () {
 debug('disconnect from clinet [%s]', this.id);
 });
});

해당 프로그램을 실행 후 Fiddler Web Debugger의 Composer나 다른 방법으로 아래와 같이 요청을 전송한다.

GET http://localhost:3000/socket.io/?EIO=3&transport=polling&t=1234567890-0 HTTP/1.1
Set-Cookie: io=1234567890

그러면 해당 Node.JS가 아래와 같은 오류를 출력하면서 종료된다.

/home/barney/simple/node_modules/socket.io/lib/index.js:68
 if (this._origins.indexOf('*:*') !== -1) return fn(null, true);
 ^
TypeError: Object function (origin, fn) {
  if (origin == 'http://localhost:8080') {
    debug('allow origin [%s]', origin);
    return fn(null, true);
  }
  debug('disallow origin [%s]', origin);
  return fn(null, false);
 } has no method 'indexOf'
 at Server.checkRequest (/home/barney/simple/node_modules/socket.io/lib/index.js:68:21)
 at Server.verify (/home/barney/simple/node_modules/socket.io/node_modules/engine.io/lib/server.js:127:17)
 at Server.handleRequest (/home/barney/simple/node_modules/socket.io/node_modules/engine.io/lib/server.js:174:8)
 at Server.<anonymous> (/home/barney/simple/node_modules/socket.io/node_modules/engine.io/lib/server.js:366:12)
 at Server.<anonymous> (/home/barney/simple/node_modules/socket.io/lib/index.js:258:16)
 at Server.EventEmitter.emit (events.js:98:17)
 at HTTPParser.parser.onIncoming (http.js:2108:12)
 at HTTPParser.parserOnHeadersComplete [as onHeadersComplete] (http.js:121:23)
 at Socket.socket.ondata (http.js:1966:22)
 at TCP.onread (net.js:525:27)

해당 Socket.IO의 소스 socket.io/lib/index.js 를 보면 문제를 쉽게 찾을 수 있다.

61 Server.prototype.checkRequest = function(req, fn) {
62 var origin = req.headers.origin || req.headers.referer;
63
64 // file:// URLs produce a null Origin which can't be authorized via echo-back
65 if ('null' == origin) origin = '*';
66
67 if (!!origin && typeof(this._origins) == 'function') return this._origins(origin, fn);
68 if (this._origins.indexOf('*:*') !== -1) return fn(null, true);
...
80 }
81 fn(null, false);
82 };

요청 헤더에 origin 값이 없기 때문에 61줄의 origin 변수는 undefied 다. 그런데 65줄에서 null 이나 undefined에 대한 처리가 없어서 67줄이 실행되지 않고 68줄로 넘어가니 this._origins 는 예제에서 지정한 함수니까 indexOf를 했을 때 TypeError 가 발생할 수 밖에 없다.

해당 문제를 발견후 간단하게 undefined 인지 여부를 확인하도록 하고 Pull Request를 보냈는데, 내 것 대신 다른 개발자의 Pull Request가 merge 되었다. 그 이유는 내가 보낸 Pull Request에는 단위 테스트가 없었기때문이 아닐까 짐작해본다. 아무리 단순한 것이라도 단위 테스트로 검증을 한 것이 올바른 방법이었다.

Socket.IO 1.3.2 버전이  1월 19일 릴리즈되었고, 이 버전에 해당 수정이 포함되어있다.

참고

Hibernate 4.3 Statement Warning 문제

Naver Pinpoint를 테스트하기 위해 프로젝트의 트랜잭션을 확인하던 중 이상한 것을 발견했다.

Hibernate 4.3 Statement Warning
Naver Pinpoint CallStack Sample

코드 상에 없는 SHOW WARNINGS 라는 질의가 실행된 것이다.

디버그 모드로 원인을 찾아 보니 Hibernate 4.2 버전과는 다르게 Hibernate 4.3에서는 Statement 를 닫을 때 SqlExceptionHelper#logAndClearWarnings(Statement) 를 호출하도록 되어 있다
(4.2에서도 해당 메소드는 있지만 임시 테이블을 만드는 작업을 할 때만 호출한다).

해당 메소드를 보면 다음과 같다:

@SuppressWarnings({"ThrowableResultOfMethodCallIgnored"})
public void handleAndClearWarnings(
 Statement statement,
 WarningHandler handler) {
 // See HHH-9174. Statement#getWarnings can be an expensive call for many JDBC libs. Don't do it unless
 // the log level would actually allow a warning to be logged.
 if (LOG.isEnabled(Level.WARN)) {
 try {
 walkWarnings( statement.getWarnings(), handler );
 }
 catch (SQLException sqlException) {
 // workaround for WebLogic
 LOG.debug( "could not log warnings", sqlException );
 }
 }
 try {
 // Sybase fail if we don't do that, sigh...
 statement.clearWarnings();
 }
 catch (SQLException sqle) {
 LOG.debug( "could not clear warnings", sqle );
 }
}

로그 레벨이 WARN이 가능한 경우 walkWarnings(…)이 실행되고 이것은 Statement#getWarnings()를 호출하는데, MySQL의 경우 실질적으로 SQLError#convertShowWarningsToSQLWarnings(…) 이 실행된다. 이 메소드의 내부에는 다음과 같은 코드가 있어서 SHOW WARNINGS 질의를 실행한다.

/*
 * +---------+------+---------------------------------------------+ |
 * Level | Code | Message |
 * +---------+------+---------------------------------------------+ |
 * Warning | 1265 | Data truncated for column 'field1' at row 1 |
 * +---------+------+---------------------------------------------+
 */
warnRs = stmt.executeQuery("SHOW WARNINGS");

개발 및 CI 환경에서는 도움이 될 수 있겠지만 production 환경에서는 모든 Statement 를 닫을 때마다 문제가 있는지 확인하는 SQL이 실행되는 것은 바람직하지 않다.

production 환경에서 이것이 실행되지 않게 하려면 다음과 같이 로그 레벨을 ERROR로 올린다.

<log4j ...>
  <logger name="org.hibernate.engine.jdbc.spi.SqlExceptionHelper">
    <level value="ERROR" />
  </logger>
</log4j>