어느 날, 모니터링 시스템에서 ‘SQLSyntaxErrorException’이 발생했다는 알림을 받았습니다. Exposed와 MySQL로 구성된 서비스에서 이스케이프(Escape) 문자열 처리와 관련된 문제가 발생한 것인데요. 4단계에 걸친 디버깅 과정을 거쳐 오류 로그를 분석한 끝에 Exposed가 문제의 원인이었음을 밝혀냈습니다. 에러 메시지를 발견했을 때 임시방편 해결책이 아닌, 근본적인 원인을 탐색하는 방법을 이 글을 통해 한 번 확인해 보세요!

안녕하세요, 카카오뱅크 홈 화면 서비스의 서버 개발을 담당하는 Issac입니다.

이 글에서는 JetBrains에서 제공하는 Exposed 오픈소스를 사용해 MySQL로 구성된 영속성 계층에서 발생한 Escape 문자열 처리 오류에 대한 경험을 공유하고자 합니다. 오류를 처음 접한 배경부터 이를 해결하기까지의 과정을 상세히 다룰 예정입니다.

개인적으로 개발 과정에서 문제를 만났을 때, 당장의 해결책을 찾기보다는 그 원인을 깊게 파헤치는 것을 즐깁니다. 이 글에서는 단순히 오류에 대응하는 것을 넘어서, 디버깅을 통해 근본적인 원인을 찾아가는 과정을 소개합니다. 글을 읽다 보면 자연스럽게 오류의 근본 원인을 찾는 방법과 디버깅하는 방법을 확인할 수 있습니다. 특히 Exposed 오픈소스를 사용 중이거나 도입을 고려 중인 분들, 그리고 디버깅을 통해 문제의 원인을 분석하는 방법이 궁금하신 분들에게 도움이 되길 바랍니다.

모니터링 시스템으로부터 날아 온 메세지 ✉️

Exposed를 잘 사용하던 어느 날

먼저 간단하게 Exposed를 사용한 배경에 대해 설명드리겠습니다. Exposed는 JetBrains사에서 만든 오픈소스 ORM(Object-Relational Mapping) 프레임워크로, Java에서 객체를 RDB(Relational Database, 관계형DB)에 매핑하기 위해 사용하는 JPA(Java Persistence API) 대신에 사용을 고려해볼 수 있습니다.

Exposed는 JPA에 비해 2가지 장점을 가지고 있습니다. 먼저, JPA를 사용하려면 JPA의 주요 요소인 트랜잭션 관리자(Transaction Manager), 엔터티 관리자(Entity Manager), 오류 표시(Error Marking) 등의 개념과 그 동작 원리를 이해해야 하기 때문에 약간의 러닝 커브가 있습니다.

두 번째 장점은 가벼움입니다. Exposed는 JVM 언어로 작성된 코드와 SQL문을 변환하는 역할만 담당하여 훨씬 가볍습니다. 이러한 장점들로 인해 저희를 포함한 카카오뱅크의 많은 개발자들이 Exposed를 개발에 적용하고 있습니다.

그러던 어느 날, 모니터링 시스템으로부터 낯선 오류 메세지를 받았습니다.

[FATAL]java.sql.SQLSyntaxErrorException: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '2024061016560885' at line 1

해당 서비스의 로그를 확인해보니, 사용자가 입력한 \ 문자를 데이터베이스에 INSERT 하려다가 SQLSyntaxErrorException이 발생하여 메세지가 날아온 것이었습니다. 곧 이어 Persist 역할을 수행한 코드로그에 찍힌 MySQL 쿼리를 살펴보니, 각각 다음과 같았습니다.

Post.upsert(
   onUpdate = {
       it.update(Post.content, stringLiteral(domain.content))
       it.update(Post.date, stringLiteral(domain.date))
   }
) {
   id[postId] = domain.postId
   it[content] = domain.content
   it[date] = domain.date
}
INSERT INTO POST(ID, CONTENT, DATE) 
VALUES (1, '\*/', '2024061016560885') AS NEW 
ON DUPLICATE KEY UPDATE 
CONTENT =  '\*/' , 
DATE =  '2024061016560885';

코드와 쿼리를 살펴보니, Exposed가 Escaping 처리를 하지 않고 있음을 확인할 수 있었습니다.

Exposed Github Issue를 확인해 보니..

왜 Exposed는 \문자를 처리하지 못한 걸까요? 🤔

