Оптимизация производительности SOAP сервиса

Перейти к концу метаданных

• Добавлено Литвинов Андрей, последняя редакция Литвинов Андрей 27.09.2012  (просмотреть изменение)

Переход к началу метаданных

Как правило в начале проекта реализуется основная логика из расчета чтобы работало то, что требует клиент и хотя бы для одного подключения. По мере реализации бизнес-логики начинают обращать внимание на скорость работы, возможность одновременного подключения. Тут приходит первый этап переделки проекта. Вдруг выясняется, что проект не работает в параллельном режиме. Второй пользователь блокируется до обработки первого. Эта проблема решается быстро так как возникает еще на этапе разработки и может быть замечена самими разработчиками. Второй этап - вдруг выясняется, что на тестовой системе где велась начальная разработка все работало быстро, а на БД с большим объемом данных(я бы сказал огромным)  все тормозит и можно сказать не работает. Это уже более сложная задача - надо переделывать чуть больше, но тоже решается на стадии разработки. Далее наступает третий этап - установка в рабочий режим. Тут выясняется, что приложение не достаточно быстрое. Клиенты жалуются на скорость и разработчики понимают что надо бы как-то померить эту скорость. Иметь не просто жалобы клиентов, а реальный механизм замера производительности. Механизм добавляется и видна печальная картина. Все жутко тормозит по непонятной причине в местах где это не должно происходить. Вот тут и начинается самое интересное для тех кто любит программировать. Надо понять в какой библиотеке, в каком месте все тормозит.

Данная статья передает опыт оптимизации java приложения на третьем этапе оптимизации. В данной статье идет речь про оптимизацию на строне java. Оптимизация на строне БД тоже должна выполняться, но эта тема выходит за рамки данной статьи.

По данным из таблицы видно, как плохо работало приложение до оптимизации и как все изменилось после.

Время выполнения операций, мс	после оптимизации	до оптимизации
0	47,2%	-
0-50	44,1%	-
50-200	5,4 %	1%
200-1000	3,2%	95,2%
1000-3000	0,1	3,6%
3000-10000	-	0,1%
>10000	-	0,1%

также были улучшены характеристики подключения веб приложения к серверу Oracle за счёт использования и настройки пула подключений.

Основные методы оптимизации:
1. Настройка soapUI тестов, проведение нагрузочного тестирования, оценка результатов
2. Логирование производительности операций
3. Определение и устранение “узких” мест и ошибок системы

Можно оптимизировать разные ключевые показатели - количество транзакций в единицу времени и время отклика. Как правило пользователей интересует время отклика. Прежде чем улучшить производительность, её необходимо измерить. Для измерения удобно настроить проект soapUI, составить TestCase из примерно десятка операций чтения(нас интересует передача данных между БД и java, поэтому нагружать БД записью чего-то в данном случае нет смысла) и создать на их основе нагрузочный тест “LoadTest”. Запустив нагрузочный тест на 20 минут (1200 сек), например 50 потоков в стратегии “simple” можно зафиксировать первые результаты: 

1. Кол-во выполненных операций
2. Время выполнения операций
3. Кол-во ошибок

Далее, определяя и устраняя “узкие” места и ошибки в системе можно сравнивать с первоначальными результатами. Также желательно прогнать тест на кол-ве потоков, которое установлено или предполагается на боевом сервере. По умолчанию в Tomcat кол-во потоков = 200, но из за слабости тестовых серверов и ограничений на кол-во подключений к серверу Oracle на тестовых инстанциях оптимальным можно указывать 150 потоков в нагрузочном тесте soapUI.
Для ориентира, приемлемым на данный момент является выполнение несложных операции в JVM за десятки миллисекунд.

Содержание:

1. Немного теории
1.1. Кластеризация сервера приложения
1.2. Характеристики работы серверов и реалистичность тестирования

2. Методы оптимизации производительности веб приложения
2.1. Использование серверной версии JVM
2.2. Использование соответствующей версии OJDBC драйвера
2.3.Использование APR библиотеки для Apache Tomcat
2.4. Определение использования памяти
2.5. Оптимизация производительности JaxB при логировании операций в многопоточной среде
2.6. Логирование производительности операций
2.7. Настройка пула подключений к серверу Oracle
2.8. Настройка лога производительности системы

1. Немного теории

1.1. Кластеризация сервера приложения

