powered by simpleCommunicator - 2.0.60     © 2026 Programmizd 02
Целевая тема:
Создать новую тему:
Автор:
Закрыть
Цитировать
Форумы / Microsoft SQL Server [игнор отключен] [закрыт для гостей] / Service broker для логирования, глюки
43 сообщений из 43, показаны все 2 страниц
Service broker для логирования, глюки
    #39746944
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Недавно решил модернизировать существующую систему журналирования и ряд «автоматизаций» с использованием ServiceBroker. Вроде как асинхронность журналирование не будет тормозить, в при критической нагрузке — очередь постепенно в нужно порядке разгребется. Так как это вроде как «другой поток/подключение» не нужно париться с тем чтоб не потерять логи при rollback-ах.

Сделал контракты, очереди, активаторы, скрипты тестовые — все ОК. Все делает как нужно, ошибки тож хорошо ловит (пробовал на делении на ноль), ничего не ломается.

Но дальше начинается магия.

Запускаю пачкой юнит тесты (из C# вызываются хранимки с «новым» журналированием). Ошибок нет. Логи — пустые. Очередь — пустая.
Запускаю отдельно тест через отладчик — все норм, данные в логах есть. Запускаю ХП из SMS – логи есть.

Отлаживаю дебаггером в SMS в которой есть ошибка (обращение к несуществующему объекту). Пошагово иду, и там где логи должны записываться — таблица пустая, ни до ошибки, ни самой ошибки, ни после. Хранимки логов вызваются, в очередь сообщения отправляются, но активатор не вызывается.
Запускаю без дебаггера с «ошибкой» - логов тоже нет.
Запускаю приложение .NET, жму кнопочки, вызываются другие ХП с таким же логированием, логи есть.
Тут же еще раз дебаггером в SMS – логов нет.
Правлю хранимку, чтоб не было ошибки, запускаю, без отладки — логи есть.


Продолбался с этим конец рабочего дня. Сейчас сижу и ломаю голову. Это у меня что-то глючит или или в режиме дебаггера какой-то другой режим работы брокера? Или если ошибка посерьезнее чем деление на ноль, то запись в очередь умирает и это как-то просчитывается? И у брокера активатор работает не совсем в "отдельном потоке" и "отдельном подключении к БД"?
Или брокера для логов использовать не камельфо? Есть какие-то нюансы которые я не учел?
Куда пропадают логи когда пачкой работают юнит тесты?

сервер - 2014 Standart
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39746948
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
по этой статейке с брокером работаю
https://germangorelkin.blogspot.com/2017/07/ms-sql-server.html
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39746951
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикТак как это вроде как «другой поток/подключение» не нужно париться с тем чтоб не потерять логи при rollback-ах.Вот с этим как раз и нужно "париться", т.к. при откате транзакции все, что отсылалось в очередь также откатывается.

Обходится через event notifications - 17329722
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39746974
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
invm,
я правильно понимаю, что "на пальцах", это примерно как я сделал, за исключением что попадание сообщения в очередь не через хранимку с dialog conversation а с использованием sp_trace_generateevent ?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747115
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикя правильно понимаю, что "на пальцах", это примерно как я сделал, за исключением что попадание сообщения в очередь не через хранимку с dialog conversation а с использованием sp_trace_generateevent ?Т.е. разница в поведении при откате транзакции для вас несущественна?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747129
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
invm, конечно существенна
я подразумевал реализацию а не поведение.
и судя по всему тип сообщения службы только [ http://schemas.microsoft.com/SQL/Notifications/PostEventNotification%5D]http://schemas.microsoft.com/SQL/Notifications/PostEventNotification] ?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747149
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикя подразумевал реализацию а не поведение.Реализация да, через SB.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747159
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
invm,
слепил из вашей заготовки и своего кода. на вскидку, ничего не упустил?
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
85.
86.
87.
88.
89.
90.
91.
92.
93.
94.
95.
96.
97.
98.
99.
100.
101.
102.
103.
104.
105.
106.
107.
108.
109.
110.
111.
112.
113.
114.
115.
116.
117.
118.
119.
120.
121.
122.
123.
124.
125.
126.
127.
128.
129.
130.
131.
132.
133.
134.
135.
136.
137.
138.
139.
140.
141.
142.
143.
144.
145.
146.
147.
148.
149.
150.
151.
152.
153.
154.
155.
-- Включаем Service Broker
-- alter database db2_log set enable_broker with rollback immediate; 

use DB2_LOG
go

if exists (select 1 from sysobjects where id = object_id('SendLogMessage'         ) and type in ('P','PC')) drop procedure SendLogMessage
if exists (select 1 from sysobjects where id = object_id('AsyncLogQueueActivation') and type in ('P','PC')) drop procedure AsyncLogQueueActivation
if exists (select 1 from sysobjects where id = object_id('XmlMessageToTable'      ) and type in ('P','PC')) drop procedure XmlMessageToTable
if exists (select 1 from sysobjects where id = object_id('SimpleAuditData'        ) and type in ('U'     )) drop table SimpleAuditData
if exists (select 1 from sys.services                  where name = 'AsyncLogService'    ) drop service AsyncLogService
if exists (select 1 from sys.service_queues            where name = 'AsyncLogQueue'      ) drop queue AsyncLogQueue;
if exists(select * from sys.server_event_notifications where name = 'asyncLogEventNotify') drop event notification asyncLogEventNotify on server
-------------------------------------------------
go

-- Создаем очередь и сервисы

if object_id('AsyncLogQueueActivation', 'P') is null
 exec('create procedure AsyncLogQueueActivation as begin set nocount on; end;');
go

create queue AsyncLogQueue with
 status = on,
 retention = off,
 activation (status = on, procedure_name = AsyncLogQueueActivation, max_queue_readers = 5, execute as owner),
 poison_message_handling (status = on);
go

create service AsyncLogService authorization dbo  
on queue AsyncLogQueue (
    [http://schemas.microsoft.com/SQL/Notifications/PostEventNotification]
);

go
create table SimpleAuditData
(
 ad_id         int identity,
 ad_OccurredAt datetime not null,
 ad_Login       sysname,
 ad_Application nvarchar(128),
 ad_Host        nvarchar(128),
 ad_ShortText   nvarchar(128),
 ad_LongText    nvarchar(4000),
 Stamp          timestamp,
 constraint PK_SimpleAuditData primary key (ad_id)
);
go

-- ХП которая разбирает XML и пишет его в таблицу
create procedure XmlMessageToTable @message xml
as
begin
    with s as
    (
            select
              n.value('EventType[1]'       , 'sysname'        ) as EventType
            , n.value('PostTime[1]'        , 'datetime'       ) as PostTime
            , n.value('TextData[1]'        , 'sysname'        ) as TextData
            , n.value('BinaryData[1]'      , 'varbinary(8000)') as BinaryData
            , n.value('DatabaseID[1]'      , 'int'            ) as DatabaseID
            , n.value('DatabaseName[1]'    , 'sysname'        ) as DatabaseName
            , n.value('ApplicationName[1]' , 'sysname'        ) as ApplicationName
            , n.value('HostName[1]'        , 'sysname'        ) as HostName
            , n.value('SessionLoginName[1]', 'sysname'        ) as SessionLoginName
            from
            @message.nodes('/EVENT_INSTANCE') x(n)
    )
    insert into SimpleAuditData
    (ad_OccurredAt, ad_Login, ad_Application, ad_Host, ad_ShortText, ad_LongText)
    select
        s.PostTime, s.SessionLoginName, s.ApplicationName, s.HostName, s.TextData, cast(s.BinaryData as nvarchar(4000))
    from s 
    --where DatabaseID = db_id();
end

-- Процедура которая будет принимать сообщения и обрабатывать их
go
alter procedure AsyncLogQueueActivation with execute as owner
as
begin
    set nocount on;

    declare @handle uniqueidentifier;
    declare @message xml;
    declare @message_type sysname;
 
    while (1=1)
    begin
        begin transaction;
 
            waitfor
            (
              receive top (1)
                @handle = conversation_handle,
                @message =  CAST(message_body AS XML),
                @message_type = message_type_name
              from AsyncLogQueue
            ), timeout 500;
 
            if (@@rowcount = 0)
            begin
              rollback transaction;
              print 'Error - нет данных в очереди'
              break;
            end
            if @message_type = N'http://schemas.microsoft.com/SQL/Notifications/EventNotification'
            begin
                exec XmlMessageToTable @message
            end
            else if @message_type = N'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog'
            begin
                end conversation @handle with cleanup;
            end
            else if @message_type = N'http://schemas.microsoft.com/SQL/ServiceBroker/Error'
            begin
                --TODO
                --log errors
                end conversation @handle with cleanup;
            end 
        commit transaction;
    end
end
go

-- привязываем пользовательское событие к службе
create event notification asyncLogEventNotify
    on server
    for USERCONFIGURABLE_0 -- event_id = 82
    to service 'AsyncLogService', 'current database';
go

-- Процедура общего вида, с помощью которой можно отправлять сообщения
go
create procedure SendLogMessage @logMsg nvarchar(128), @logData nvarchar(1024)
as
begin
    set nocount on;
    -- sp_trace_generateevent 
    --      [     @eventid  = ]  event_id   
    --      [ , [ @userinfo = ] 'user_info' ]  
    --      [ , [ @userdata = ]  user_data  ]  
    -- event_id - numbers from 82 through 91
    declare @b varbinary(8000) = cast(@logData as varbinary(8000));
    exec sp_trace_generateevent 82, @logMsg, @b;
end
go


exec  SendLogMessage 'message1', 'data1'
exec  SendLogMessage 'message2', 'data2'
exec  SendLogMessage 'message3', 'data3'
exec  SendLogMessage 'message4', 'data4'
waitfor delay '00:00:01'
select * from SimpleAuditData

...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747168
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикна вскидку, ничего не упустил?Вроде нет.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39747208
Владислав Колосов
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

тесты откатывают транзакции и вместе с ними сообщения брокера. Вам для журналирования надо использовать механизм event notification, который передаёт сообщения брокеру независимо от отката.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748001
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Всем спасибо за наводки. Заработало на "боевой" базе.
Правда еще пришлось танцевать с бабунами.
допиливание чтоб на базе это все завелось (может кому пригодится)
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
use db_log
go
exec sp_changedbowner 'sa'
go
alter database db_log set trustworthy on
go
alter database db_log set enable_broker with rollback immediate; 
go

use master;
go
grant alter trace to user1
go



признаюсь не до конца осознал последствия trustworthy и changedbowner, но это заработало )))

