AX2009 TraceParcer issue

[DSPIC]

Всем привет,

AX2009

может кто-то сталкивался с ошибкой при попытке импортитовать лог в TraceParcer?





пробовал сделать то же самое на совершенно независимом энве - аналогичная ошибка.

[Logger]

Багу не встречал.

Идеи:
1. Возможно загрузка полагается на порядок следования полей в базе и загрузка значения происходит не в тот столбец. Сиквел пытается автоматически сконвертировать значение и происходит переполнение.
Что можно сделать - посмотреть какой SQL запрос идет. Угадать правильный порядок столбцов. пересоздать табличку с нужным порядком следования столбцов в базе.

2. Может формат базы не тот ? Опять можно потрассировать запросы и попытаться угадать какой должен быть правильным.

[DSPIC]

Спасибо, но похоже, дело не в этом. Поигравшись, заметил, что ошибка возникает уже после загрузки трейса в DB и появляется каждый раз когда, скажем, переключаешся между сессиями юзеров, т.е. при перестроении дерава колл стека. Колл стек, тем не менее, отрисовывается, но время исполнения выполнения кода кривое, прописывается значение, как максимально-возможное для типа int(или long-int), что коррелирует с сообщением об ошибке. Т.е. ошибка, похоже чисто на UI.

[Logger]

Да он вообще немного глючный
Тормозит создание буфера.

[Logger]

У меня вот такой был. Microsoft Dynamics AX Trace Parser.rar

[Sergicc]

скиньте пжл дистр. парсера если не трудно не могу найти нигде.спс

[alexkrut]

Привет!

Понимаю, что форум теперь больше экономический, чем про аксапту, но рискну спросить.

Столкнулся с той же проблемой что и топикстартер, причем на двух разных аксаптах (2009 и 2012) и двух разных трейспарсерах соответственно.

Исследования показали, что сами трейспарсеры не при чем (трейсы собранные на моей личной виртуалке, открываются без проблем что в 2012, что в 2009).

Сама проблема в записи (или интерпретации) sql запросов (если записывать в трейс только X++) все работает.
А конкретно не работает интерпретация AxPrepDuration:

Запускаю запись трейсов вот так:

SysTraceControl::startClientTrace( @"C:\temp\trace.etl", 
                                        #AXTRACE_DEFAULT_BUFFER_SIZE,
                                        #AXTRACE_DEFAULT_MINBUFFERS,
                                        #AXTRACE_DEFUALT_MAXBUFFERS,
                                        0x34);
    
    select * from inventTable;

    info( inventTable.ItemId );
    
    SysTraceControl::stopClientTrace();

Получаю вот такое в etl (сконвертил etl в xml):

PHP код:

