Hyun

Version

1. Spark : 1.6.3
2. hdfs : 2.7.3
3. Hive : 1.2.1

기분좋게 휴가를 다녀왔더니 집계 메일이 와있어 호다닥 이슈를 확인해 봤다.

실패한 Spark 집계 및 상당히 느려진 Spark 집계... 당혹스러웠다.

Spark UI를 확인하면 아래와 같다.

분명 집계 개선을 하여 3분대로 낮춰놨는데, 당혹스럽게 위 사진과 같이 불필요한 wait 시간이 29분이나 되는 것을 확인할 수있다. total Uptime과 비교하면 실직적으로 집계를 수행한 시간은 1분 남짓인데, 기다린 시간이 29분인 것을 보니 상당히 큰 이슈였다.

그래서 Hadoop Application 에서 로그를 확인해 보니 아래와 같은 문제가 발생하였다.

ERROR Hive: org.apache.thrift.transport.TTransportException: java.net.SocketTimeoutException: Read timed out
    at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:129)
    at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
    ...
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    ... 134 more

내부망으로 DataNote 통신을 하는데 TimeOut인 것은 뭔가 문제가 있어보였다.

다른 문제점이 무엇이 있는지 확인할 겸 Ambari를 확인해보니, HiveMetastore에 Alert가 발생하였다 .

        Metastore on ambariserver.coresight.com failed (Traceback (most recent call last):
  File "/var/lib/ambari-agent/cache/common-services/HIVE/0.12.0.2.0/package/alerts/alert_hive_metastore.py", line 203, in execute
    timeout_kill_strategy=TerminateStrategy.KILL_PROCESS_TREE,
  File "/usr/lib/python2.6/site-packages/resource_management/core/base.py", line 166, in __init__
    self.env.run()
  File "/usr/lib/python2.6/site-packages/resource_management/core/environment.py", line 160, in run
    self.run_action(resource, action)
  File "/usr/lib/python2.6/site-packages/resource_management/core/environment.py", line 124, in run_action
    provider_action()
  File "/usr/lib/python2.6/site-packages/resource_management/core/providers/system.py", line 262, in action_run
    tries=self.resource.tries, try_sleep=self.resource.try_sleep)
  File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 72, in inner
    result = function(command, **kwargs)
  File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 102, in checked_call
    tries=tries, try_sleep=try_sleep, timeout_kill_strategy=timeout_kill_strategy)
  File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 150, in _call_wrapper
    result = _call(command, **kwargs_copy)
  File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 297, in _call
    raise ExecuteTimeoutException(err_msg)

내용을 보아하니 대충 Metatore에 문제가 발생하였다는 것을 볼 수 있다.

그럼으로 해당 문제를 확인하기 위해 (Hortnworks기준) /var/log/hive/hivemetastore.log 를 확인해 보니 아래와 같은 엄청난 것을 볼 수 있었다.

위와 같은 충격적인 Log를 확인하고, Error문구를 확인하니 아래와 같았다.

com.mysql.jdbc.PacketTooBigException: Packet for query is too large (1048964 > 1048576). You can change this value on the server by setting the max_allowed_packet' variable.
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3279)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1971)
        ...

에러 문구를 보니 설정한 max_allowed_packet 보다 많은 양의 packet보내 문제가 발생하였다는 것이였다.

필자는 mysql 을 5.1버전을 사용하고 있는데, Default값이 1MB인지, Hortenworks의 Default값인지 정확하게 확인은 하지 않았지만, 상대적으로 낮은 사이즈로 설정되어있었다. (5.7 버전의 Default값은 4MB였다.)

이것을 해결 하는 방법은 여러가지가 있겠지만, 필자가 생각하는 방법은 2가지가 있다.

1. 더 작은 패킷을 보낸다

   • 사실상 원하는 해결책이 아님

2. max_allowed_pachet을 늘린다.

   1. 당장 바꾸고 싶다면 아래와 같이 하면 된다

       SET GLOBAL max_allowed_packet = 33554432;        
       FLUSH PRIVILEGES;        
       show variables where Variable_name = 'max_allowed_packet';

   2. /etc/my.cnf 에 max_allowed_pachet 추가해줌

       [mysqld]
       datadir=/var/lib/mysql
       socket=/var/lib/mysql/mysql.sock
       user=mysql
       # Disabling symbolic-links is recommended to prevent assorted security risks
       symbolic-links=0
       max_allowed_packet=32M

      • 굳이 32MB일 필요는 없다

   3. mysql을 재시작 해주면된다.

여러가지 문제를 경험해야 많은 것을 배울 수 있는 것 같다.

만약 설정된 max_allowed_packet가 1MB가 아니여서 위와 같은 Error가 발생하지 않았다면,
회사에서 5년치 데이터를 한번에 읽어 처리하여 Pachet량이 1mb를 넘기지 않았다면 필자는 해당 문제를 경험하지 않아 고민을 하지 않았을 것 같다.

물론 문제가 발생하여 짜증은 났지만, 해결한 현재는 좋은 경험이였다고 생각한다.