그 원인을 찾기 위해 오픈소스로 공개되어 있는 Exposed Github 프로젝트로 이동하여 관련 내용을 파헤쳐 보기 시작했습니다. 우선 해당 현상이 이미 제보된 문제인지 확인하기 위해 Issues 페이지에서 Escape 관련 문제를 검색해보고 다음과 같은 이슈를 발견했습니다.

원문 내용을 요약하면, 다음과 같습니다.

  1. 한 개발자의 제보: “MySQL와 Exposed로 구성된 프로젝트에서 문자열 Escape 처리가 제대로 되지 않는 문제가 존재한다.”
  2. Exposed 개발자 입장: “Exposed에 DB별 의존성 넣고 싶지 않습니다.” (Exposed는 ‘단순 쿼리 빌더’로서의 역할만 가져간다.)
  3. 다른 개발자들이 등장해서 비슷한 불만을 공유: “SQL Injection 공격이 있었고, 자기 프로젝트가 방대하지 않았으면 Exposed를 바로 Spring Data나 다른 프레임워크로 바꿨을 것이다.”
  4. 처음 문제 제기한 사람이 재등장하여 다른 개발자의 경험을 자세히 물어보니 Escape 처리가 뭔가 이상함을 감지
  5. 로그에 남는 쿼리랑 실행되는 쿼리 차이가 존재한다. ✅

해당 이슈를 통해 ‘로그에 찍힌 쿼리와 실행되는 쿼리가 다를 수 있다’는 것을 발견하고, 이어서 실제로 실행된 쿼리가 무엇인지 찾아봤습니다.

원인 추적 🔍 (feat. 디버깅)

Step1. 실행되는 쿼리를 찾아보자

사용하는 IDE에서 디버거(Debugger)를 타고 들어가면, com.mysql.cj.NativeSessionexecSQL 메서드에서 실제 실행 쿼리를 날린다는 것을 알 수 있습니다. execSQL을 좀 더 들여다보면, query 변수에는 DB전용 명령어들(COMMIT, SET AUTOCOMMIT = TRUE, SET READONLY 등)이 전달되고, packet 변수에 실제 SQL문이 전달되는 것을 확인할 수 있습니다.

public <T extends Resultset> T execSQL(Query callingQuery, String query, int maxRows, NativePacketPayload packet, boolean streamResults,
ProtocolEntityFactory<T, NativePacketPayload> resultSetFactory, ColumnDefinition cachedMetadata, boolean isBatch) {
  ...
        try {
            return packet == null
                    ? ((NativeProtocol) this.protocol).sendQueryString(callingQuery, query, this.characterEncoding.getValue(), maxRows, streamResults,
                            cachedMetadata, resultSetFactory)
                    : ((NativeProtocol) this.protocol).sendQueryPacket(callingQuery, packet, maxRows, streamResults, cachedMetadata, resultSetFactory);

        } catch (CJException sqlE) {
          ...
        } catch (Throwable ex) {
          ...
        } finally {
          ...
        }

    }

packet 변수에 들어있는 실제 데이터베이스로 날아가는 쿼리는 다음과 같습니다.

INSERT INTO POST(ID, CONTENT, DATE)
VALUES (1, '\\*/', '2024061016560885') AS NEW
ON DUPLICATE KEY UPDATE
CONTENT =  '\*/' ,
DATE =  '2024061016560885';

이상하게도 INSERT 부분의 CONTENT 컬럼에는 Escape 처리를 해주고, UPDATE 부분의 컬럼에는 Escape 처리를 해주지 않았습니다. 왜 이렇게 Escape 처리가 되는지 확인하기 위해, 먼저 packet: NativePacketPayload이 만들어지는 곳을 찾아보았습니다.

Step2. NativePacketPayload를 만드는 곳은 어딜까?

다시 디버거를 통해 packet: NativePacketPayload를 만드는 부분을 찾아보니, com.mysql.cj.protocol.a.NativeMessageBuilderbuildComQuery 메서드에서 packet 변수에 들어갈 값을 만들고 있었습니다.

public NativePacketPayload buildComQuery(NativePacketPayload sharedPacket, Session sess, PreparedQuery preparedQuery, QueryBindings bindings,
            String characterEncoding) {
  ...
  byte[][] staticSqlStrings = preparedQuery.getQueryInfo().getStaticSqlParts();
  
  //bindValues = ["1" , "\*/", "2024061016560885"]
  for (int i = 0; i < bindValues.length; i++) {
    bindings.checkParameterSet(i);
    sendPacket.writeBytes(StringLengthDataType.STRING_FIXED, staticSqlStrings[i]);
    //escape 처리 해줌
    bindValues[i].writeAsText(sendPacket); 
  }
  
  //escape 처리 X
  sendPacket.writeBytes(StringLengthDataType.STRING_FIXED, staticSqlStrings[bindValues.length]); 
  ...
  }

