가끔 버그는 친절하지 않다.

분명히 고객이 겪은 건 “DB에 접속이 안 된다”는 문제였는데, 로그에는 전혀 다른 얼굴이 나타났다.

Expected to read 0xFF but got 0x0A

처음 보면 이런 생각이 든다.

“음… 우리 parser가 뭔가 잘못 읽었나?”

그런데 이번 사건의 재미있는 점은 이거였다.

parser가 이상한 게 아니라, MySQL이 처음 인사부터 실패 메시지를 보내고 있었다.

보통은 이렇게 인사한다

MySQL client가 server에 연결하면, server는 먼저 “안녕, 나는 이런 버전이고 이런 인증 방식을 지원해”라고 알려준다.

이걸 initial handshake라고 부른다.

아주 단순화하면 이런 흐름이다.

Client -> Server: 연결할게요
Server -> Client: 안녕하세요, 저는 MySQL 8.x이고 이런 기능을 지원해요
Client -> Server: 그럼 이 계정으로 로그인할게요
Server -> Client: OK 또는 실패

그래서 proxy 입장에서는 첫 번째 server packet을 보면 자연스럽게 이렇게 생각한다.

“아, server greeting이겠구나. handshake payload로 파싱해야지.”

기존 코드도 그렇게 동작했다.

Target MySQL 서버에서 첫 packet을 받으면 바로 InitialHandshakePayload.Create(...)로 넘겼다.

대부분의 정상 상황에서는 이게 맞다.

그런데 서버가 처음부터 “안 돼요”라고 하면?

문제는 MySQL 서버가 항상 예쁘게 인사하지는 않는다는 점이다.

예를 들어 Target DB의 connection 수가 꽉 찬 상태라면, MySQL은 정상 handshake packet 대신 이런 오류를 먼저 보낼 수 있다.

ERROR 1040 (HY000): Too many connections

즉, 첫 packet이 “안녕하세요”가 아니라 “지금 너무 바빠서 못 받아요”일 수 있다.

여기서 proxy가 이 packet을 정상 handshake라고 착각하면 어떻게 될까?

오류 packet을 greeting packet으로 억지로 읽으려 한다.

그러면 실제 원인은 DB connection limit인데, 로그에는 parser exception이 먼저 튀어나온다.

Expected to read 0xFF but got 0x0A

운영자 입장에서는 꽤 난감하다.

“Target DB가 바쁜 건가?”

“QueryPie proxy parser가 깨진 건가?”

“Agent timeout 때문인가?”

“connection pool 문제인가?”

원인이 하나로 좁혀지지 않는다.

이번 패치의 핵심: 인사인지, 화난 메시지인지 먼저 본다

이번 수정은 거창한 구조 변경이 아니다.

오히려 핵심은 아주 작다.

첫 packet을 받았을 때 바로 handshake로 파싱하지 말고, 먼저 물어본다.

“이거 혹시 MySQL ERR packet이야?”

흐름은 이렇게 바뀌었다.

Target MySQL 첫 packet 수신
        |
        v
ERR packet인가?
   | Yes
   v
ErrorCode / SQL State / Message를 로그에 남김
원본 ERR packet을 client에 그대로 전달
handshake 종료

   | No
   v
기존처럼 정상 initial handshake parsing 진행

코드 관점에서는 MySqlProxySession.HandshakeAsync()에서 첫 packet 수신 직후 ErrorPayload.IsError(protocol)을 먼저 확인하도록 했다.

ERR packet이면 ErrorPayload.Create(...)로 MySQL 오류 payload를 읽고, 로그에 이런 정보를 남긴다.

  • ErrorCode
  • SQL State
  • Message

예를 들면 이렇게 보인다.

MySQL initial handshake failed: target server returned ERR packet.
ErrorCode=1040, State=HY000, Message=Too many connections

그리고 중요한 점 하나.

원본 packet을 client에 그대로 돌려준다.

