Бойтесь буквы «M». Самый странный баг в моей жизни

Вечером в пятницу коллега, назовем его Мститель, спросил, не сталкивался ли я с проблемой, что route возвращает 400... но «если сменить название на сильно другое», то всё ок. Я сперва не обратил внимание на слово «сильно». Может быть, где-то дублируется регистрация этого рута? Или мститель перепутал GET и POST. Или какой-то баг в общем на создание хэндлеров?

Мистическая буква «М»

Утро понедельника началось с хождения по мукам. Убийства gradle-демонов. Обновление JDK. Чистый билд. Удаление кода авторизации. Возня с call logging. Дебаггер. Тщетно — нигде никаких логов об ошибке.

Мытарства длились пару часов до того, как Мститель выяснил удивительную закономерность:

Если в названии эндпоинта есть буква M - он не работает.

На кону стоял срыв релиза, поэтому приоритетом было решить проблему.

Используя git-bisect, Мститель нашел сломанный коммит — то было поднятие версий библиотек до «безопасных» по требованию безопасников. Самыми безопасными оказались эндпоинты с буквой «M».

Используя тот же бинарный поиск, откатывая по половине библиотек за синк гредла, Мститель нашел сломанную библиотеку — то была Netty codec http 4.1.129.Final.

Взяли версию свежее — и проблема решена. Фикс есть, начиная с 4.1.130.Final.

Мой методичный микроанализ

Я не мог это так оставить, и после работы полез разбираться, что не так с буквой «M».

Вот гитхаб-проект, чтобы воспроизвести проблему. Состоит только из указанной выше версии Netty codec и сервера с двумя ручками:

fun main() {
    embeddedServer(Netty, port = 8080) {
        routing {
            get("/hello") { call.respondText("ok", ContentType.Text.Plain, HttpStatusCode.OK) }
            get("/helloM") { call.respondText("ok", ContentType.Text.Plain, HttpStatusCode.OK) }
        }
    }.start(wait = true)
}

Запускаем сервис, кидаем curl:

curl -i localhost:8080/hello # ok
curl -i localhost:8080/helloM # 400

Чтобы быть fail fast, большинство библиотек валидируют URL перед роутингом. Если вы видели % в ссылках — это оно. Так и называется — percent-encoding. Что если спрятать «М» так, чтобы она уже была «заэнкожена»?

Percent-encoding использует только символы из ASCII. Находим в таблице hexadecimal «M» — это «4D».

Из википедии про percent-encoding:

Special characters are replaced with a percent sign (%) followed by two hexadecimal digits representing the character's byte value

curl -i localhost:8080/hello%4D # ok

Вот и подтвердили, что не работает валидация.

Мистическая буква... «J»!

Давайте сразу разберёмся, что еще не работает. Покидаем курлы по алфавиту:

for c in {A..Z}; do
  _path="/hello${c}"
  code=$(curl -s -o /dev/null -w "%{http_code}" "http://localhost:8080$\_path")
  echo "$code $_path"
done

# 404 /helloA
# 404 /helloB
# 404 /helloC
# 404 /helloD
# 404 /helloE
# 404 /helloF
# 404 /helloG
# 404 /helloH
# 404 /helloI
# 400 /helloJ
# 404 /helloK
# 404 /helloL
# 400 /helloM
# 404 /helloN
# 404 /helloO
# 404 /helloP
# 404 /helloQ
# 404 /helloR
# 404 /helloS
# 404 /helloT
# 404 /helloU
# 404 /helloV
# 404 /helloW
# 404 /helloX
# 404 /helloY
# 404 /helloZ

Видим два варианта ответа:

1. 404, когда эндпоинт не найден.

2. 400, когда у netty маразм.

Оказывается, не работает еще и буква «J». Очередной намёк, что Массоны и Иезуиты (Jesuits) правят миром.

Маниакально раскапываем проблему

Собираем сборку:

./gradlew installDist
# бинарь будет лежать в build/install/mmm/bin/mmm

Устанавливаем JAVA_TOOL_OPTIONS в значение для записи всех ошибок и запускаем:

export JAVA_TOOL_OPTIONS=-Xlog:exceptions=debug:file=logs/netty.log

./build/install/mmm/bin/mmm

Из другого таба терминала кидаем curl:

curl -i localhost:8080/helloM # 400

Убиваем процесс и в файле логов ищем ошибки валидации, которые мы предположили:

cat logs/netty.log | grep validat

Напечатается:

 thrown in interpreter method <{method} {0x0000000128e0c9d8} 'validateRequestLineTokens' '(Lio/netty/handler/codec/http/HttpVersion;Lio/netty/handler/codec/http/HttpMethod;Ljava/lang/String;)V' in 'io/netty/handler/codec/http/HttpUtil'>