<Data Name="seqNum">318586</Data>
<Data Name="AxServerName">...</Data>
<Data Name="AxUserName">...</Data>
<Data Name="AxSessionId">3</Data>
<Data Name="AxRC">1</Data>
<Data Name="AxConDBSpid">59</Data>
<Data Name="AxSqlStmt">SELECT T1.ITEMID,T1.ITEMTYPE,T1.PURCHMODEL,T1.HEIGHT,T1.WIDTH,T1.SALESMODEL,T1.COSTGROUPID,T1.REQGROUPID,T1.EPCMANAGER,T1.PRIMARYVENDORID,T1.NETWEIGHT,T1.DEPTH,T1.UNITVOLUME,T1.BOMUNITID,T1.ITEMPRICETOLERANCEGROUPID,T1.DENSITY,T1.COSTMODEL,T1.USEALTITEMID,T1.ALTITEMID,T1.MATCHINGPOLICY,T1.INTRACODE,T1.PRODFLUSHINGPRINCIP,T1.MINIMUMPALLETQUANTITY,T1.PBAITEMAUTOGENERATED,T1.WMSARRIVALHANDLINGTIME,T1.BOMMANUALRECEIPT,T1.PHANTOM,T1.INTRAUNIT,T1.BOMLEVEL,T1.BATCHNUMGROUPID,T1.AUTOREPORTFINISHED,T1.ORIGCOUNTRYREGIONID,T1.STATISTICSFACTOR,T1.ALTCONFIGID,T1.STANDARDCONFIGID,T1.PRODPOOLID,T1.PROPERTYID,T1.ABCTIEUP,T1.ABCREVENUE,T1.ABCVALUE,T1.ABCCONTRIBUTIONMARGIN,T1.COMMISSIONGROUPID,T1.SALESPERCENTMARKUP,T1.SALESCONTRIBUTIONRATIO,T1.SALESPRICEMODELBASIC,T1.NAMEALIAS,T1.PRODGROUPID,T1.PROJCATEGORYID,T1.GROSSDEPTH,T1.GROSSWIDTH,T1.GROSSHEIGHT,T1.STANDARDPALLETQUANTITY,T1.QTYPERLAYER,T1.SORTCODE,T1.SERIALNUMGROUPID,T1.ITEMBUYERGROUPID,T1.TAXPACKAGINGQTY,T1.WMSPALLETTYPEID,T1.ORIGSTATEID,T1.WMSPICKINGQTYTIME,T1.TARAWEIGHT,T1.PACKAGINGGROUPID,T1.SCRAPVAR,T1.SCRAPCONST,T1.STANDARDINVENTCOLORID,T1.STANDARDINVENTSIZEID,T1.ITEMDIMCOSTPRICE,T1.ALTINVENTSIZEID,T1.ALTINVENTCOLORID,T1.FORECASTDMPINCLUDE,T1.PRODUCT,T1.PALLETTAGGING,T1.ITEMTAGGINGLEVEL,T1.DEFAULTDIMENSION,T1.BOMCALCGROUPID,T1.PBAITEMCONFIGURABLE,T1.PBAINVENTITEMGROUPID,T1.PBAHIDEDIALOG,T1.PBAHIDEAPPROVAL,T1.PBAAUTOSTART,T1.PBAMANDATORYCONFIG,T1.PDSCWWMSSTANDARDPALLETQTY,T1.PDSCWWMSMINIMUMPALLETQTY,T1.PDSCWWMSQTYPERLAYER,T1.ALTINVENTSTYLEID,T1.BATCHMERGEDATECALCULATIONMETHOD,T1.PDSBASEATTRIBUTEID,T1.PDSBESTBEFORE,T1.PDSFREIGHTALLOCATIONGROUPID,T1.PDSITEMREBATEGROUPID,T1.PDSPOTENCYATTRIBRECORDING,T1.PDSSHELFADVICE,T1.PDSSHELFLIFE,T1.PDSTARGETFACTOR,T1.PDSVENDORCHECKITEM,T1.PMFPLANNINGITEMID,T1.PMFPRODUCTTYPE,T1.PMFYIELDPCT,T1.STANDARDINVENTSTYLEID,T1.MODIFIEDDATETIME,T1.DEL_MODIFIEDTIME,T1.MODIFIEDBY,T1.CREATEDDATETIME,T1.DEL_CREATEDTIME,T1.CREATEDBY,T1.RECVERSION,T1.PARTITION,T1.RECID FROM INVENTTABLE T1 WHERE ((PARTITION=?) AND (DATAAREAID=?))</Data>
<Data Name="AxDuration">7203</Data>
<Data Name="AxPrepDuration">0</Data> 


Как можно видеть, AxPrepDuration = 0
Но если загрузить этот трейс в трейс парсер, получаем следующее:

Prep Time (ms) : -922,337,203,685,478.00 (и так реально лежит в базе трейспарсера для этой строки трейса)

Выглядит так, будто в процессе импорта 0 из AxPrepDuration зачем-то интерпретируется, как минимальное значение long.

Но при этом трейсы, которые нормально работают тоже содержат в себе AxPrepDuration = 0 но загружаются без проблем.

Может у кого-то возникнут идеи, хотябы в каком направлении копать?

Сервер 2019
SQL 2017
билд 2012 - 6.3.6000.151
билд 2009 - 5.0.1500.3761

[Logger]

Если мне не изменяет память, загрузку в базу вы делаете в самом трейспарсере.
А он представляет из себя сборку .net
Можно посмотреть исходник ILSpy-ем. Или может даже они где-то есть на гитхабе.
Посмотрите это место в коде. Возможно там некорректно работа с типами идет.

[Masel]

А если собрать через perfmon.exe? Я просто только так и собираю. Там еще есть проблема с версией ОС. На 2019 не работает. Вроде максимум на 2016. То есть файл формируется, но в парсер грузится с ошибкой на 2019.

[alexkrut]

Цитата:

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

А если собрать через perfmon.exe?

Через него тоже пробовал, с аналогичным результатом. А можете подсказать, с какими настройками вы его запускаете? (Keywords для провайдера, размер буфера и т д)

И по поводу версии ос где-то были статьи и\или официальный анонс, почему именно не будет работать с 2019?

