來自 Service Broker / Activation 過程的令人困惑的錯誤消息
我的 SQL Server 遇到了一個非常令人困惑的問題,我希望有人能給我提示如何調試這個問題。
喝杯咖啡什麼的,這會有點複雜。一路上你可能會想,“好吧,你一直在要求這個!除了你自己,你沒有人可以責備!”。你甚至可能是對的。但我保證,在此過程中的每一步,我都盡我所能,我相信我的決定是有正當理由的。
Soooo,我們使用了一個鮮為人知的 ERP 軟體和一個產品/項目數據管理系統 (PDM)。實際上,我們目前正處於設置 PDM 系統的最後一步(我們希望如此),因此我們最終可以將它介紹給我們的使用者。
為了有用,PDM 系統需要有關於 ERP 系統中發生的事情的實時資訊,例如在 ERP 系統中創建項目或創建各種文件(訂單、發票、報價單)時, ETC。)。
我面臨的問題與告訴 PDM 系統有關 ERP 系統的新項目有關。ERP 和 PDM 系統都使用 MS SQL Server 數據庫作為後端(顯然,每個都使用自己的數據庫)。為了讓事情變得更有趣,我們還創建了一個傳輸數據庫,作為數據從 ERP 到 PDM 數據庫的中間步驟(但它只有一個表)。
我的第一個想法是在儲存項目的 ERP 數據庫中的表上創建一個觸發器,以在傳輸數據庫中插入相應的記錄。但是我的研究使我認為這通常被認為是一個壞主意,因為在傳輸數據過程中的任何小問題都會導致創建項目的初始交易失敗。不用說,我們的使用者不會非常喜歡這樣。
不過,我遇到了一個建議,即使用 SQL Server 附帶的 Service Broker 並使用消息隊列來解耦這些步驟。我喜歡這個想法,因為我想避免編寫、設置和維護另一個程序來傳輸數據。如果我可以將所有內容都保存在數據庫實例中,我想,事情會更容易理解。我可能錯了,但我不完全確定我可以做得更好。
因此,在目前設置下,數據流如下所示:
- 使用者創建一個新項目
- ERP 數據庫中項目表上的觸發器提取有關項目的一些元數據,創建 XML 消息並將其寫入消息隊列。
- 這會觸發一個啟動過程以從隊列中讀取消息、提取元數據並將記錄插入傳輸數據庫。
- 傳輸數據庫/表上的觸發器讀取新記錄,進行一些數據處理並將新記錄插入到儲存 PDM 端項目的 PDM 數據庫表中(這反過來會導致觸發器執行,從而導致觸發器執行) . 這個觸發器最初是由向我們出售 PDM 軟體的公司的一位顧問編寫的,但由於那個顧問比我貴得多,所以維護那個東西就落在了我的腿上。(為了清楚起見,我確實有點喜歡它。一般來說。這是一項有趣的工作,我可以幫助彌合人們有時會在 IT 方面和業務方面看到的差距。)
我們在測試系統上重新創建了 ERP 數據庫、Transfer 數據庫和 PDM 數據庫的完整設置。這就是事情變得非常奇怪的地方。
如果我們在 ERP 測試實例中創建一個新項目,它不會到達。
我看到 XML 消息到達消息隊列,它看起來與我期望的差不多。但從那裡開始,事情就橫向發展了。在 SQL Server 實例的錯誤日誌文件中,出現許多消息告訴我:“已啟動的 proc
$$ dbo $$.$$ PDM_Transfer $$在隊列’MyCompany.dbo.project_transfer_queue’上執行輸出以下內容:將varchar值’FEHLER’轉換為數據類型int時轉換失敗。“如果重要:FEHLER是德語的錯誤。我們位於德國,所以是這並不奇怪——不過,錯誤消息的其餘部分是英文的。我發現這條消息令人困惑,因為我的 sproc 嘗試將文本轉換為整數的唯一地方是從已填充的 XML 消息中提取欄位時來自 ERP 數據庫的整數值。據我所知,除了有效的整數文字外,幾乎不可能出現任何東西。當我檢查 XML 消息時,就像我說的那樣,它們看起來像我期望的那樣他們到。 如果在整個觸發器和儲存過程鏈中的某個點,某些程式碼實際上試圖將字元串“FEHLER”轉換為 int,那麼失敗也就不足為奇了。但我不知道在哪裡會發生這種情況以及為什麼會發生這種情況。
為了讓事情變得更加混亂,我停用了消息隊列上的儲存過程(從某種意義上說,它不再被自動呼叫。然後我從 SSMS 調試器手動呼叫儲存過程。它完全按照應有的方式工作。
那時我開始懷疑這可能是權限問題。通常,消息隊列上的啟動過程在專用使用者下執行,當我手動呼叫儲存過程時,它(顯然)在我的使用者帳戶下執行,該使用者帳戶(幾乎)對測試數據庫具有不受限制的權限。
所以我檢查了消息隊列上執行啟動過程的帳戶,將其權限與生產系統中的權限進行了比較。我發現了一些差異,但在我修復了這些差異之後,問題仍然存在。
為了更加確定,我刪除了所有服務代理對象並重新創建了它們。
到目前為止,我已經走到了盡頭。誰能給我一個提示,我可以在哪裡尋找問題的根本原因?
非常感謝,本傑明
編輯:正如 Aaron Bertrand 所建議的,這裡是受它影響的 sproc 和 table/s 的原始碼。我試圖使原始碼盡可能可讀,並添加一些註釋來解釋我認為不明顯的事情。但是原始碼有點長(至少按照我的標準),所以我可能錯過了很多地方。如果您看到不清楚的地方,如果您問,我會很樂意解釋。
似乎原始碼格式不正確。不知道是太長還是太醜。我不知道如何解決它。:-(
因此,事不宜遲,我們開始:
CREATE PROCEDURE dbo.ProFile_Transfer AS BEGIN DECLARE @conversation_handle UNIQUEIDENTIFIER; DECLARE @messagetypename VARCHAR(256); DECLARE @messagebody XML; DECLARE @message_type VARCHAR(MAX); DECLARE @transaction_name VARCHAR(MAX); DECLARE @tmp VARCHAR(MAX); DECLARE @projektnummer VARCHAR(MAX); DECLARE @kurztext VARCHAR(MAX); DECLARE @vertreter VARCHAR(MAX); DECLARE @anlagedatum DATETIME; DECLARE @kundennummer INT; DECLARE @status INT; DECLARE @vorgang VARCHAR(MAX); DECLARE @kunde VARCHAR(MAX); DECLARE @kunde2 VARCHAR(MAX); DECLARE @anschrift VARCHAR(MAX); DECLARE @ort VARCHAR(MAX); DECLARE @telefon VARCHAR(MAX); DECLARE @fax VARCHAR(MAX); DECLARE @kostenstelle INT; DECLARE @LOGMSG VARCHAR(MAX); DECLARE @MSGLEN INT; SET NOCOUNT ON; -- Originally, the ERP database and the PDM database resided on -- different SQL servers, therefore we use a distributed transaction. -- Both databases now reside in the same SQL Server instance, so -- the distributed transaction is not required any more. -- I have decided to keep it nevertheless, because I am not sure -- of the implications. BEGIN DISTRIBUTED TRANSACTION; BEGIN TRY WAITFOR( RECEIVE TOP (1) @conversation_handle = conversation_handle, @messagetypename = message_type_name, @messagebody = CAST(message_body AS XML) FROM projekt_transfer_rcv_queue), TIMEOUT 60000; IF @@ROWCOUNT = 0 BEGIN ROLLBACK TRANSACTION; RETURN 0; END; -- IF (@@ROWCOUNT = 0) SET @MSGLEN = DATALENGTH(@messagebody); IF @messagetypename = 'projekt_transfer_message' BEGIN SET @projektnummer = @messagebody.value( '(Message/Projektnummer/text())[1]', 'VARCHAR(40)' ); SET @vorgang = @messagebody.value( '(Message/Vorgang/text())[1]', 'VARCHAR(40)' ); SET @kurztext = @messagebody.value( '(Message/Kurztext/text())[1]', 'VARCHAR(40)' ); SET @vertreter = @messagebody.value( '(Message/Vertreter/text())[1]', 'VARCHAR(40)' ); SET @anlagedatum = @messagebody.value( '(Message/Anlagedatum/text())[1]', 'DATETIME' ); SET @kundennummer = @messagebody.value( '(Message/Kundennummer/text())[1]', 'INT' ); SET @status = @messagebody.value( '(Message/Projektstatus/text())[1]', 'VARCHAR(40)' ); SET @kunde = @messagebody.value( '(Message/Kunde/text())[1]', 'VARCHAR(40)' ); SET @kunde2 = @messagebody.value( '(Message/Kunde2/text())[1]', 'VARCHAR(40)' ); SET @anschrift = @messagebody.value( '(Message/Anschrift/text())[1]', 'VARCHAR(40)' ); SET @ort = @messagebody.value( '(Message/Ort /text())[1]', 'VARCHAR(40)' ); SET @telefon = @messagebody.value( '(Message/Telefon/text())[1]', 'VARCHAR(40)' ); SET @fax = @messagebody.value( '(Message/Fax/text())[1]', 'VARCHAR(40)' ); SET @kostenstelle = @messagebody.value( '(Message/Kostenstelle/text())[1]', 'VARCHAR(40)' ); -- dbg_log is an sproc that writes a log message to a dedicated table in the -- PDM transfer database. This was meant to help me in debugging, but it turned out -- less helpful than I had hoped. SET @tmp = 'ProjektXFR - '+@projektnummer+' ('+ @vorgang+')'; EXEC dbg_log @tmp; -- The maximum length of various VARCHAR fields in the ERP database -- is longer than the corresponding fields in the PDM database. -- In order to prevent errors, we explicitly check the fields, and -- if any of them are too long, we truncate them manually and emit -- a log message. IF DATALENGTH(@projektnummer) > 40 BEGIN SET @LOGMSG = 'Projektnummer "'+ @projektnummer+'" ist zu lang: '+CAST( DATALENGTH(@projektnummer) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@vorgang) > 40 BEGIN SET @LOGMSG = 'Vorgangsart "'+@vorgang+ '" ist zu lang: '+CAST(DATALENGTH(@vorgang) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@kurztext) > 40 BEGIN SET @LOGMSG = 'Kurztext "'+@kurztext+ '" ist zu lang: '+CAST(DATALENGTH(@kurztext) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@vertreter) > 40 BEGIN SET @LOGMSG = 'Vertreter "'+@vertreter+ '" ist zu lang: '+CAST(DATALENGTH( @vertreter) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@status) > 40 BEGIN SET @LOGMSG = 'Status "'+@status+ '" ist zu lang: '+CAST(DATALENGTH(@status) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@kunde) > 40 BEGIN SET @LOGMSG = 'Kunde "'+@kunde+ '" ist zu lang: '+CAST(DATALENGTH(@kunde) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@kunde2) > 40 BEGIN SET @LOGMSG = 'Kunde2 "'+@kunde2+ '" ist zu lang: '+CAST(DATALENGTH(@kunde2) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@anschrift) > 40 BEGIN SET @LOGMSG = 'Anschrift "'+@anschrift+ '" ist zu lang: '+CAST(DATALENGTH( @anschrift) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@ort) > 40 BEGIN SET @LOGMSG = 'Ort "'+@ort+'" ist zu lang: '+ CAST(DATALENGTH(@ort) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@telefon) > 40 BEGIN SET @LOGMSG = 'Telefonnummer "'+@telefon+ '" ist zu lang: '+CAST(DATALENGTH(@telefon) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; IF DATALENGTH(@fax) > 40 BEGIN SET @LOGMSG = 'Faxnummer "'+@fax+ '" ist zu lang: '+CAST(DATALENGTH(@fax) AS VARCHAR(100)); EXEC dbg_log @LOGMSG; END; INSERT INTO TransferERPPRofile.dbo.TransferToPROFILEProject (MessageType, IDENT, DESC1, RESP_USER, CREATE_DATE, CUSTOMER_NO, PROJECT_STATUS, CUSTOMER_NAME, CUSTOMER_SHORTNAME, CUSTOMER_STREET, CUSTOMER_TOWN, CUSTOMER_TEL, CUSTOMER_FAX, COST_CENTER ) VALUES (@vorgang, @projektnummer, @kurztext, @vertreter, @anlagedatum, @kundennummer, @status, @kunde, @kunde2, @anschrift, @ort, @telefon, @fax, @kostenstelle ); END; ELSE BEGIN SET @tmp = 'Unbekannter bzw. unerwarteter Nachrichtentyp: '+ @messagetypename; PRINT @tmp; EXEC dbg_log @tmp; END; END CONVERSATION @conversation_handle; COMMIT TRANSACTION; END TRY BEGIN CATCH DECLARE @ERRORNO INT, @Severity TINYINT, @state SMALLINT, @LineNo INT, @message NVARCHAR(4000), @errmsg VARCHAR(MAX); SELECT @ERRORNO = ERROR_NUMBER(), @Severity = ERROR_SEVERITY(), @state = ERROR_STATE(), @LineNo = ERROR_LINE(), @Message = ERROR_MESSAGE(); DECLARE @x VARCHAR(MAX); SET @x = 'FEHLER '+@ERRORNO+ ' beim Lesen aus Message Queue, Zeile '+CAST(@LineNo AS VARCHAR(MAX))+': '+@message; ROLLBACK TRANSACTION; EXEC dbg_log @x; SET @x = 'XML-Nachrichtenlänge war '+CAST(@MSGLEN AS VARCHAR(MAX))+' bytes.'; EXEC dbg_log @x; END CATCH; END; CREATE PROCEDURE [dbo].[dbg_log] @msg varchar(max) --WITH EXECUTE AS 'anw' AS BEGIN TRY INSERT INTO TransferERPProfile.dbo.DebugLog( [Timestamp], [Message] ) VALUES( GETDATE(), @msg ); END TRY BEGIN CATCH END CATCH; GO USE [TransferERPProfile]; GO /****** Object: Table [dbo].[TransferToPROFILEProject] Script Date: 27.11.2017 08:27:05 ******/ SET ANSI_NULLS ON; GO SET QUOTED_IDENTIFIER ON; GO SET ANSI_PADDING ON; GO CREATE TABLE dbo.TransferToPROFILEProject (MessageID INT IDENTITY(1, 1) NOT NULL, MessageType VARCHAR(50) NOT NULL, MessageRetVal INT NULL, MessageRetDate DATETIME NULL, IDENT VARCHAR(50) NOT NULL, DESC1 VARCHAR(50) NULL, RESP_USER VARCHAR(50) NULL, CREATE_DATE DATETIME NOT NULL, CUSTOMER_NO INT NOT NULL, PROJECT_STATUS INT NULL, CUSTOMER_NAME VARCHAR(50) NULL, CUSTOMER_SHORTNAME VARCHAR(50) NULL, CUSTOMER_STREET VARCHAR(50) NULL, CUSTOMER_TOWN VARCHAR(50) NULL, CUSTOMER_TEL VARCHAR(50) NULL, CUSTOMER_FAX VARCHAR(50) NULL, COST_CENTER INT NULL, CONSTRAINT PK_TransferToPROFILEProject PRIMARY KEY CLUSTERED(MessageID ASC) WITH(PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 60) ON [PRIMARY]) ON [PRIMARY]; GO SET ANSI_PADDING OFF; GO EXEC sys.sp_addextendedproperty @name = N'MS_Description', @value = N'Transfertabelle für Daten aus Mosaik ins Pro.File', @level0type = N'SCHEMA', @level0name = N'dbo', @level1type = N'TABLE', @level1name = N'TransferToPROFILEProject'; GO CREATE TABLE [dbo].[DebugLog]( [ID] [int] IDENTITY(1,1) NOT NULL, [Timestamp] [datetime] NOT NULL, [Message] [varchar](max) NOT NULL, CONSTRAINT [PK_DebugLog] PRIMARY KEY CLUSTERED ( [ID] ASC )WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 60) ON [PRIMARY] ) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY] GO SET ANSI_PADDING OFF GO
以防萬一有人遇到這種問題,我想我已經找出了問題並找到了解決方案。根本原因顯然是我對 T-SQL 類型系統的尷尬誤解。
雖然不是最優雅的問題解決方法,但使用 grep 在我的 SQL 程式碼中搜尋字元串“FEHLER”的實例導致我在 SProc 末尾附近找到以下程式碼:
SET @x = 'FEHLER '+@ERRORNO+ ' beim Lesen aus Message Queue, Zeile '+CAST(@LineNo AS VARCHAR(MAX))+': '+@message;
@x
是 VARCHAR(MAX) 類型的變數。在大多數定義了 VARCHAR/STRING + INT 且合法的程式語言中,整數值會自動轉換為字元串/varchar。顯然,T-SQL 嘗試將第一部分 (
'FEHLER '
) 轉換為 INT。替換
@ERRORNO
為CONVERT(VARCHAR(MAX), @ERRORNO)
已使此問題消失。錯誤一直擺在我面前,我感到有點害羞,但至少我鬆了一口氣,因為它現在正在起作用。
乾杯,本傑明