а внутри обработчика сообщений пришлось добавить строку
set QUERY_GOVERNOR_COST_LIMIT 0;
иначе брокер вылетал с ошибкой
авторthe query has been canceled because the estimated cost of this query (8570) exceeds the configured threshold of 6000
Видать обработка XML со своими данными запиханного в BinaryData оказалась сравнительно ресурсоемкой.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748014
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

подзравляю, теперь ваш любой db_owner может стать сисадмином сервера.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748017
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикпризнаюсь не до конца осознал последствия trustworthy и changedbowner, но это заработало )))А зачем из процедуры активации обращаться к внешним ресурсам?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748039
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

кстати вам еще следуют учитывать что для уведомлений о событиях диалоги не закрываются. они висят до тех пор пока не будет удалено уведомление.
Если у вас эта система логирования предполагает работать с высокой нагрузкой, следует озаботится вопросом что вы будете делать с открытыми диалогами
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748040
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ffКифирчик,

подзравляю, теперь ваш любой db_owner может стать сисадмином сервера.

invm >признаюсь не до конца осознал последствия trustworthy и changedbowner, но это заработало )))

А зачем из процедуры активации обращаться к внешним ресурсам?

уточните плиз, вопрос относительно trustworthy или changedbowner?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748042
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

совокупность.

сделав овнером базы пользователя из группы сисадмин вы расширили его права, любой пользователь группы db_owner может сделать
execute as user = 'dbo' тем самым переключив себя на контекст 'sa' но он пока еще закрыт в базе.

поставив trustworthy вы открыли песочницу, тем самым пользователь теперь не заперт в базе а получает доступ прав уровня sysadmin
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748043
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ffКифирчик,

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

это не спасает?
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
        waitfor
        (
          receive top (1)
              @handle     = conversation_handle
            , @msgBody    = cast( message_body as xml)
            --, @msgBodyStr = cast( message_body as nvarchar(max))
            , @msgType   = message_type_name
          from AsyncLogQueue
        ), timeout 500;

        ....

        else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog'
        begin
            end conversation @handle with cleanup;
        end
        else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/Error'
        begin
            --TODO
            --log errors
            end conversation @handle with cleanup;
        end 
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748054
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

не спасет.

срабатываение события посылает в очередь только тип сообщения [ http://schemas.microsoft.com/SQL/Notifications/EventNotification%5D]http://schemas.microsoft.com/SQL/Notifications/EventNotification]

никакого enddialog ему не приходит, поэтому у вас нижние ветки if никогда не сработают.

[ http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog%5D]http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog] поступит в очередь только при удалении уведомления инструкцие drop event notification

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

Код: sql
1.
2.
3.
4.
5.
   if @message_type = N'http://schemas.microsoft.com/SQL/Notifications/EventNotification'
            begin
                exec XmlMessageToTable @message
                end conversation @handle;
            end
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748066
Владислав Колосов
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

диалог надо закрывать с двух сторон - и на сервисе А и на сервисе Б. Сервис А в данном случае контролирует система Event Notification, а сервис Б - ваша процедура. Вы получаете и обрабатываете сообщение и закрываете со своей сторону диалог в любом случае, независимо от типа полученного сообщения.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748082
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ff,
Код: sql
1.
2.
3.
4.
5.
if @message_type = N'http://schemas.microsoft.com/SQL/Notifications/EventNotification'
            begin
                exec XmlMessageToTable @message
                end conversation @handle;
            end