Вот здесь тоже люди встречались с подобным и пишут, что может случиться на версиях сервера младше 2019

https://community.dynamics.com/ax/f/...flow-exception

[Logger]

Названия полей там интересные упомянуты

Columns : inclusivedurationnano , databasedurationnano , binddurationnano, exclusivedurationnano , prepdurationnano , rowfetchdurationnano

Может там счетчики старта завершения длительности в тиках стоят. И в более свежих виндах (более свежих версиях .net) они приобретают более высокие значения ? Тикают с большей точностью чем на старых виндах и быстрее достигают значений приводящих к переполнению.

Обычно разные счетчики обнуляются с перезагрузкой винды.
Попробуйте сервак перезагрузить и снова трейс собрать и загрузить.

Реально я не исследовал - это только поверхностные предположения.

[Masel]

Вставил скрин с настройками. Не берусь сказать, что это какие-то оптимальные настройки, но у меня так работает. Если не успевает писать, можно наверное увеличивать параметры.
По поводу статей. Когда была такая проблема, где-то находил, что версия ОС поддерживается какая-то древняя по нынешним меркам. Там по моему и 2016 не поддерживается. Но есть практический опыт, на 2019 не работает. Сносишь 2019 ставишь 2016 и работает. Несколько раз такое наблюдал. Почему это так и как направить 2019 я не разбирался.

[Товарищ ♂uatr]

Привет.
При регистрации новой БД приложение выдает ошибку. Для меня является загадкой причина по которой не был сделан динамический вывод информации о причине ошибки, тем не менее... после кастомизации Microsoft.Dynamics.AX.Tracing.Data.dll пришло понимание, что текст ошибки звучит как: 'PK__TraceLin__9FC961DF25869641' is not a constraint.
Удалось найти проблемный запрос к БД:

ALTER TABLE [dbo].[TraceLines] DROP CONSTRAINT [PK__TraceLin__9FC961DF25869641]

Понятное дело, что "игра называется угадай, а что в БД на самом деле", а там "PK__TraceLin__9FC961DF4E1C95DE".
Мой вопрос - насколько это обыденная проблема при работе с данным ПО? У меня может дитрибутив "битый"?

[gl00mie]

Цитата:

Сообщение от Товарищ ♂uatr

Мой вопрос - насколько это обыденная проблема при работе с данным ПО? У меня может дитрибутив "битый"?

Еще бы версию Trace Parser-а привести для понимания...

Цитата:

Сообщение от Товарищ ♂uatr

При регистрации новой БД приложение выдает ошибку: 'PK__TraceLin__9FC961DF25869641' is not a constraint. В БД на самом деле "PK__TraceLin__9FC961DF4E1C95DE".

Не встречал при регистрации новой БД Trace Parser ошибок, кроме связанных с отсутствием права create database на сервере. В целом же после ковыряний с D365FO и ее глючной синхронизацией я лично решил для себя, что если приложение хочет дропнуть в базе что-то, чего там нет, то проще дать ему это дропнуть: создать недостающий constraint с нужным именем (любого содержания), или поле, или индекс, или что там приложение не может найти, но хочет изничтожить. Пусть дропнет и не мотает нервы

[Товарищ ♂uatr]

Совсем забыл...речь идет о Version 6.0.947.9033.

Да, создать нужный объект мне тоже хотелось и это было бы решением, если бы (много бы) утилита умела валидировать целостность БД и продолжать выполнение с момента предыдущего прерывания. У нее 2 состояния - создать новую БД или использовать существующую.

Проблемы, на самом деле две:
Первая - в коде исполняемого файла, в функции Microsoft.Dynamics.AX.Tracing.TraceParser.Presentation.DatabaseRegister.CollectDatabaseRegistrationConnectionString. Изображение прикрепил, стрелками синего цвета отмечен путь в случае когда БД есть, серого - БД нет.
Вторая - можно вызвать "Microsoft.Dynamics.AX.Tracing.Data.DatabaseHelper.CreateDatabase" через то же консольное приложение, но там "затык" уже в самих запросах к БД. Первым запросом идет "create database" - снова "свалится", БД же есть к этому моменту.

Вижу 2.5 путей решения:
1. Разобраться с генерацией названия PK;
2. Видоизменить проблемный код в библиотеке;
2.5. Запустить скрипты по подготовке БД самостоятельно.
Понятное дело, что 1-ый вариант вызывает интерес. Для эксперимента взял другую машину (SQL другой, ОС другая) результат - "PK__TraceLin__9FC961DFECC085B4". Документации официальной на тему правил генерации наименований не вижу, может кто-то владеет такой информацией?