Если после оптимизации, утилизация процессорного времени сервером Tomcat, на предоставленном боевом сервере, достигла порога более 70%, то стоит рассматривать возможность кластеризации сервера приложения.

Когда интенсивность запросов мала, время отклика практически равно времени обслуживания. Если в систему начинает поступать больше запросов, образуется очередь на обслуживание, и время отклика возрастает. С определенного уровня интенсивности поступления запросов время ожидания в очереди, а с ним и время отклика, начинают стремительно расти, а производительность системы — падать. Для современных компьютерных систем с процессорной SMP-архитектурой такой точкой считается уровень утилизации их ресурса в 70 — 80 %.

  

Для сервера Oracle например, из теории очередей и наблюдений известно, что время ожидания составляет около 10% времени отклика, даже если коэффициент утилизации CPU не превышает 70%. Это может оказаться очень тревожным фактором, если система работает при загрузке около 90%. (Кстати, при нагрузке в 90% время ожидания превышает 46% времени отклика!)

1.2. Характеристики работы серверов и реалистичность тестирования

(выдержка из http://stem.osp.ru/os/2002/12/182266/) 

Серверы в Сети — типичные системы массового обслуживания, обрабатывающие поток заявок, поступающих в случайные моменты времени. Системы состоят из некоторого числа обрабатывающих единиц — каналов обслуживания. В качестве заявок выступают пользовательские запросы. Пропускная способность системы массового обслуживания зависит от числа каналов и их производительности, а также, что особенно важно для реалистичности тестирования, от характера потока заявок.

Надежность характеризуется вероятностью отказа в обслуживании, а производительность можно измерить либо числом обработанных в единицу времени запросов, либо временем, затрачиваемым на обработку одного запроса. Для оценки качества обслуживания более содержательны временные характеристики — среднее время обработки и дисперсия времени обработки. Наибольшую значимость эти характеристики приобретают в случаях, когда предельное время обработки фиксировано, как, например, для систем резервирования билетов, электронной коммерции, разнообразных банковских приложений и т.д.

Важную информацию предоставляет также анализ зависимости между интенсивностью входного потока запросов и числом обработанных запросов в единицу времени. Можно выделить три фазы этой зависимости: линейный рост производительности, отклонение от линейности и насыщение. На первой фазе среднее число обрабатываемых запросов в единицу времени линейно возрастает с увеличением нагрузки, среднее время обработки запроса постоянно. На второй фазе рост производительности уменьшается с ростом нагрузки, среднее время обработки увеличивается. На фазе насыщения роста производительности не происходит, время обработки с увеличением нагрузки неограниченно растет. 

  На форму зависимости пропускной способности от нагрузки влияют: конфигурация оборудования, параметры операционной системы (число нитей управления, размер файла подкачки) и настройки самого приложения. Исследование вида этой зависимости позволяет выявить факторы, оказывающие наибольшее воздействие на производительность, а также обнаружить недостатки проектирования и разработки серверного приложения.

2. Методы оптимизации производительности веб приложения

2.1. Использование серверной версии JVM

Убедиться что используется серверная JVM

 MonitorTomcat / закладка Java / поле java virtual machine должно содержать серверную версию JVM. Например: C:\Program Files (x86)\Java\jdk1.6.0_24\jre\bin\server\jvm.dll

2.2. Использование соответствующей версии OJDBC драйвера

Важно использовать версию драйвера соответствующую используемой версии сервера Oracle. Например для версии сервера БД Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Prod

тестировались следующие драйвера (нагрузочное тестирование 50 потоков без ошибок 30 мин):

1. ojdbc14-10.2.0.4.0.jar (6465 выполнений и 3,59 tps)  + 10% выполненных запросов относительно ojdbc14-10.2.0.3.0.jar
2. ojdbc14-10.2.0.3.0.jar (5888 выполнений, 3,26 tps)
3. ojdbc6.jar наихудший вариант для данного случая

ojdbc14-10.2.0.3.0.jar при всех прочих одинаковых не тормозит относительно ojdbc6.jar и  GC(сборщик мусора Java) забирает 3%  CPU против 35% на ojdbc6.jar

Узнать версию Oracle можно выполнив скрипт:

select * from v$version
where banner like 'Oracle%'; 

вернёт текст, например:

Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Prod

Взять соответствующий драйвер

o:\Dist\Oracle JDBC\

или скачать http://www.oracle.com/technetwork/database/features/jdbc/index-091264.html 

при необходимости сделать бэкап предыдущего драйвера и скопировать в папку

C:\Program Files (x86)\Apache Software Foundation\Tomcat 6.0\lib\

новый драйвер, например

ojdbc14-10.2.0.4.0.jar

2.3.Использование APR библиотеки для Apache Tomcat

При установке Tomcat следует включать установку APR native.dll. Если при установке не было выбрана данная опция, можно скачать с официального сайта: http://tomcat.apache.org/download-native.cgi 

После старта сервера Tomcat в логе в начале должна быть строка:

INFO: Loaded APR based Apache Tomcat Native library 1.1.22.

2.4. Определение использования памяти

Следует определить размер используемой памяти приложением, для этого необходимо добавить в Monitor Tomcat/Java Options:

 -Dcom.sun.management.jmxremote=true
-Dcom.sun.management.jmxremote.port=9090
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false

 Это позволит подключиться с помощью стандартной утилиты VisualVM для мониторинга работы сервиса в режиме реального времени. 

При большом и часто повторяющемся значении параметра GC activity, следует увеличить максимальный доступный размер памяти для JVM, а при необходимости перейти на использование Tomcat x64, тогда можно будет разрешить серверу Tomcat использовать более 1,5 Гб оперативной памяти. Также можно учесть, что увеличение максимально доступного размера памяти для JVM проблема плохой производительности вряд ли решится. Утечка памяти может указывать на блокировку потоков и/или о не освобождении ресурсов.

2.5. Оптимизация производительности JaxB при логировании операций в многопоточной среде

Неотъемлемой частью функционирования веб-сервисов является сохранение данных в лог при выполнении операций, при котором необходимо преобразование из Java бизнес объектов в их XML представление для записи в лог. Для этого используется JaxB (Java Architecture for XML Binding). Для выполнения процесса преобразования необходимо произвести несколько действий:

1. cоздать JAXBContext для конкретного бизнес класса, объект которого требуется преобразовать (маршализовать)
JAXBContext jaxbContext = JAXBContext.newInstance(clazz);
где clazz - полное наименование класса бизнес объекта, например: “com.colvir.modules.ibank.service.data.customer.Account”

2. создать маршалер, объект который может выполнить преобразование бизнес объекта из 
Marshaller marshaller = jaxbContext.createMarshaller();

3. выполнить маршалинг (преобразование)
marshaller.marshal(
                   new JAXBElement<Object>(new QName("http://colvir.com/modules/ibank/service/data", "data"),
                           (Class<Object>) businessObject.getClass(),businessObject), out);
где businessObject - бизнес Java объект содержащий данные,
out - выходные данные в формате строки XML

Действие №1 трудоёмкое и занимает много процессорного времени (сотни миллисекунд), поэтому следует создать по одному JaxBContext  для каждого класса бизнес объектов и использовать их в дальнейшем избегая повторного создания. 

Маршалер и демаршалер не являются потокобезопасными в отличии от JaxBContext. Поэтому их использование требует синхронизации для исключения ситуации блокировки потоков, при которой 2 или более потоков пытаются выполнить действия 2 и 3 для одного и того же класса бизнес объекта. Синхронизации можно достигнуть использованием критической секции:

 synchronized (this) {
               Marshaller marshaller = jaxbArtifactsHolder.getMarshaller();
               marshaller.marshal(
                   new JAXBElement<Object>(new QName("http://colvir.com/modules/ibank/service/data", "data"),
                           (Class<Object>) result.getClass(), result), out);
           }

Первый поток, который занял критическую секцию, будет выполнять действия 2 и 3 с гарантией, что никакой другой поток ему не помешает и не будет выполнять действия 2 и 3 одновременно с первым потоком. Другие потоки будут синхронно по очереди пользоваться критической секцией, не мешая друг другу.

Действие №3 занимает сравнительно небольшое время (порядка 0мс), но при огромном количестве мелких документов желательно маршалинг проводить не синхронно по очереди (см. выше), а использовав пул маршалеров:

• статья: http://blog.zont.eu/2012/02/jaxb-and-commons-pool.html 
• исходники: http://www.zont.eu/published/jaxbpool.zip 

Таким образом автор статьи обещает увеличить производительность данного кода в 14 раз, в нашем случае 0мс/14 = 0мс.

Оптимизация производительности JaxB при логировании позволила сократить время отклика сервиса с 200мс-500мс до десятков миллисекунд. Обнаружена данная проблема была при помощи инструментирующего профайлера CPU утилиты VisualVM входящего в состав JDK.

  

Для подключения к Tomcat для профайлинга, необходимо запустить Tomcat в консольном режиме, под пользователем, под которым запускается VisualVM.

2.6. Логирование производительности операций

Хорошей практикой можно считать настройку логирования производительности операций в csv формате, для удобного анализа в MS Excel также при помощи сводных диаграмм. Файл не содержит конфиденциальной информации и поэтому банк легко пошлет нам его с боевой системы. Формат записи лога:

[7842BD261FD27732B848D3E904F42A59];2012-09-21 12:04:02.308;813;78;735;2;loadCustomersList;e-

1. RequestId - идентифицирует операцию веб сервиса
2. Время записи
3. Общее время выполнения данной операции, которое состоит из следующих двух
4. Время выполнения кода Java в JVM
5. Время выполнения кода pl\sql на сервере БД (Oracle)
6. Кол-во обращений к серверу БД (Oracle)
7. Наименование операции
8. В случае завершения данной операции исключительной ситуацией, желательно вывести в данное поле флажок, например “e-”, если операция выполнилась штатно, поле остаётся пустым.

Общий принцип сбора статистики:

1. Подсчитать полное время выполнения данной операции (переменная lServiceOracle)  
2. Подсчитать количество и время всех вызовов к БД Oracle произошедших во время выполнения данной операции и сохранить с накоплением в сборщик статистики PerfomanceCollector (синглтон HashMap с ключом RequestId) (переменная lOracle)  
3. Вычислить время выполнения данной операции в JVM = п.1 минус п.2 (переменная lService)  
4. Вывести результаты в лог, в случае ошибки вывести “e-”
5. Незабыть почистить HashMap, чтобы не было MemoryLeak - perfomanceCollector.unregisterMethodCall("[" + requestId + "]");

пункты 1,3,4,5 выполняются в 
/colvir-ibank-service/src/main/java/com/colvir/modules/ibank/service/ws/impl/AbstractIbankServiceImpl.java

protected final <T extends AbstractResponse> T execute(RequestHeader header, T result, ServiceAction<T> action)

т.к. метод является общим и внутри него выполняются все операции веб сервиса, значит здесь удобным является подсчитать время выполнения каждой операции и вывести в лог:

       perfomanceLogger.log(PerfomanceLogLevel.PERF, lServiceOracle + ";" + lService + ";" + lOracle + ";"
               + perfomanceCollector.getCountDB("[" + requestId + "]") + ";" + sMethod + ";" + errorMessage);

Собрать данные в процессе выполнения операции (пункт 2) удобно при помощи аспектно ориентированного программирования. Использование аспектов позволяет легко внедрить логирование производительности в приложение без переписывания кода.
Все методы максимально приближенные к вызовам БД Oracle аннотируются "@LogPerfomanceDb". Например
/colvir-ibank-service/src/main/java/com/colvir/modules/ibank/service/dao/IbankDaoImpl.java
 @LogPerfomanceDb
 public final List<DomesticPaymentListItem> loadDomesticPayments.

классом com.colvir.modules.ibank.service.annotations.LoggingAdvicePerfomanceDb в методе public final Object process(ProceedingJoinPoint joinPoint) throws Throwable

происходит обработка аспекта:

long start = System.currentTimeMillis(); // время начала выполнения обращения к БД
Object result = joinPoint.proceed(); // выполнение методов с аннотацией @LogPerfomanceDb
long end = System.currentTimeMillis(); // время окончания выполнения обращения к БД
p.addTimeDb(NDC.peek(), (end - start)); // накапливаем в сборщике статистики PerfomanceCollector с ключом RequestId

При многопоточном программировании не рекомендуется использовать шаблон проектирования “синглтон” и не сохранять состяния в потоках. Если без синглтона не обойтись, можно обратиться к статье “Правильный Singleton в Java” http://habrahabr.ru/post/129494/ 

В нашем случае PerfomanceCollector объявлен как java bean в spring контексте который является сам по себе единственным для всего веб приложения:

/colvir-ibank-service/src/main/resources/META-INF/spring-ibank-service.xml

<bean id="PerfomanceCollector" class="com.colvir.modules.ibank.service.utils.PerfomanceCollector"></bean>

2.7. Настройка пула подключений к серверу Oracle

По умолчанию в Tomcat кол-во потоков = 200, но из за ограничения по умолчанию максимального кол-ва подключений к серверу Oracle в 170, на тестовых инстанциях нагрузить или использовать пул подключений на полную мощность (200 потоков) невозможно. Удобно следить за кол-вом подключений к серверу Oracle можно следующим образом:

Открыть окно PL/SQL Developer \ Tool \ Sessions \ добавить новый запрос и поставить в автоматический режим обновления для удобства

SELECT 'Curr '
|| (SELECT COUNT(*) FROM V$SESSION)
|| ' (tomcat '
|| (SELECT COUNT(*) from V$SESSION where USERNAME = 'IE_GWS_CCP' and PROGRAM = 'JDBC Thin Client')
|| ') max '
|| VP.VALUE
|| ' conn used. CPU (%)= '
|| (select avg(round(value)) from v$sysmetric where metric_name= 'Host CPU Utilization (%)') AS USAGE_MESSAGE
FROM
V$PARAMETER VP
WHERE VP.NAME = 'sessions'

выдаёт строку: 

Curr 144 (tomcat 70) max 170 conn used. CPU (%)= 6

где 144 текущее кол-во подключений к серверу Oracle, из них 70 подключений веб приложения, 170 максимально допустимое кол-во подключений, 6 % нагрузка на процессор сервера Oracle.
Чтобы увеличить максимальное количество сессий со 170 например до 335 надо выполнить:

alter system set processes=300 scope=spfile;
alter system set sessions=335 scope=spfile;
alter system set transactions=369 scope=spfile;

задаем если надо новые параметры, начиная от кол-ва процессов

sessions = (1.1 * PROCESSES) + 5
transactions= (1.1 * SESSIONS) 

после выполнения этих команд надо перезапустить БД.

2.8. Настройка лога производительности системы

В некоторых случаях полезно определить общую загрузку операционной системы, для этого удобно использовать стандартный системный монитор. Инструкция для банка о настройке логирования производительности системы может содержать 2 пункта:

 1. Запустить логирование производительности системы в файл “C:\Perf\Logs\System_Overview.log” на продолжительное время, на сутки или на 8 часов и затем остановить (можно настроить по расписанию). С параметрами по умолчанию, файл лога увеличивается порядка 700КБайт за 7 часов.

  2. Прислать лог файл “C:\Perf\Logs\System_Overview.log”. Он содержит 3 счётчика производительности: использования процессора, памяти, диска.

При необходимости можно добавить интересующие счётчики и повторить сбор статистики. Полученный файл можно анализировать с помощью системного монитора:

 
 Расшифровка значений основных счётчиков в оригинале:

%Processor Time
Processor Time is the percentage of elapsed time that the processor spends to execute a non-Idle thread. It is calculated by measuring the duration of the idle thread is active in the sample interval, and subtracting that time from interval duration.  (Each processor has an idle thread that consumes cycles when no other threads are ready to run). This counter is the primary indicator of processor activity, and displays the average percentage of busy time observed during the sample interval. It is calculated by monitoring the time that the service is inactive, and subtracting that value from 100%.

Pages/sec
Pages/sec is the rate at which pages are read from or written to disk to resolve hard page faults. This counter is a primary indicator of the kinds of faults that cause system-wide delays.  It is the sum of Memory\\Pages Input/sec and Memory\\Pages Output/sec.  It is counted in numbers of pages, so it can be compared to other counts of pages, such as Memory\\Page Faults/sec, without conversion. It includes pages retrieved to satisfy faults in the file system cache (usually requested by applications) non-cached mapped memory files.

Avg. Disk Queue Length
Avg. Disk Queue Length is the average number of both read and write requests that were queued for the selected disk during the sample interval.

НравитсяАлександр Костерин likes this

• Нет меток
• Редактировать метки

1 комментарий

1. 

   Владимир Тимошевич

   В данной статье есть вариант как найти строку кода которая грузит процессор:
   
   http://javaeesupportpatterns.blogspot.com/2012/04/java-thread-cpu-analysis-on-windows.html
   

   как вариант для linux
   http://habrahabr.ru/post/153135/