в таком варианте, очередь обрабатывает только одно первое сообщение, все остальные sp_trace_generateevent я не вижу (((


Владислав Колосов диалог надо закрывать с двух сторон - и на сервисе А и на сервисе Б. Сервис А в данном случае контролирует система Event Notification, а сервис Б - ваша процедура. Вы получаете и обрабатываете сообщение и закрываете со своей сторону диалог в любом случае, независимо от типа полученного сообщения.
Я не совсем понимаю "закрыть со своей стороны"

Со своей стороны я вызываю
Код: sql
1.
2.
3.
  declare @a nvarchar(128) = 'AsyncLogMsg'
   declare @b varbinary(8000) = cast(@messageXml as varbinary(8000));
   exec sp_trace_generateevent 82, @a, @b;


как закрыть диалог с "моей стороны"?
или "моя сторона" подразумевается процедура активации очереди?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748086
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикуточните плиз, вопрос относительно trustworthy или changedbowner?Да.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748126
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

ну напишите так чтобы у вас при активации очереди цикл читал сообщения из очереди, если вдруг в цикле меняется conversation_handle или инструкция receive не возвращет сообщения, закрывается последний прочитанный диалог.

Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
declare @h uniqueidentifier, @h2 uniqueidentifier
while 1=1 begin
     waitfor (receive top (1) @h = conversation_handle, @m = message_body from [quque]), timeout 500

     if @@rowcount = 0 begin 
          if @h is not null end conversation @h;
          break;
     end

     --логика обработки сообщения
     
     if @h2 <> @h and @h2 is not null end conversation @h2;

     set @h2 = @h;
end



а лучше вычитывать в буффер
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
declare @buffer table (h uniqueidentifier, message varbinary(max));
declare @tc int, @limit int, @m varbinary(max), @sql nvarchar(max);
while 1 = 1 begin
      waitfor (receive conversation_handle, message_body into @buffer from [queue]), timeout 500
      set @tc = @@rowcount;
      set @limit += @tc;
      if @tc = 0 or @limit > 100 break;
end;

declare cur cursor local fast_forward for select message from @buffer;
open cur;
while 1=1 begin
      fetch next from cur into @m;
      if @@fetch_status <> 0 break;
      exec <someproc> @m;
end;
close cur;
deallocate cur;

set @sql = N'';
select @sql = @sql + 'end conversation ' + quotename(cast(h as nchar(50)), nchar(39)) + nchar(59) + nchar(13) + nchar(10)
from @buffer;
exec (@sql);
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748300
aleks222
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикНедавно решил модернизировать существующую систему журналирования и ряд «автоматизаций» с использованием ServiceBroker. Вроде как асинхронность журналирование не будет тормозить, в при критической нагрузке — очередь постепенно в нужно порядке разгребется.

Интересно, в чем разница: писать в очередь или сразу писать в журнал?

ЗЫ. Битва с ветряными мельницами?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748355
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
aleks222КифирчикНедавно решил модернизировать существующую систему журналирования и ряд «автоматизаций» с использованием ServiceBroker. Вроде как асинхронность журналирование не будет тормозить, в при критической нагрузке — очередь постепенно в нужно порядке разгребется.

Интересно, в чем разница: писать в очередь или сразу писать в журнал?

ЗЫ. Битва с ветряными мельницами?
Хороший вопрос, заставил задуматься...
Но он был бы справедлив, если бы запись в очередь равнялась записи в таблицу.

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

Недавно придумали новую систему, которая должна решить проблемы перечисленные выше:
- дополнительно пишется ID "бизнес процесса", внутри которого может быть несколько ХП у которых тоже пишется свой не похожий на соседние ID
- есть поле для "бизнес объекта"
- есть система включения/выключение логирования (через табличку)
- упрощена запись (длинная, с указанием кучи аргументов только первая строка)
- не теряются логи после отката транзакции (через промежуточное хранение в табличной переменной)
То есть логгирование хранимки в таком варианте - это минимум две записи о начале/окончании, и при каждой записи обращения к таблице настроек и мета информации плюс запись в логи.
Это определенно окажет еще большее влияние на производительность.
Также, попадаются ошибки из-за которых все равно логи откатываются, вариант с табличной переменной работает не идеально.

Вчера на ноуте запустил тест, в котором ОЧЕНЬ много логов пишется через обсуждаемый вариант логирования (через брокера и event-ы) (упрощенный, только вставка без использование мета информации). Тесты за минуту забили в очередь 100к записей, которые асинхронно минут 15..20 распихивались в таблицу логов. По мне так это пример что это минимально нагружает хранимые процедуры.

Также, мне кажется крайне важным асинхронно развязаться с триггерами соседней системы, не камельфо в них выполнять свои хранимые процедуры. И судя по всему тут доктор прописал использовать ServiceBroker.
Сейчас появилась возможность, и я начал копать в сторону ServiceBroker-a, и решил начать с логов.

Что касается ветряных мельниц - с точки зрения того что есть куча других задач, приходится делать фоново, да и без этого и так работает, то это определенно на ветряную мельницу смахивает.
С точки зрения "хочется чтоб было не через ж#пу" и меньше долбаться с анализом проблем - это не мельница а крепость на пути к светлому будущему )
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748385
aleks222
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикПо мне так это пример что это минимально нагружает хранимые процедуры.

Тебе уже сказали: все очереди сервис брокера - суть таблицы.

Т.е. твой пример пишет два раза.
И это, канешно, быстрее, чем один раз.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748409
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ffКифирчик,
совокупность.

сделав овнером базы пользователя из группы сисадмин вы расширили его права, любой пользователь группы db_owner может сделать
execute as user = 'dbo' тем самым переключив себя на контекст 'sa' но он пока еще закрыт в базе.

поставив trustworthy вы открыли песочницу, тем самым пользователь теперь не заперт в базе а получает доступ прав уровня sysadmin
какую тогда "правильную" стратегию выбрать?
сделать отдельного пользователя не в группе db_owner и не sysadmin, и в собственники базы его?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748438
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

я не знаю Вашей инфраструктуры. если у вас бизнес логика позволяет иметь овнером бд пользователя с наименьшими привилегиями, то желательно тогда овнером делать имено такого пользователя.

правильная стратегия если вам нужно использовать СБ между базами, это создание сертификатов и настройка безопасности на их основе.

тоже касаемо выдачи прав для пользоветей: давая какому то юзеру alter trace вы ему дали возможность создавать серверную трассировку. поэтому теперь этот логин может спокойно следить за запросами даже в тех базах в которые сам не отмаплен.
или поднапрячь сервак какой нибудь кошерной трассой на отлов lock:aсquired к примеру.ъ
в этом варианте лучше сделать процедуру обертку, и подписать ее сертификатом у которого овнер с нужным правом, а пользователю уже дать право на execute этой процедуры обертки.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748451
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

Может уже поделитесь, зачем понадобилось включать trustworthy?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748458
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
invmКифирчик,

Может уже поделитесь, зачем понадобилось включать trustworthy?
Да хз )
На моем компе все и без этого работает.
На объекте на одном сервере завелось, на другом нет. В трассировке еле откопал по поводу сообщение о нехватке прав (примерно).
Сравнил базы, отличие было в trustworthy.
Вспомнил что в одном из примеров по ServiceBroker мне попадалось что автор его включал.
Включил, пересоздал очередь и привязки - заработало.

Касаемо инфраструктуры
С MSSQL работает сервер приложения, под одним логином. Плюс соседнее приложение.
базы, примерно так
BASE_TASK1
BASE_TASK2
BASE_TASK3
BASE_LOG
Наш сервер приложений работает от user1, сторонний - от user2, у обоих во всех этих база db_datareader/writer, и grant exec.
Разделение на базы во много логическое, то есть имеются связи между базами. Сеть закрытая, IT отдел в сервера не лезет. Я бы сказал сертификаты тут избыточное усложнение, и усложнит жизнь коллегам.
И таких серверов несколько, между собой связаны репликациями.

в базах BASE_TASK1, BASE_TASK2б, BASE_TASK3 есть обертки над sp_trace_generateevent, примерно как в спойлере
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
create procedure log.spLogSimple 
     @logProc nvarchar(255)
   , @logMsg  nvarchar(255)
   , @logData nvarchar(2048) = null
as
begin
    --print 'call log.spLogSimple'
    declare @messageBody xml =
    (
         select
            @logProc as LogProc  
          , @logMsg  as LogMsg  
          , @logData as LogData  
          , db_name() as LogDb
          , getdate() as LogDateTime
        for xml raw  ('AsyncLogMessageSimple'), elements
    ) 
    --print cast(@messageBody as nvarchar(4000))

    -- передаем в событие
    declare @a nvarchar(128) = 'AsyncLogMessageSimple'
    declare @b varbinary(8000) = cast(@messageBody as varbinary(8000));
    exec sp_trace_generateevent 82, @a, @b;

    --print 'finish log.spLogSimple'
end



в базе BASE_LOG - очередь, сервис брокер и обработчик очереди, который вызывает ХП которая делает insert в BASE_LOG.log.AppLog
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
create procedure log.AsyncLogQueueProcessing with execute as owner
as
begin
    set nocount on;
    SET ARITHABORT OFF;
    set QUERY_GOVERNOR_COST_LIMIT 0;

    ...
    while (1=1)
    begin
        -- begin tran
        waitfor
        (
          receive top (1)
              @handle     = conversation_handle
            , @msgBody    = cast( message_body as xml)
            , @msgType   = message_type_name
          from AsyncLogQueue
        ), timeout 500;
 
        if (@@rowcount = 0)
        begin
            print '@@rowcount = 0, нет данных в очереди, выходим'           
            break;
        end
        ...
            exec log.XmlEventMessageProcessing @msgBody
 
    end
end
---------------
create procedure log.XmlEventMessageProcessing @message xml with execute as owner
as
begin
    ....
    insert into log.AppLog
    ....
end



подозреваю мои проблемы могу быть вызваны тем что я использовал with as owner
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748535
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

а вы с какой ошибкой то боролись включением trustworthy. на service broker он может повлиять только в том случае если у вас диалог межбазовых очередей.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748559
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ffКифирчик,
а вы с какой ошибкой то боролись включением trustworthy. на service broker он может повлиять только в том случае если у вас диалог межбазовых очередей.

Сейчас выключил на обеих базах, и без него все работает ((
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748576
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Ниже кусок кода как мне видится "правильно бы сделать"
собственником всех баз делам отличного пользователя, под которым не работают клиенты и который не может TRACE EVENT
в базах - два пользователя user_task, для работы клиентов, и user_log, у которого будут права на TRACE EVENT

user_task вызывает ХП обертки над TRACE EVENT которые run as user_log

но не работает - "Нет разрешения на запуск "SP_TRACE_GENERATEEVENT"

чего в коде не хватает?

Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
85.
86.
87.
88.
89.
90.
91.
92.
93.
94.
95.
96.
97.
98.
99.
100.
101.
102.
103.
104.
105.
106.
107.
108.
109.
110.
111.
112.
113.
114.
115.
116.
117.
118.
119.
120.
121.
122.
123.
124.
125.
126.
127.
128.
129.
130.
131.
132.
133.
134.
135.
136.
137.
138.
139.
140.
141.
142.
143.
144.
145.
146.
147.
148.
149.
150.
151.
152.
153.
154.
155.
156.
157.
158.
159.
160.
161.
162.
163.
164.
165.
166.
167.
168.
169.
170.
171.
172.
173.
174.
175.
176.
177.
178.
179.
180.
181.
182.
183.
184.
185.
186.
187.
188.
189.
190.
191.
192.
193.
194.
195.
196.
197.
198.
199.
200.
201.
202.
203.
204.
205.
206.
207.
208.
209.
210.
211.
212.
213.
214.
215.
216.
217.
218.
219.
220.
221.
222.
223.
224.
225.
226.
227.
228.
229.
230.
231.
232.
233.
234.
235.
236.
237.
238.
239.
240.
241.
242.
243.
244.
245.
246.
247.
248.
249.
250.
251.
252.
253.
254.
255.
256.
257.
258.
259.
260.
261.
262.
263.
264.
265.
266.
267.
268.
269.
270.
271.
use master
go
if exists (select 1 from sys.databases where name='db_log')
    drop database db_log

if exists (select 1 from sys.databases where name='db_task')
    drop database db_task

go


if exists (select 1 from master.sys.server_principals where name = 'login_db_owner')
    drop login login_db_owner
go

if exists (select * from master.sys.server_principals where name = 'login_task')
    drop login login_task
go

if exists (select * from master.sys.server_principals where name = 'login_log')
    drop login login_log
go



-------------------------------------------------------------------

create database db_log
go
create database db_task
go

create login login_db_owner with password = 'login_db_owner'
go
create login login_task with password = 'login_task'
go
create login login_log with password = 'login_log'
go

-- собственник баз - login_db_owner

alter authorization on database::db_log to login_db_owner
go
alter authorization on database::db_task to login_db_owner
go


-- логину login_log даем возможность вызывать EVENT-ы
use master
go
grant alter trace to login_log
go

-----------------
-- пользователи в базах
use db_task
go

create user user_task for login login_task
create user user_log for login login_log
go

alter role db_datareader add member user_task
alter role db_datawriter add member user_task
go
grant exec to user_task
grant exec to user_log
go
-----------------
use db_log
go

create user user_task for login login_task
create user user_log for login login_log
go

alter role db_datareader add member user_log
go
alter role db_datawriter add member user_log
go
grant exec to user_log
go
--------------------------
-- тестовая ХП бизнес логики и обертка над sp_trace_generateevent
use db_task
go
create schema log
go
go
-- вроде как логину login_log (c которым связан пользователь базы user_log) 
-- даны права на sp_trace_generateevent
-- и от его имени запустим ХП
create procedure log.spLogSimple @logMsg  nvarchar(255), @logData nvarchar(2048) = null with execute as 'user_log'
as
begin
    declare @m xml= (select @logMsg  as LogMsg , @logData as LogData for xml raw  ('AsyncLogMessageSimple'), elements) 
    declare @a nvarchar(128) = 'AsyncLogMessageSimple'
    declare @b varbinary(8000) = cast(@m as varbinary(8000));
    exec sp_trace_generateevent 82, @a, @b;
end
go
create procedure SomeTaskProc as
begin
    exec log.spLogSimple 'SomeTaskProc start', 'args1'
    waitfor delay '00:00:01.000'
    exec log.spLogSimple 'SomeTaskProc finish', 'args2'
end
go

--------------
-- база с логами
use db_log
go
create schema log
go
create table log.AppLog(LogDateTime datetime, LogMsg nvarchar(128), LogData nvarchar(2000), Stamp timestamp)
go

go
create procedure log.XmlMsgProcessing @message xml
as
begin

    declare @postTime   datetime        = @message.value('(EVENT_INSTANCE/PostTime)[1]'  , 'datetime'       )
    declare @textData   nvarchar(128)   = @message.value('(EVENT_INSTANCE/TextData)[1]'  , 'sysname'        )
    declare @binaryData varbinary(8000) = @message.value('(EVENT_INSTANCE/BinaryData)[1]', 'varbinary(8000)')

    declare @messageXml xml = cast(cast(@binaryData as nvarchar(4000)) as xml)

    declare @logMsg  nvarchar(128) = @messageXml.value('(AsyncLogMessageSimple/LogMsg)[1]' ,'nvarchar(128)'  )
    declare @logData nvarchar(128) = @messageXml.value('(AsyncLogMessageSimple/LogData)[1]','nvarchar(2000)'  )

    insert into log.AppLog(LogDateTime, LogMsg, LogData)
    select @postTime, @logMsg, @logData
end
go

create procedure log.AsyncLogQueueProcessing with execute as 'user_log'
as
begin

    set nocount on;
    set arithabort off;
    set query_governor_cost_limit 0;

    declare @h uniqueidentifier, @h2 uniqueidentifier, @m xml, @msgType sysname 

    while 1=1 begin
         waitfor (receive top (1) @h = conversation_handle, @m = message_body from log.AsyncLogQueue), timeout 500

         if @@rowcount = 0 begin 
              if @h is not null end conversation @h;
              break;
         end

         --логика обработки сообщения
         if @msgType = N'http://schemas.microsoft.com/SQL/Notifications/EventNotification'
         begin
             exec log.XmlMsgProcessing @m
             end conversation @h with cleanup;
         end
         else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog'
             end conversation @h with cleanup;
         else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/Error'
             end conversation @h with cleanup;
     
         if @h2 <> @h and @h2 is not null end conversation @h2;

         set @h2 = @h;
    end

    -- declare @handle uniqueidentifier;
    -- declare @msgBody xml;
    -- declare @msgBodyStr nvarchar(max);
    -- declare @msgType sysname;
    -- while (1=1)
    -- begin        
    --     waitfor(
    --       receive top (1)
    --           @handle  = conversation_handle
    --         , @msgBody = cast( message_body as xml)
    --         , @msgType = message_type_name
    --       from AsyncLogQueue
    --     ), timeout 500;
    -- 
    --     if (@@rowcount = 0)
    --     begin
    --         print '@@rowcount = 0, нет данных в очереди, выходим'
    --         break;
    --     end
    --      
    --     if @msgType = N'http://schemas.microsoft.com/SQL/Notifications/EventNotification'
    --     begin
    --         exec log.XmlEventMessageProcessing @msgBody
    --         end conversation @handle with cleanup;
    --     end
    --     else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog'
    --         end conversation @handle with cleanup;
    --     else if @msgType = N'http://schemas.microsoft.com/SQL/ServiceBroker/Error'
    --         end conversation @handle with cleanup;
    -- 
    -- end
end
go

create queue log.AsyncLogQueue with status = on, retention = off,
 activation (status = on, procedure_name = log.AsyncLogQueueProcessing, max_queue_readers = 5, execute as 'user_log'),
 poison_message_handling (status = on);
go

go
create service AsyncLogService authorization user_log on queue log.AsyncLogQueue ([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification] );
go

drop event notification AsyncLogEventNotify on server
go
create event notification AsyncLogEventNotify on server for USERCONFIGURABLE_0 
    to service 'AsyncLogService', 'current database';
go
---------------------------------------------------------
---------------------------------------------------------
use db_task
go
-- эмитируем вызов хранимки бизнес логики от пользователя user_task
execute as user = 'user_task'

    begin try
        exec SomeTaskProc
    end try
    begin catch
        print 'Error in SomeTaskProc'
        print '@error_procedure = '+  isnull(                error_procedure() ,'null')
        print '@error_line      = '+  isnull(convert(varchar,error_line     ()),'null')
        print '@error_number    = '+  isnull(convert(varchar,error_number   ()),'null')
        print '@error_message   = '+  isnull(                error_message  () ,'null')
        print '@error_severity  = '+  isnull(convert(varchar,error_severity ()),'null')
        print '@error_state     = '+  isnull(convert(varchar,error_state    ()),'null')
    end catch

revert

---------------------------------------------------------
---------------------------------------------------------
use db_log
go
-- пробуем вставить сообщение под user_log и прочитать его
--execute as user = 'login_log'
execute as user = 'user_log'

    begin try
        -- exec db_task.log.spLogSimple 'Test message','some data'

        declare @m xml= (select 'Test message2'  as LogMsg , 'some data2' as LogData for xml raw  ('AsyncLogMessageSimple'), elements) 
        declare @a nvarchar(128) = 'AsyncLogMessageSimple'
        declare @b varbinary(8000) = cast(@m as varbinary(8000));
        exec sp_trace_generateevent 82, @a, @b;

        exec log.AsyncLogQueueProcessing
        select top 20 * from log.AppLog order by Stamp desc
    end try
    begin catch
        print 'Error in db_log'
        print '@error_procedure = '+  isnull(                error_procedure() ,'null')
        print '@error_line      = '+  isnull(convert(varchar,error_line     ()),'null')
        print '@error_number    = '+  isnull(convert(varchar,error_number   ()),'null')
        print '@error_message   = '+  isnull(                error_message  () ,'null')
        print '@error_severity  = '+  isnull(convert(varchar,error_severity ()),'null')
        print '@error_state     = '+  isnull(convert(varchar,error_state    ()),'null')
    end catch

revert

...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748621
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

вы путаете контекст переключения, в вашем случае надо использовать execute as login вместо execute as user

сделайте
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
use db_log
go

execute as user = 'user_log';
go
use master
select * from sys.user_token
select * from sys.login_token;
go

use db_log
go
revert;
go

execute as login = 'login_log';
go
use master
go
select * from sys.user_token
select * from sys.login_token;
go

use db_log
go
revert;
go

увидите разницу
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748626
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
о внимательней посмотрел, там у вас намешано.

легче сделать так:

Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
use master
go
create certificate [trace_cert] ENCRYPTION BY PASSWORD = 'some_strong_password' WITH SUBJECT = 'certificate_for_trace_events';
create login [trace_login] from certificate [trace_cert];

BACKUP CERTIFICATE [trace_cert] TO FILE = 'C:\temp\trace_cert.cer'  
     WITH PRIVATE KEY   
      (   
        FILE = 'C:\temp\trace_cert.pvk' ,  
        ENCRYPTION BY PASSWORD = 'storng_password'   
        ,DECRYPTION BY PASSWORD = 'storng_password'   
      );

grant alter trace to [trace_login];
go

use db_task
go

create certificate [trace_cert] from file = 'C:\temp\trace_cert.cer' with private key (FILE = 'C:\temp\trace_cert.pvk' ,  
        ENCRYPTION BY PASSWORD = 'storng_password'   
        ,DECRYPTION BY PASSWORD = 'storng_password');
go

create or alter procedure log.spLogSimple @logMsg  nvarchar(255), @logData nvarchar(2048) = null --with execute as 'user_log'
as
begin
    declare @m xml= (select @logMsg  as LogMsg , @logData as LogData for xml raw  ('AsyncLogMessageSimple'), elements) 
    declare @a nvarchar(128) = 'AsyncLogMessageSimple'
    declare @b varbinary(8000) = cast(@m as varbinary(8000));
    exec sp_trace_generateevent 82, @a, @b;
end
go

add signature to [spLogSimple] by certificate [trace_cert] with password = 'strong_password';
go



тогда вам не надо парится с переключением контекстов и их правами.
у вас права выданные логину trace_login будут применены на вызов модуля который подписан соответствующим сертификатом.

писал по памяти может где то с синтаксисом накосячил.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748834
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
felix_ff, Сработало )
На память получилось очень точно )))

