Поймать стек вызова у долгой транзакции.

[Logger]

Привет.

Кто-нибудь решал задачу ловли стеков вызовов приведших к долгим транзакциям ?

Как оказалось, кастомизации Application.ttsNotify* методов не помогают. Ядро там возвращает пустой стек. Как его еще можно было бы достать?

Ax 2012 R3

[S.Kuskov]

Странно. Раньше вроде работало Анализатор незакрытых транзакций

[Logger]

Цитата:

Сообщение от S.Kuskov

Странно. Раньше вроде работало Анализатор незакрытых транзакций

Так там исходный код анализируется.
Это не то.
Я попробовал в 2012 и 2009. Стек вызовов урезанный. Т. Е при вызове ttsbegin вызов в ttsnotify* приходит откуда то из ядра.

[S.Kuskov]

Цитата:

Сообщение от Logger

Так там исходный код анализируется.
Это не то.

Я сослался на конкретное сообщение в той ветке.
Там предлагается в методах ttsNotifyBegin
и ttsNotifyCommit обращаться к xSession::xppCallStack()

[trud]

Если транзакция работает в данный, можно запустить трейсинг на АОСе, потом его разобрать Trace парсером, соответственно он покажет кто что делает.

[Logger]

Цитата:

Сообщение от S.Kuskov

Я сослался на конкретное сообщение в той ветке.
Там предлагается в методах ttsNotifyBegin
и ttsNotifyCommit обращаться к xSession::xppCallStack()

А!
Я так и хотел.
И этот способ не работает в 2009-й и 2012-й. Вызов в эти методы приходит из ядра. Ноэто геинформативно - Не видно стека, по которому произошел вызов ttsbegin.

[belugin]

Оно не в cil исполняется? mfp: X++ Debugging Tips and Tricks #2 – xSession::xppCallStack()

[Raven Melancholic]

Цитата:

Сообщение от belugin

Оно не в cil исполняется? mfp: X++ Debugging Tips and Tricks #2 – xSession::xppCallStack()

Не, тут неважно где выполняется. Когда работают методы Application.ttsNotify* стек видно только начиная с этого метода и в отладчике и при программном получении. Там уже где не ставь точку останова - в самом методе или там, кого он вызывает, на вершине стека метод Application.ttsNotify*, а откуда он сам вызван уже не видно.

[Logger]

Нет, речь о p-code.
Запускаем такой джоб

static void Job144(Args _args)
{
    void  someMethod()
    {
        callStack2infolog();
    }
    ;

    ttsBegin; // здесь в Application запоминается время начала

    someMethod(); // а здесь мы легко получаем стек вызовов и запоминаем его в глобальной переменной, которую чистим по завершении транзакции
    // нам же необязательно  получить стек при начале или конце транзакции. Главное локализовать участки кода.
    // это попытка хоть как-то обойти потерю стека вызовов ядром при пересечении ttsBegin / ttsCommit

    ttsCommit; // здесь в Application запоминается время конца и идет запись времени в лог вместе со стеком вызовов
}

где callStack2infolog это

// подняли из ax3.0
#localmacro.ClientPrefix "(C)" #endmacro
#localmacro.ServerPrefix "(S)" #endmacro
#define.PathPrefixLen       (4)

static void callStack2infolog(
    str         _prefix = "", // "@SYS65092",
    Counter     _skipLevels = 0,
    /*
    container   stack = xSession::xppCallStack() //pkoz 18.02.2014
    */
    container   stack = Stack_MRC::xppCallStack(0)
    )
{
//    container               stack = xSession::xppCallStack();
    TreeNodePath            correctPath;
    TreeNodePath            stackPath;
    Counter                 n;
    int                     line;
    ;

    setPrefix(_prefix);

    if (_skipLevels < 0)
    {
        _skipLevels = 0;
    }

    for (n = 3 + _skipLevels * 2; n <= conLen(stack); n += 2)
    {
        stackPath   = conPeek(stack,n);
        line        = conPeek(stack,n+1);
        correctPath = stackPath;

        if (line)
        {
            if (    subStr(stackPath, 1, #PathPrefixLen) == #ClientPrefix
                ||  subStr(stackPath, 1, #PathPrefixLen) == #ServerPrefix
               )
            {
                correctPath = subStr(stackPath, #PathPrefixLen + 1, maxInt());
            }

            info(strFmt("%1 %2", stackPath, line),'', SysInfoAction_Editor::newLineColumn(correctPath, line));
        }
        else
        {
            info(strFmt("%1", stackPath),'', SysInfoAction_Editor::newLineColumn(correctPath, 1));
        }
    }
}

по итогу он вывел в инфолог

Цитата:

(C)\Classes\Global\callStack2infolog 6
(C)\Jobs\Job144 5

а если запустить такой джоб

static void Job145(Args _args)
{
    ttsBegin; 
    ttsCommit;
}

воткнув в метод
\Classes\Application\ttsNotifyPostBegin
такой код

public void ttsNotifyPostBegin()
{
    ;

    if (curUserId() == "pkoz")
    {
        callStack2infolog();
    }
    
    super();
...
}

то в инфолог будет выведен такой стек вызовов

Цитата:

(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11

т.е. вызов идет откуда-то из ядра. Стек вызовов усекается - нет упоминаний про джоб.

[Logger]

Так, прошу прощенья, похоже меня обманули.
Если джоб 145 запустить на сервере через серверный менюитем, то стек вызовов не теряется.

Цитата:

(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11
(S)\Jobs\Job145 3
(S)\Classes\xMenuFunction\runServer

похоже, какие-то ограничения для обращения на клиент.

[Raven Melancholic]

Хотя нет.
В отладчике видно, если как советует Ace of Database включить точки останова на АОСе (ну понятно, если их не включить, то и остановки не будет). А вот из джоба Logger, действительно, программно стек не ловится.

[Logger]

Набросал тестовую форму
потыкал по кнопкам
в инфолог вывалилось

Цитата:

Запустили ttsBegin на clicked кнопки
(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11

Запустили ttsBegin в серверном методе класса вызванном с clicked метода кнопки на форме.
(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11
(S)\Classes\Jobs_MRC\testServer 3
(C)\Forms\Form20\Designs\DesignList\Button2\Methods\Clicked 5

Запустили ttsBegin в серверном методе класса вызванном с метода формы.
(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11
(S)\Classes\Jobs_MRC\testServer 3
(C)\Forms\Form20\Methods\test3 3
(C)\Forms\Form20\Designs\DesignList\Button3\Methods\Clicked 5

Запустили ttsBegin в методе формы вызванном с clicked кнопки.
(S)\Classes\Global\callStack2infolog 6
(S)\Classes\Application\ttsNotifyPostBegin 11

[Logger]

Вывод:
Обсуждаемый баг имеет место когда ttsBegin или ttsCommit написан в клиентском X++ коде.
Если писать на серверном то все ок.

[Raven Melancholic]

Кстати, да.
В отлидчике та часть, которая на клиенте в стеке обычным шрифтом представлена, а начиная с Application.ttsNotifyPostBegin жирным.