[Logger]

Цитата:

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

По поводу статей. Когда была такая проблема, где-то находил, что версия ОС поддерживается какая-то древняя по нынешним меркам. Там по моему и 2016 не поддерживается. Но есть практический опыт, на 2019 не работает. Сносишь 2019 ставишь 2016 и работает. Несколько раз такое наблюдал. Почему это так и как направить 2019 я не разбирался.

А вы не пробовали запускать приложение в режиме совместимости с предыдущими версиями Windows ? Может поможет снизить частоту возникновения проблем. Аос можно как консольное приложение запускать и прописать для него соответствующую совместимость.

[Logger]

А вы обратили внимание что везде повторяется одна "магическая" константа "-9223372036854775808"

И если погуглить
https://www.google.com/search?q="-9223372036854775808"

То легко увидеть что это 2^63 со знаком минус. Явно было какое то переполнение.
А судя по тому что описывают тут
https://stackoverflow.com/questions/...f-a-2d-array-a

https://github.com/numpy/numpy/issues/13101

Такие числа получаются если вещественный Nan приравнять целому числу. Тогда получается MinInt соответствующей размерности (для int64 будет -2^63 т.е. наш случай)
Там явно где то при сборе трейсов идет ошибка.

Думаю, что раз трейс смог закачаться в SQL базу то можно одним SQL запросом перебить эту магическую константу на 0 и тогда с трейсом можно будет обращаться.
Судя по скрину там был вызов ConPeek() (если мне не изменяет память, то qpeek это ConPeek()) - он не должен очень много занимать. Если обнулить, то погрешность вероятно будет не слишком большой.

[Logger]

А возможно что там на входе 64-битный счетчик типа аксаптовского \Classes\WinAPI\getTickCount64
(System.DateTime::get_Now())

который считает некие тики. Если это тики процессора, то переполняться может достаточно часто (кстати, если не ошибаюсь, то размер "тик"-а для System.DateTime зависит от версии .net - отсюда и зависимость частоты возникновения глюков от версии винды. Выше версия винды - более мелкий тик - чаще переполняется счетчик).

И возможно что значение этого счетчика трактуется в коде как беззнаковое целое, а используется знаковое целое и при переходе через максимальное целое нормально не обрабатывается при этом.
Получается что если TickStart был положительным целым, а TickFinish перемахнул в область отрицательных, то разница их по модулю всегда будет больше или равная чем 2^63 А само число будет всегда меньше или равно чем -2^63
Но больше не влезает в размерность числа, вот мы и получаем всегда -2^63

Если эти предположения верны, то можно попробовать пофиксить приложение, чтобы корректно обрабатывало такие случаи (где бы еще взять исходники. Хотя при определенном желании можно дизассемблировать и пересобрать).

Ну или заставить все это работать с меньше точностью (задействовать более старую версию дотнет или запустить в режиме совместимости со старой версией винды)

[Товарищ ♂uatr]

Спасибо, словно на съемках Санта Барбара побывал - там действительно проблема с преобразованием...
...у винды есть вот такая функция QueryPerformanceFrequency
У утилиты есть конвертер "QueryPerfCounter" с функцией:

public static long ConvertQPFTimeToTicks(ulong QPFTime)
{
	if (!initialized)
	{
		if (!NativeMethods.QueryPerformanceFrequency(out mFrequency))
		{
			throw new InvalidOperationException();
		}
		initialized = true;
	}
	return (long)((double)QPFTime / (double)mFrequency * (double)multiplier);
}

Где для mFrequency может быть инициализирована значением по умолчанию из той самой функции. История на этом могла бы и закончиться (ну да, выдавало бы оно разные результаты на разных машинах), если бы не лог трассировки в комбинации с этой строкой "QueryPerfCounter.Frequency = e.Properties.TryGetValue<long>("PerfFreq");" желающей видеть данное свойство у каждого события лога.
Только не все логи события "XppUtilFuncEvent" (согласно статистике) желают заполнять данную информацию. Поэтому получаем mFrequency равное 0, а далее "силу бесконечности".

[Logger]

Судя по коду значение должно быть одинаково у всех замеров. Т. Е. MinInt64 у всех. А оно у одних так у других сяк.
Поэтому мне все же кажется что дело в переполнении.