Понятно, то есть нельзя просто так сказать "выполни от этого логина", он должен как то "логиниться", и это возможно автоматически если создать логин с сертификатом.
Код: sql
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
21.
22.
23.
24.
25.
26.
27.
28.
29.
30.
31.
32.
33.
34.
35.
36.
37.
38.
39.
40.
41.
42.
43.
44.
45.
46.
47.
48.
49.
50.
51.
52.
53.
54.
55.
56.
57.
58.
59.
60.
61.
62.
63.
64.
65.
66.
67.
68.
69.
70.
71.
72.
73.
74.
75.
76.
77.
78.
79.
80.
81.
82.
83.
84.
85.
86.
87.
88.
89.
90.
91.
92.
93.
94.
95.
96.
97.
98.
99.
100.
101.
102.
103.
104.
105.
106.
107.
108.
109.
110.
111.
112.
113.
114.
115.
116.
117.
118.
119.
use master
go
if exists (select 1 from sys.databases where name='db_task')
    drop database db_task

go

if exists (select 1 from master.sys.server_principals where name = 'login_db_owner')
    drop login login_db_owner
go

if exists (select * from master.sys.server_principals where name = 'login_task')
    drop login login_task
go

if exists (select * from master.sys.server_principals where name = 'login_trace')
    drop login login_trace