이때 bindValues 에는 INSERT 쿼리 부분의 ID, CONTENT, DATE 값이 들어있습니다.

bindValues[i].writeAsText(sendPacket);

위의 코드를 디버거로 보면, com.mysql.cj.protocol.a.StringValueEncodergetBytes 메서드에서 Escape 처리된 결과값이 sendPacket에 들어갑니다.

@Override
public byte[] getBytes(BindValue binding) {
  ...
  if (isEscapeNeededForString(x, stringLength)) {
    String escString = StringUtils
        .escapeString(new StringBuilder((int) (x.length() * 1.1)), x, this.serverSession.useAnsiQuotedIdentifiers(), this.charsetEncoder)
        .toString();
    return StringUtils.getBytes(escString, this.charEncoding.getValue());
  }
  ...
}

쿼리의 나머지 부분은 staticSqlStrings 변수에 들어가고, 아래 코드를 통해 Escape 처리 없이 쿼리가 packet 변수에 들어가게 됩니다.

sendPacket.writeBytes(StringLengthDataType.STRING_FIXED, staticSqlStrings[bindValues.length]);
ON DUPLICATE KEY UPDATE
CONTENT =  '\*/' ,
DATE =  '2024061016560885';

위 2개를 종합하면 다음과 같은 쿼리가 만들어집니다.

INSERT INTO POST(ID, CONTENT, DATE) 
VALUES (1, '\\*/', '2024061016560885') AS NEW 
ON DUPLICATE KEY UPDATE 
CONTENT =  '\*/' , 
DATE =  '2024061016560885';

정리하면, MySQL에서는 쿼리 패킷을 만들때 bindingValues는 사용자의 입력값(Value)이기 때문에 Escape 처리를 해주고, staticSqlParts는 순수 문자열(Plain text)이기 때문에 Escape 처리를 안해주고 있습니다. 조금 더 들여다보면, INSERT or UPDATE 구문의 INSERT 부분의 값들은 bindingValues에 들어가기 때문에 Escape 처리가 되고 있고, UPDATE 부분의 값들은 staticSqlParts에 들어가기 때문에 Escape 처리가 안되고 있습니다.

그럼 이어서 staticSqlParts를 어떻게 만드는지 찾아보겠습니다. staticSqlParts는 preparedQuery의 QueryInfo 클래스에서 가져오고 있습니다. 여기서 등장한 QueryInfo 클래스가 어디서 만들어지는지 확인해 보겠습니다.

byte[][] staticSqlStrings = preparedQuery.getQueryInfo().getStaticSqlParts();

Step3. QueryInfo가 만들어지는 곳은 어딜까?

디버거로 QueryInfo를 따라가면, com.mysql.cj.QueryInfo의 생성자에서 bindingValuesstaticSqlParts를 만드는 것을 확인할 수 있습니다. 코드를 분석해보면, staticSqlParts에 들어가는 쿼리를 ?, ; 문자 단위로 자르고 있습니다.

public QueryInfo(String sql, Session session, String encoding) {
  ...
  if (currChar == '?') { 
    ...
  } else if(currChar == ';') { 
    ...
  }
}

QueryInfo 생성자의 staticSqlParts 파라미터(Parameter)에 들어온 쿼리를 보면 다음과 같습니다.

INSERT INTO POST(ID, CONTENT, DATE) 
VALUES (?, ?, ?) AS NEW 
ON DUPLICATE KEY UPDATE 
CONTENT =  '\*/' , 
DATE =  '2024061016560885';

MySQL에서는 변수를 ?로 구분하고 있기 때문에 UPDATE 구문의 변수들을 Escape 처리하려면, 쿼리는 다음과 같이 전달되야 합니다.

INSERT INTO POST(ID, CONTENT, DATE) 
VALUES (?, ?, ?) AS NEW 
ON DUPLICATE KEY UPDATE 
CONTENT =  ? , 
DATE =  ?;

쿼리가 잘못 전달되고 있으니, QueryInfo에 쿼리를 넘겨주는 곳을 이어서 디버거로 찾아보았습니다.

Step4. QueryInfo에 넘겨주는 쿼리는 어디서 만들어질까?

디버거로 확인해 보니, org.jetbrains.exposed.sql.vendors.MysqlFunctionProviderupsert 메서드에서 UPDATE 부분의 쿼리가 만들어지고 있었습니다.

