블로그 이미지
JEEN

서울에 사는 꽃청년의 IT찌질모험기

Rss feed Tistory
IT/Perl 2008.04.20 12:57

[ 뒷북 && 삽질 경험기 ] RedHat 계열의 Perl Bug

 작년 중순 쯤에  RedHat 계열의 리눅스에서 Perl Package Bug가 보고되었고, 이에 따른 패치도 즉시 나왔던 적이 있습니다. 당시에는 뉴비이고 지금도 뉴비이지만, 패키지 소스의 문제까지 내다볼 능력이 없었던 저에게 사나흘의 시간은 너무 아깝더군요. 직접 당해보니까 말이죠.

 회사의 서버에서는 CentOS 4 - Perl 5.8.8 을 사용하고 있었는데요.
 아래는 어떤 스크립트를 돌렸을 때의 시간을 리포트 한 결과입니다.

사용자 삽입 이미지

Perl Patch를 때리기 전

사용자 삽입 이미지

Perl Patch 를 때리고 난 후


 대략 13분 정도 걸리는 스크립트가 10시간이 넘게 걸렸다.. 이런 얘기가 됩니다.
 그 원인이 무엇이냐고 하면...  RedHat 계열의 Perl Package에서 생기는 버그의 내용은...
 use overload 한 Package(여기서는 Perl의 package)를 bless 할 때의 CPU부하가 엄청나게 걸려서,
전체적인 처리 시간이 증가된다는 것입니다.

 실제 루프 카운트 한번에 0.25~ 0.7초라는 경이적인 속도를 보여주더군요. 총 루프횟수는 거의 50000번
정도 였구요. 이 처리를 위해서 담아둔 소스 데이터의 양은 300MB정도 됩니다. 소스 데이터의 갯수는
30개 정도 되구요. 생성되는 파일 또한 30개 정도 됩니다.

 이 처리에서 사용된 것은 DateTime 이라는 모듈인데요. 어떤 날짜를 보고 그 날짜로부터 몇 일 사이의
내용에 대해 출력하는 내용도 포함되어 있었던 것입니다. 바로 DateTime 자체가 overload 한 package를
bless 하는 것에 해당하는 것이었죠.
  혹시나 코드가 바뀌면서 버그가 있었는 가 의심해서 차츰차츰 예전의 리비젼으로 바꿔가면서 돌려봤지만
어지간히 시간은 그대로더군요. 나흘이전의 코드에서도 마찬가지로 너무 느려서 강제종료 시켜버렸습니다.

 문제는 소스가 되는 데이터도 바뀐 것이었는데... 나흘전에 다른 사람이 만들고 있던 처리에서 제가 사용하는
소스 데이터를 건드리는 게 있었거든요. 이전의 코드에서 문제가 없었던 이유는 DateTime을 사용할
조건에 부합하지 않았다는 것이었죠. 소스 데이터가 바뀌니까... 50000번 루프의 대부분이 그 조건에 부합되고
그에 따라서 처리시간은 784 -> 37419 로 바뀌어졌습니다. 생각해보면 사흘전에는 1200초 정도였군요. 조건이 부합되는 게 몇 건 밖에 없었으니까요..

 그럼 자신의 머신이 이런 문제가 있느냐 없느냐를 어떻게 간단하게 확인하냐 하면...
 
  http://blog.yappo.jp/yappo/archives/000515.html

 여기에 그 검증 코드가 있습니다. 일단 일본어 임에 주의하시구요.
 CentOS와 FreeBSD에서 검증 코드를 움직여 보면.. 그 결과의 차이에 대해서 어느 저도 파악하실 수 있습니다.
 그리고 그 차이를 절감하신다면... 패치를 하시면 됩니다. 물론 Perl 을 애용하시고, Perl 을 주로 쓰시는 분께 한해서 말이죠.
 
  물론 작년의 이슈이므로 제가 삽질한 것은 분명합니다.
  교훈은... Code의 문제 뿐 아니라.. 그 위아래의 레이어에 대해서도 알아야 되겠다는 것이죠.
  그나저나 DateTime은 없어서는 안될 좋은 모듈입니다 :-)
신고
TOTAL 483,766 TODAY 1

티스토리 툴바