go
use master
go

-------------------------------------------------------------------
create database db_task
go

create login login_db_owner with password = 'login_db_owner'
go
create login login_task with password = 'login_task'
go

---------------------------------------------------------------
-- СЕРТИФИКАТ
-- drop certificate [trace_cert]

-- create certificate [trace_cert] encryption by password = 'some_strong_password' with subject = 'certificate_for_trace_events';

-- backup certificate [trace_cert] to file = 'c:\svn\trace_cert.cer'  with private key   
--  ( file = 'c:\svn\trace_cert.pvk',encryption by password = 'some_strong_password', decryption by password = 'some_strong_password' );

create login login_trace from certificate [trace_cert];
go
use master
go
grant alter trace to login_trace;
go
---------------------------------------------------------------

-- собственник баз - login_db_owner
alter authorization on database::db_task to login_db_owner
go

-----------------
-- пользователи в базах
use db_task
go

create user user_task for login login_task
go

alter role db_datareader add member user_task
alter role db_datawriter add member user_task
go
grant exec to user_task
go

--------------------------
-- тестовая ХП бизнес логики и обертка над sp_trace_generateevent
use db_task
go
create schema log
go

create certificate [trace_cert] from file = 'c:\svn\trace_cert.cer' with private key (file = 'c:\svn\trace_cert.pvk' ,  
        encryption by password = 'some_strong_password'   
        ,decryption by password = 'some_strong_password');