override fun upsert(
        table: Table,
        data: List<Pair<Column<*>, Any?>>,
        expression: String,
        onUpdate: List<Pair<Column<*>, Any?>>,
        keyColumns: List<Column<*>>,
        where: Op<Boolean>?,
        transaction: Transaction
    ): String {
        ...
        return with(QueryBuilder(true)) {
            +insert(false, table, data.unzip().first, expression, transaction)
            if (isUpsertAliasSupported(transaction.db.dialect)) {
                +" AS NEW"
            }

            +" ON DUPLICATE KEY UPDATE "
            onUpdate.appendTo { (columnToUpdate, updateExpression) ->
                append("${transaction.identity(columnToUpdate)}=") //here
                registerArgument(columnToUpdate, updateExpression)
            }
            toString()
        }
    }

여기서 append("${transaction.identity(columnToUpdate)}=") 부분을 따라가보면, org.jetbrains.exposed.sql.QueryBuilderregisterArgument 메서드에서 넘겨 준 인자 유형(Argument Type)에 따라 그대로 쿼리 조건에 추가(Append) 할지 또는 ? 로 추가하고 파라미터에 등록할지를 결정하고 있습니다.

이때 UPDATE 부분의 인자는 Expression 타입이기 때문에 그대로 추가되고 있습니다.

fun <T> registerArgument(column: Column<*>, argument: T) {
        when (argument) {
            //here
            is Expression<*> -> append(argument) 
            DefaultValueMarker -> append(TransactionManager.current().db.dialect.dataTypeProvider.processForDefaultValue(column.dbDefaultValue!!))
            else -> registerArgument(column.columnType, argument)
        }
    }

다시 처음으로 돌아가서, INSERT or UPDATE하는 부분의 DSL(Domain Specific Language)을 보면 onUpdate 부분에는 UPDATE를 할 때, 변경시킬 컬럼과 값을 지정합니다. 이때 지정하는 값이 ‘Expression 타입’으로 넘어갔기 때문에, Escape 문제가 생긴 것을 알 수 있습니다.

Post.upsert(
    onUpdate = {
        it.update(Post.content, stringLiteral(domain.content))
        it.update(Post.date, stringLiteral(domain.date))
    }
) {
    id[postId] = domain.postId
    it[content] = domain.content
    it[date] = domain.date
}

하지만 update 메서드의 시그니처(Signature)를 보면, 모두 Expression 타입의 변수만 인자로 받고 있습니다.

open fun <T, S : T?> update(column: Column<T>, value: Expression<S>) {
    checkThatExpressionWasNotSetInPreviousBatch(column)
    values[column] = value
}

/** Updates the mapping of the specified [column] with the value of the provided expression. */
open fun <T, S : T?> update(column: Column<T>, value: SqlExpressionBuilder.() -> Expression<S>) {
    update(column, SqlExpressionBuilder.value())
}

이제 근본 원인을 찾았습니다.

1. upsert DSL의 INSERT 부분에는 값, UPDATE 부분에는 Expression 타입만 인자로 허용
2. MySQL Connector로 쿼리를 넘길 때, 값 부분은 ?로 전달하고, Expression 타입 부분은 순수 문자열(Plain text)로 전달
3. MySQL은 Native 쿼리를 만들때, ? 부분은 Escape 처리하지만, 순수 문자열 부분은 Escape 처리하지 않음

이를 간단하게 하나의 그림으로 정리하면 다음 [그림 1]과 같습니다.

1-trouble-shooting-summary-image
[그림 1] 문제 해결 과정 한 판 정리본

더 좋은 해결책을 위한 고민

근본 원인을 찾고 나서, 해결 방법을 고민해봤습니다. 이때 떠오른 해결 방법 3가지는 다음과 같습니다.

1. DSL에서 stringLiteral(value)에 값을 할당하기 전, Escape 처리
2. INSERT or UPDATE 부분을 JPA처럼 변경: SELECT & (INSERT or UPDATE)
3. Exposed에 이슈 제보: UPDATE 시 Expression 타입 말고, 값도 넘길 수 있게 수정 요청

1번 해결책은 가장 직관적일 수 있지만, Escape 처리가 필요한 부분을 발견할 때마다 개발자가 수작업으로 Escape 처리해야 하는 번거로움이 있습니다. 또한, Escape 처리가 필요한 부분을 알지 못하는 개발자가 프로젝트를 맡게 되면 누락될 위험이 있습니다. 매번 DSL로 코드를 작성할 때마다 Escape 필요 여부를 판단하는 것은 현재뿐만 아니라 미래의 요구사항까지 고려해야 하는 어려운 일입니다. 이러한 이유로 1번 해결책은 기각되었습니다.