즉, client도 MySQL이 실제로 반환한 오류를 그대로 볼 수 있다.

ERROR 1040 (HY000): Too many connections

이건 작지만 꽤 중요한 차이다.

이제 문제의 중심이 “우리 parser가 왜 이상하지?”에서 “Target DB가 왜 connection을 못 받지?”로 바로 이동한다.

바꾸지 않은 것도 중요하다

이번 패치는 일부러 범위를 좁혔다.

바꾼 것:

  • MySQL initial handshake 직전의 ERR packet 선처리
  • Target DB 원본 오류 로그 명확화
  • 원본 ERR packet client 전달 유지
  • 회귀 테스트 추가

바꾸지 않은 것:

  • 정상 MySQL handshake 흐름
  • Agent timeout 기본값
  • Target DB의 max_connections
  • connection pool 정책
  • MySQL 외 다른 DB 모듈

버그 수정에서 “무엇을 안 바꿨는지”는 생각보다 중요하다.

장애 상황은 복잡하지만, 패치는 작아야 한다.

특히 proxy처럼 여러 protocol과 client/server 사이에 서 있는 코드는 더 그렇다.

테스트는 작은 packet 하나로 충분했다

이번 회귀 테스트는 실제 MySQL 서버를 띄우지 않아도 핵심을 검증할 수 있었다.

Too many connections를 나타내는 MySQL ERR packet payload를 만들어서 세 가지를 확인했다.

  1. 이 packet이 initial handshake parsing 전에 ERR packet으로 감지되는가?
  2. ErrorCode, State, Message가 보존되는가?
  3. 같은 packet을 정상 handshake로 파싱하면 기존처럼 실패하는가?

테스트 결과는 통과했다.

Failed: 0, Passed: 3, Skipped: 0, Total: 3

작은 테스트지만 의미는 분명하다.

“이 packet은 greeting이 아니다. error다.”

그 사실을 코드가 먼저 알아차리게 만든 것이다.

여기서 배운 점

이번 작업은 기능 추가라기보다 관찰 가능성 개선에 가깝다.

제품이 장애를 완전히 없애지는 못한다.

Target DB의 connection limit은 여전히 존재한다.

네트워크 장애도 생긴다.

timeout 설정도 운영 환경에 따라 다르다.

하지만 좋은 제품은 장애가 났을 때 엉뚱한 방향으로 사람을 보내지 않아야 한다.

이번 패치는 바로 그 부분을 고쳤다.

예전에는 실제 원인이 Target DB의 접속 거부인데도 내부 parser 오류처럼 보일 수 있었다.

이제는 MySQL이 처음부터 화가 나 있으면, 그 화난 이유를 그대로 보여준다.

Too many connections

이 한 줄이 있으면 운영자는 다음 질문으로 바로 갈 수 있다.

  • Target DB의 max connections가 충분한가?
  • 장시간 유지되는 session이 누적되고 있는가?
  • Agent timeout이 너무 길게 잡혀 있지는 않은가?
  • 특정 client가 connection을 과도하게 점유하고 있지는 않은가?

디버깅에서 좋은 로그는 답을 주는 것이 아니라, 다음 질문을 정확하게 좁혀준다.

마무리

이번 패치의 주인공은 거대한 아키텍처가 아니다.

첫 packet을 받은 직후의 작은 if문 하나에 가깝다.

하지만 그 작은 순서 변경이 장애 해석의 방향을 바꾼다.

정상 handshake로 읽기 전에, 먼저 error인지 확인하기.

사람 사이에서도 비슷하다.

상대가 인사하는지, 이미 화가 나 있는지 먼저 봐야 대화가 된다.

MySQL도 마찬가지였다.

처음 만났는데 벌써 화가 나 있다면, 억지로 인사말로 해석하지 말자.

그냥 이렇게 물어보면 된다.

“무슨 일이야?”

그리고 이번 패치는 MySQL의 대답을 드디어 제대로 듣게 만들었다.