go
create procedure log.spLogSimple @logMsg  nvarchar(255), @logData nvarchar(2048) = null -- with execute as 'user_log'
as
begin
    declare @m xml= (select @logMsg  as LogMsg , @logData as LogData for xml raw  ('AsyncLogMessageSimple'), elements) 
    declare @a nvarchar(128) = 'AsyncLogMessageSimple'
    declare @b varbinary(8000) = cast(@m as varbinary(8000));
    exec sp_trace_generateevent 82, @a, @b;
end
go
add signature to log.spLogSimple by certificate [trace_cert] with password = 'some_strong_password';
go
go
create procedure SomeTaskProc as
begin
    exec log.spLogSimple 'SomeTaskProc start', 'args1'
    waitfor delay '00:00:01.000'
    exec log.spLogSimple 'SomeTaskProc finish', 'args2'
end
go

---------------------------------------------------------
use db_task
go
-- эмитируем вызов хранимки бизнес логики от логина login_task
execute as login = 'login_task'

    begin try
        print 'Current login/user: ['+isnull(SUSER_NAME(), 'null')+']/['+isnull(current_user, 'null')+'], call SomeTaskProc...'
        exec SomeTaskProc
        print 'Ok'
    end try
    begin catch
        print 'Error in SomeTaskProc'
        print '@error_procedure = '+  isnull(                error_procedure() ,'null')
        print '@error_line      = '+  isnull(convert(varchar,error_line     ()),'null')
        print '@error_number    = '+  isnull(convert(varchar,error_number   ()),'null')
        print '@error_message   = '+  isnull(                error_message  () ,'null')
        print '@error_severity  = '+  isnull(convert(varchar,error_severity ()),'null')
        print '@error_state     = '+  isnull(convert(varchar,error_state    ()),'null')
    end catch

revert


Осталось срастить очередями, понять что-там с диалогами точно происходит и натянуть свои более сложные обработчики.

Единственное, НО, решение в итоге получается не такое уж и тривиальное, если через год за базу возьмутся менее опытные коллеги, что-то сломается, может получиться что им будет проще свой велосипед чем это отремонтировать.