2번 해결책도 1번과 비슷한 한계점을 가집니다. 지금으로서는 upsert 메서드를 사용하는 부분을 모두 제거한다고 해도, 나중에 Escape 처리 이슈와 관련된 히스토리를 모르는 개발자가 해당 프로젝트에서 개발을 한다면 upsert 메서드를 사용하고 동일한 오류를 반복할 수 있다는 단점을 지닙니다.

3번 해결책은 위의 2가지 해결책 대비 가장 확실한 해결책입니다. 하지만 Exposed 오픈소스를 관리하는 측에서도 이를 수용하고 수정 개발을 진행해야 하므로, 실제 버전에 반영되기까지는 시간이 오래 걸릴 수 있습니다.

우리가 채택한 방법 👉 3번!

위의 3가지 해결 방법을 두고, 팀원들과 상의한 끝에 최종적으로 3번을 채택했지만, 우선은 2번으로 Workaround 처리하기로 했습니다. 단, 2번 해결책은 초당 처리되는 쿼리의 수(Queries Per Second, 이하 QPS)가 늘어나거나, 동시성 문제가 생길 수 있으므로 주의해야 됩니다. 사내 DBA분들을 통해서 QPS에 문제가 없음을 확인했고, 동시성 문제는 앞단의 다른 단계에서 일어나지 않게 만드는 작업이 보장되도록 했습니다.

그래서, 다음과 같이 SELECT를 먼저 진행한 한 뒤에 INSERT or UPDATE 하도록 DSL을 변경해주었습니다.

val postId: Long? = Post.selectAll()
    .andWhere { Post.postId eq domain.id }
    .firstOrNull()
    ?.getOrNull(Post.postId)

 if (postId == null) {
    Post.insert {
        it[postId] = id
        it[content] = domain.content
        it[date] = domain.date
    }
} else {
     Post.update({ Post.postId eq domain.id }) {
         it[content] = domain.content
         it[date] = domain.date
    }
}

이제 드디어 고객이 작성한 '\*/' 문자를 포함한 텍스트도 문제 없이 데이터베이스에 저장할 수 있게 되었습니다. 🎉

마무리하며

개발자로서 저의 하루는 수많은 도전과 문제들로 가득 차 있습니다. 때로는 너무나 복잡해 보이는 문제들에 직면해 좌절감을 느낄 때도 있습니다. 하지만 그럴 때일수록 중요한 것은 당황하지 않고 차근차근 하나씩 문제를 해결해 나가는 자세인 것 같습니다. 특히 문제를 작은 단위로 나누고, 세밀하게 분석하는 과정에서 비로소 해결의 실마리를 찾을 수 있습니다. 이러한 과정을 통해 우리는 더 깊이 있는 이해와 더 나은 해결책을 마련할 수 있게 됩니다. 저도 항상 노력하는 부분이고, 때로는 ‘임시방편책 만으로도 충분하지 않나?‘라는 생각이 들 때가 있지만, 그럴 수록 더 집요하게 근본 원인을 파악했던 노력들이 제가 만든 서비스를 더 확장시키고 안정적으로 운영하는데 도움이 되었던 것 같습니다.

또한, 문제 해결하는 과정은 단지 기술적인 능력뿐만 아니라 팀워크와 커뮤니케이션의 중요성도 부각시켜 줍니다. 개발을 하면서도 항상 느끼는 부분이지만, 우리는 혼자서 모든 것을 해결할 수 없으며, 동료들과의 협업을 통해 더 많은 아이디어를 도출하고, 더 창의적인 해결책을 찾아낼 수 있습니다. 저도 혼자서 문제를 붙잡고 깊게 탐구한 시간도 있었지만, 해결책을 도출하고 더 좋은 해결책이 무엇인지 고민하는 과정에서 주변 동료와 저와 비슷한 문제를 먼저 겪어본 선배 개발자들로부터 많은 도움을 받았습니다.

오늘도 풀리지 않는 오류의 실마리를 찾아 고군분투하는 개발자 분들에게 짧은 응원의 메세지를 건네며, 이 글을 마무리하도록 하겠습니다.

아무리 복잡한 문제라도 차근차근 하나씩 해결해 간다면 거의 모든 문제를 해결할 수 있을거라 믿습니다. 화이팅! 💪