[1.578s][debug][exceptions] Looking for catch handler for exception of type "java.lang.IllegalArgumentException" in method "validateRequestLineTokens"
[1.578s][debug][exceptions] No catch handler found for exception of type "java.lang.IllegalArgumentException" in method "validateRequestLineTokens"

Ищем validateRequestLineTokens прям в IntellijIDEA по символам — видим, что это netty-codec-http-4.1.129.Final.jar!/io/netty/handler/codec/http/HttpUtil.class:

static void validateRequestLineTokens(HttpVersion httpVersion, HttpMethod method, String uri) {
    if (method.getClass() != HttpMethod.class) {
        if (!isEncodingSafeStartLineToken(method.asciiName())) {
            throw new IllegalArgumentException(
                    "The HTTP method name contain illegal characters: " + method.asciiName());
        }
    }

    if (!isEncodingSafeStartLineToken(uri)) {
        throw new IllegalArgumentException("The URI contain illegal characters: " + uri);
    }
}

Внутри используется функция:

private static final long ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK = 1L << 'n' | 1L << 'r' | 1L << ' ';

public static boolean isEncodingSafeStartLineToken(CharSequence token) {
    int i = 0;
    int lenBytes = token.length();
    int modulo = lenBytes % 4;
    int lenInts = modulo == 0 ? lenBytes : lenBytes - modulo;
    for (; i < lenInts; i += 4) {
        long chars = 1L << token.charAt(i) |
                1L << token.charAt(i + 1) |
                1L << token.charAt(i + 2) |
                1L << token.charAt(i + 3);
        if ((chars & ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK) != 0) {
            return false;
        }
    }
    for (; i < lenBytes; i++) {
        long ch = 1L << token.charAt(i);
        if ((ch & ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK) != 0) {
            return false;
        }
    }
    return true;
}

Ставим брейкпоинты, запускаем проект в режиме дебага, кидаем curl с «M» и видим, что в нижнем цикле код вылетает с false, когда token.charAt(i) = M.

В спецификации Java читаем:

If the promoted type of the left-hand operand is long then only the six lowest-order bits of the right-hand operand are used as the shift distance... The shift distance actually used is therefore always in the range 0 to 63, inclusive.

63 в бинарной системе счисления — 0b111111.

Это значит, что побитовый сдвиг (оператор <<) на n будет не больше, чем сдвиг на 63 или n & 0b111111.

1L & 0  // 0
1L & 63 // 63
1L & 64 // то же что и  `1L & 0`   т.к. 64 & 63 = 0
1L & 77 // то же что и  `1L & 13`  т.к. 77 & 63 = 13

В коде мы видим long ch = 1L << token.charAt(i). 'M' — это 77, 'J' — 74.

long ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK = 1L << 'n' | 1L << 'r' | 1L << ' ';
// 4294976512L

(1L << 'M') & ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK
 // 8192

Вот так и получается false, из-за того, что разработчики не учли, что сдвиг на Long учитывает только 6 битов.

long ch = 1L << token.charAt(i);
if ((ch & ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK) != 0) {
    return false; // выходим из `isEncodingSafeStartLineToken` с `false`
}

Всё остальное, что не попадает в ILLEGAL_REQUEST_LINE_TOKEN_OCTET_MASK, не попадает случайно.

Может, 6 бит — мало для лонга?

Почему только 6 битов на сдвиг?

Long укладывается в 64 бита. То есть единицы и нули разложены на позициях от 0 до 63.
Эти 64 значения можно представить как 2^6 = 64. Как раз достаточно для того, чтобы учесть сдвиг на всю длину “лонга“.

Момент истины — фикс

В 4.1.130.Final проблему пофиксили (issue), вот как выглядит уже известный нам isEncodingSafeStartLineToken:

public static boolean isEncodingSafeStartLineToken(CharSequence token) {
    int lenBytes = token.length();
    for (int i = 0; i < lenBytes; i++) {
        char ch = token.charAt(i);
        // this is to help AOT compiled code which cannot profile the switch
        if (ch <= ' ') {
            switch (ch) {
                case 'n':
                case 'r':
                case ' ':
                    return false;
            }
        }
    }
    return true;
}

Момент итогов

Вот так вот Netty дал маху. Мелкие косяки — это нормально, но неожиданно видеть подобное от фреймворка вроде Netty. И было удивительно, что не получилось нагуглить проблему. Возможно, мы теперь единственные, кто знает о заговоре M & J.

Рад, что вы дочитали! Если не хотите прощаться и увидеть больше интересных фактов о букве «M» — заходите ко мне на канал.