И есть вопросы как это будет себя вести с бэкапами и переносом баз.
Сертификат как я понимаю живет в сервере, если я переношу базу на другой сервер - то там нужно сертификат "подгружать"и обновлять add signature to log.spLogSimple? или делать новый сертификат и переподписывать log.spLogSimple?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39748839
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикПонятно, то есть нельзя просто так сказать "выполни от этого логина", он должен как то "логиниться", и это возможно автоматически если создать логин с сертификатом. https://docs.microsoft.com/ru-ru/previous-versions/sql/sql-server-2008-r2/ms188304(v=sql.105)
КифирчикСертификат как я понимаю живет в сервереСертификат живет в той БД, где был создан.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39749732
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Еще одна паталогия.
Столбец слева - это время вызова eventa, берется перед самим вызовом, то есть реальное время сработки вызова в ХП.
Столбец справа - это временная метка записи в таблицу с логами, то есть порядок обработки сообщений (desc).

Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
LogDatetime              Stamp
2018-12-18 16:48:19.507  0x00000000000B8C0F
2018-12-18 16:48:04.230  0x00000000000B8C0E
2018-12-18 16:48:35.720  0x00000000000B8C0D
2018-12-18 16:48:19.563  0x00000000000B8C0C
2018-12-18 16:48:35.700  0x00000000000B8C0B
2018-12-18 16:48:35.687  0x00000000000B8C08
2018-12-18 16:48:35.683  0x00000000000B8C07
2018-12-18 16:48:35.493  0x00000000000B8C06
2018-12-18 16:48:35.490  0x00000000000B8C05
2018-12-18 16:48:35.490  0x00000000000B8C04
2018-12-18 16:48:19.357  0x00000000000B8C03
2018-12-18 16:48:11.397  0x00000000000B8C02

Предполагалось что Stamp сможет определить верный порядок вызовов Event, но в столбце LogDateTime данные вперемешку.
В инструкции к RECEIVE сказано - "Результирующий набор, возвращенный инструкцией RECEIVE, неявно упорядочен."
То есть очередь как получила, так и выдает (видимо в обратном порядке, order by к очереди не применимо).

Получается event-ы доходят в очередь не всегда в порядке их вызова?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39749760
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчик,

именно, очередь сообщений гарантируется только в рамках одного диалога, а не кучи диалогов.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39749886
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Мде...
еще два вопроса:
1) conversation, диалог, относительно Notify event, где его рамки? вызов одной ХП? или пакета?
2) можно ли сделать так чтоб сами notify event и сообщения типа "The activated proc '[log].[AsyncLogQueueProcessing]' running on queue 'VTSDB2_LOG.log.AsyncLogQueue' output the following: 'exec spLogSimpleDo1'" не валились в журнал MSSQL? это как-нибудь настраивается?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39749907
felix_ff
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикМде...
еще два вопроса:
1) conversation, диалог, относительно Notify event, где его рамки? вызов одной ХП? или пакета?
2) можно ли сделать так чтоб сами notify event и сообщения типа "The activated proc '[log].[AsyncLogQueueProcessing]' running on queue 'VTSDB2_LOG.log.AsyncLogQueue' output the following: 'exec spLogSimpleDo1'" не валились в журнал MSSQL? это как-нибудь настраивается?

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

2) у вас сообщения в журнал могут сыпаться если у вас уведомление о событии не получается доставить. что детально в сообщении лога написано?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39749965
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Кифирчикconversation, диалог, относительно Notify event, где его рамки? вызов одной ХП? или пакета?Вас это вообще не должно волновать. Отметка времени должна приходить вместе с логируемым сообщением. Не следует привязываться к порядку поступления сообщений и, тем более, к порядку строк в таблице логов.
Не нужно завершать диалог на каждый чих. Не вы этот диалог начали - не вам и завершать.
Завершать нужно лишь в ответ на EndDialog и Error и без опции with cleanup (мой косяк в примере). Данная опция служит для аварийного завершения.
И проверьте что твориться в sys.conversation_endpoints в msdb и VTSDB2_LOG.
Кифирчикможно ли сделать так чтоб сами notify event и сообщения типа "The activated proc '[log].[AsyncLogQueueProcessing]' running on queue 'VTSDB2_LOG.log.AsyncLogQueue' output the following: 'exec spLogSimpleDo1'" не валились в журнал MSSQL? это как-нибудь настраивается?Уберите весь диагностический вывод из процедуры log.AsyncLogQueue.
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39750250
Кифирчик
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
Блин, точно
"The activated proc '[log].[AsyncLogQueueProcessing]' running on queue 'VTSDB2_LOG.log.AsyncLogQueue' output the following: 'exec spLogSimpleDo1'
это PRINT 'exec spLogSimpleDo1' внутри AsyncLogQueueProcessing

invmВас это вообще не должно волновать. Отметка времени должна приходить вместе с логируемым сообщением. Не следует привязываться к порядку поступления сообщений и, тем более, к порядку строк в таблице логов.
К сожалению отметки времени не уникальны, могут приходить две (и даже 5) одинаковые, и тогда проблематично понять в какой последовательности они появились. Если диалог в очереди имеет границы например в рамках одного @spid, или внутри одной ХП - то это позволило бы точно сохранить порядок вызовов, исходя из порядка появления сообщений в очереди.
Иначе - нужно формировать Stamp перед отправкой логируемого сообщения. Или последовательность длинючую использовать.

Нужно и правда сделать эксперимент, сохраняя в обработчике очереди handle диалога. Мало ли, мне бы это много упростило )

sys.conversation_endpoints
LOG
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
conversation_handle	conversation_id	is_initiator	service_contract_id	conversation_group_id	service_id	lifetime	state	state_desc	far_service	far_broker_instance	principal_id	far_principal_id	outbound_session_key_identifier	inbound_session_key_identifier	security_timestamp	dialog_timer	send_sequence	last_send_tran_id	end_dialog_sequence	receive_sequence	receive_sequence_frag	system_sequence	first_out_of_order_sequence	last_out_of_order_sequence	last_out_of_order_frag	is_system	priority
B7B2F36D-72FF-E811-8127-0CC47A70A1C0	A08BFD0B-64C5-4B63-A087-B8E7B9A8F976	0	2	00000000-0000-0000-0000-000000000000	65561	2087-01-01 10:44:50.107	CD	CLOSED	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	11	0	0	-1	0	0	0	5
DEA109ED-95FF-E811-8127-0CC47A70A1C0	172476B0-6464-4DB9-A6CA-434B14087F3F	0	2	00000000-0000-0000-0000-000000000000	65561	2087-01-01 10:44:50.107	CD	CLOSED	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	8	0	0	-1	0	0	0	5
D64E0EF4-A8FF-E811-8127-0CC47A70A1C0	A3A3467B-5E23-4942-A844-827CA59B7B93	0	2	00000000-0000-0000-0000-000000000000	65561	2087-01-01 10:44:50.107	CD	CLOSED	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	4	0	0	-1	0	0	0	5
8C5D3F74-B0FF-E811-8127-0CC47A70A1C0	59930D03-6E20-4EB1-A76E-4C4C554A11D7	0	2	8B5D3F74-B0FF-E811-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.443	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	270110	0	0	-1	0	0	0	5
65D5176F-4500-E911-8127-0CC47A70A1C0	337D1522-475E-4F85-B91D-CF9AA493DF0E	0	2	64D5176F-4500-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	35229	0	0	-1	0	0	0	5
D686F8A0-FD00-E911-8127-0CC47A70A1C0	ACF3043A-465D-44BE-81BB-AEF2F3A098AA	0	2	D586F8A0-FD00-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	49503	0	0	-1	0	0	0	5
548A006E-1701-E911-8127-0CC47A70A1C0	1E5D472B-A2AB-46BF-9B1E-D2809A0B6054	0	2	538A006E-1701-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.443	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	56359	0	0	-1	0	0	0	5
53C289A0-2C01-E911-8127-0CC47A70A1C0	F7773E74-D6F1-44F1-9DC6-8CC624698FA7	0	2	52C289A0-2C01-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	51491	0	0	-1	0	0	0	5
D8AC24B0-3001-E911-8127-0CC47A70A1C0	F548C0BF-B19B-490F-A136-E147B2C018F6	0	2	D7AC24B0-3001-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	76844	0	0	-1	0	0	0	5
4BB85015-3801-E911-8127-0CC47A70A1C0	B23C5BD4-2E68-49D8-8CDB-BD8DC2C0DD05	0	2	4AB85015-3801-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	59348	0	0	-1	0	0	0	5
7A4EEBD8-4801-E911-8127-0CC47A70A1C0	CF68993D-DEEB-4C19-8A99-1343EEF5661B	0	2	794EEBD8-4801-E911-8127-0CC47A70A1C0	65562	2087-01-01 18:10:44.440	CO	CONVERSING	 http://schemas.microsoft.com/SQL/Notifications/EventNotificationService 	E6F81215-B045-463F-BF31-96D7359B35B4	1	1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	0	0x000000000000	-1	47554	0	0	-1	0	0	0	5

msdb
Код: plaintext
1.
2.
3.
4.
5.
6.
7.
8.
9.
conversation_handle	conversation_id	is_initiator	service_contract_id	conversation_group_id	service_id	lifetime	state	state_desc	far_service	far_broker_instance	principal_id	far_principal_id	outbound_session_key_identifier	inbound_session_key_identifier	security_timestamp	dialog_timer	send_sequence	last_send_tran_id	end_dialog_sequence	receive_sequence	receive_sequence_frag	system_sequence	first_out_of_order_sequence	last_out_of_order_sequence	last_out_of_order_frag	is_system	priority
9DC46B29-72FF-E811-8127-0CC47A70A1C0	FFFB9CA6-2C5D-4CA1-BFCE-2BEC0ACE3B98	1	2	00000000-0000-0000-0000-000000000000	2	2087-01-01 10:44:50.107	DO	DISCONNECTED_OUTBOUND	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	4603	0x625CED000000	4603	0	0	0	-1	0	0	1	5
745D3F74-B0FF-E811-8127-0CC47A70A1C0	F548C0BF-B19B-490F-A136-E147B2C018F6	1	2	755D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	76844	0x2A20EF000000	-1	0	0	0	-1	0	0	1	5
775D3F74-B0FF-E811-8127-0CC47A70A1C0	ACF3043A-465D-44BE-81BB-AEF2F3A098AA	1	2	785D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	49503	0xD81EEF000000	-1	0	0	0	-1	0	0	1	5
7A5D3F74-B0FF-E811-8127-0CC47A70A1C0	B23C5BD4-2E68-49D8-8CDB-BD8DC2C0DD05	1	2	7B5D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	59348	0x5A21EF000000	-1	0	0	0	-1	0	0	1	5
7D5D3F74-B0FF-E811-8127-0CC47A70A1C0	F7773E74-D6F1-44F1-9DC6-8CC624698FA7	1	2	7E5D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	51491	0x5D1FEF000000	-1	0	0	0	-1	0	0	1	5
805D3F74-B0FF-E811-8127-0CC47A70A1C0	337D1522-475E-4F85-B91D-CF9AA493DF0E	1	2	815D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	35229	0x821FEF000000	-1	0	0	0	-1	0	0	1	5
835D3F74-B0FF-E811-8127-0CC47A70A1C0	CF68993D-DEEB-4C19-8A99-1343EEF5661B	1	2	845D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.440	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	47554	0x1EF7EE000000	-1	0	0	0	-1	0	0	1	5
865D3F74-B0FF-E811-8127-0CC47A70A1C0	59930D03-6E20-4EB1-A76E-4C4C554A11D7	1	2	875D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.443	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	270110	0xA627EF000000	-1	0	0	0	-1	0	0	1	5
895D3F74-B0FF-E811-8127-0CC47A70A1C0	1E5D472B-A2AB-46BF-9B1E-D2809A0B6054	1	2	8A5D3F74-B0FF-E811-8127-0CC47A70A1C0	2	2087-01-01 18:10:44.443	CO	CONVERSING	AsyncLogService	D775EE0B-292D-4712-AECB-89C4559A6ED8	4	-1	00000000-0000-0000-0000-000000000000	00000000-0000-0000-0000-000000000000	1900-01-01 00:00:00.000	1900-01-01 00:00:00.000	56359	0x9E27EF000000	-1	0	0	0	-1	0	0	1	5

в таблицах все очень плохо? должны быть пустые?
...
Рейтинг: 0 / 0
Service broker для логирования, глюки
    #39750269
invm
Скрыть профиль Поместить в игнор-лист Сообщения автора в теме
Участник
КифирчикК сожалению отметки времени не уникальны, могут приходить две (и даже 5) одинаковые, и тогда проблематично понять в какой последовательности они появились. Если диалог в очереди имеет границы например в рамках одного @spid, или внутри одной ХП - то это позволило бы точно сохранить порядок вызовов, исходя из порядка появления сообщений в очереди.
Иначе - нужно формировать Stamp перед отправкой логируемого сообщения. Или последовательность длинючую использовать. Заведите в VTSDB2_LOG sequence, дергайте из него значения в других БД и передавайте полученное в сообщении.
Кифирчикв таблицах все очень плохо? должны быть пустые?Нет, все более-менее.
Из той, которая в LOG, нужно прибить строки с state_desc = 'CLOSED' путем вызовов end conversation ... with clean up
...
Рейтинг: 0 / 0
43 сообщений из 43, показаны все 2 страниц
Форумы / Microsoft SQL Server [игнор отключен] [закрыт для гостей] / Service broker для логирования, глюки
Найденые пользователи ...
Разблокировать пользователей ...
Читали форум (0):
Пользователи онлайн (0):
x
x
Закрыть


Просмотр
0 / 0
Close
Debug Console [Select Text]