marcingminski / sqlwatch

SQL Server Performance Monitor
https://docs.sqlwatch.io
Other
428 stars 168 forks source link

SQL-IMPORTER job throws error. #437

Closed DickUMCG closed 1 year ago

DickUMCG commented 2 years ago

Describe the bug

Got a bunch of servers added but now I got the following error-message when our scheduled job which runs every 5 minutes finishes:

Server repository-server Job Name SQLWATCH-IMPORTER Step Name SQLWatch - import Duration 00:00:25 Sql Severity 0 Sql Message ID 0 Operator Emailed
Operator Net sent
Operator Paged
Retries Attempted 0

Message 2022-02-01 17:00:25.816 ERROR Failed to merge table "[server0978].dbo.sqlwatch_logger_xes_iosubsystem" at Cannot insert duplicate key row in object 'dbo.sqlwatch_logger_xes_iosubsystem' with unique index 'idx_sqlwatch_xes_iosubsystem_event_time'. The duplicate key value is (Jan 27 2022 7:26PM). ;merge dbo.sqlwatch_logger_xes_iosubsystem as target using ( select s. from [#dbo.sqlwatch_logger_xes_iosubsystem] s inner join dbo.sqlwatch_logger_snapshot_header h on s.[snapshot_time] = h.[snapshot_time] and s.[snapshot_type_id] = h.[snapshot_type_id] and s.[sql_instance] = h.[sql_instance]) as source on (source.[snapshot_time] = target.[snapshot_time] and source.[snapshot_type_id] = target.[snapshot_type_id] and source.[sql_instance] = target.[sql_instance] and source.[event_time] = target.[event_time]) when not matched then insert ([event_time],[io_latch_timeouts],[total_long_ios],[longest_pending_request_file],[longest_pending_request_duration],[snapshot_time],[snapshot_type_id],[sql_instance]) values (source.[event_time],source.[io_latch_timeouts],source.[total_long_ios],source.[longest_pending_request_file],source.[longest_pending_request_duration],source.[snapshot_time],source.[snapshot_type_id],source.[sql_instance]); 2022-02-01 17:00:25.827 ERROR Failed to merge table "[server0978].dbo.sqlwatch_logger_xes_query_processing" at Cannot insert duplicate key row in object 'dbo.sqlwatch_logger_xes_query_processing' with unique index 'idx_sqlwatch_xes_query_processing_event_time'. The duplicate key value is (Jan 27 2022 7:26PM). ;merge dbo.sqlwatch_logger_xes_query_processing as target using ( select s. from [#dbo.sqlwatch_logger_xes_query_processing] s inner join dbo.sqlwatch_logger_snapshot_header h on s.[snapshot_time] = h.[snapshot_time] and s.[snapshot_type_id] = h.[snapshot_type_id] and s.[sql_instance] = h.[sql_instance]) as source on (source.[snapshot_time] = target.[snapshot_time] and source.[snapshot_type_id] = target.[snapshot_type_id] and source.[sql_instance] = target.[sql_instance] and source.[event_time] = target.[event_time]) when not matched then insert ([event_time],[max_workers],[workers_created],[idle_workers],[pending_tasks],[unresolvable_deadlocks],[deadlocked_scheduler],[snapshot_time],[snapshot_type_id],[sql_instance]) values (source.[event_time],source.[max_workers],source.[workers_created],source.[idle_workers],source.[pending_tasks],source.[unresolvable_deadlocks],source.[deadlocked_scheduler],source.[snapshot_time],source.[snapshot_type_id],source.[sql_instance]);

The duplicate key value doesn't really make sense to me. The server which throws the error was added to the repository today.

To Reproduce Steps to reproduce the behavior:

  1. Go to..
  2. Click this..

Running manually SQLWatchimport.exe results in the same error-message. Data seems to be refreshed.

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Took a look at table dbo.sqlwatch_logger_exes_query_processing and encountered 'old' data which was I guess taken at the first snapshot this morning.

image

Windows Server (please complete the following information):

SQL Server (please complete the following information):

SQL Server Management Studio (SSMS -> about -> copy info):

SQLWATCH version (from DACPAC or from sysinstances)

Additional context Add any other context about the problem here.

DickUMCG commented 2 years ago

Update: In the repository database the sqlwatch_logger_xes_query_processing-table doesn't show entries for this partical instance. But...

image

So, there was another sql_instance with particular data with exactly the same timestamp.

That must be causing this. Do we need a modification of the index. With multiple instances events can occur at exactly the same time.

DickUMCG commented 2 years ago

Continue:

I tried issuing this on the repository-database:

update sqlwatch_logger_xes_query_processing set event_time='2022-01-27 19:26:49.136' where event_time='2022-01-27 19:26:49.137'

This results in 1 row affected and committed, but when querying again it still shows the old value.

So tried it on the server which can't pass the information but this results in the same.

As the information is not that important I did a delete of the culprit on the server with problems and ran SQLWatchimport again, and this time it complains about the next entry in the table with the timestamp 5 minutes later.

Next step:

image

Now no errors on this table anymore. But the next table :

2022-02-01 17:43:52.170 ERROR Failed to merge table "[server0978].dbo.sqlwatch_logger_xes_iosubsystem" at Cannot insert duplicate key row in object 'dbo.sqlwatch_logger_xes_iosubsystem' with unique index 'idx_sqlwatch_xes_iosubsystem_event_time'. The duplicate key value is (Jan 27 2022 7:26PM). ;merge dbo.sqlwatch_logger_xes_iosubsystem as target using ( select s.* from [#dbo.sqlwatch_logger_xes_iosubsystem] s inner join dbo.sqlwatch_logger_snapshot_header h on s.[snapshot_time] = h.[snapshot_time] and s.[snapshot_type_id] = h.[snapshot_type_id] and s.[sql_instance] = h.[sql_instance]) as source on (source.[snapshot_time] = target.[snapshot_time] and source.[snapshot_type_id] = target.[snapshot_type_id] and source.[sql_instance] = target.[sql_instance] and source.[event_time] = target.[event_time]) when not matched then insert ([event_time],[io_latch_timeouts],[total_long_ios],[longest_pending_request_file],[longest_pending_request_duration],[snapshot_time],[snapshot_type_id],[sql_instance]) values (source.[event_time],source.[io_latch_timeouts],source.[total_long_ios],source.[longest_pending_request_file],source.[longest_pending_request_duration],source.[snapshot_time],source.[snapshot_type_id],source.[sql_instance]);

Another index modification:

image

This time Sqlwatchimport.exe completes without errors:

image

pluim003 commented 2 years ago

Update: I'm moving stuff from DickUMCG to my other account and will close the other one. Inconvenient to use 2 accounts. Forked repository has also been transferred.

pluim003 commented 2 years ago

Another thing. Discovered now that in the repository database there were about 170 tables named _DUMP_20220201_timestamp_server_tablename . Had to remove those manually (fortunately with one statement :-) ).

marcingminski commented 2 years ago

This has already been explained in: https://github.com/marcingminski/sqlwatch/issues/394#issuecomment-866930750

pluim003 commented 2 years ago

@marcingminski but shouldn't the index-definitions be changed to prevent this?

marcingminski commented 2 years ago

To prevent errors? Are those errors caused by the index?

pluim003 commented 2 years ago

Yep. As event_time might be the same for more sql_instances.

pluim003 commented 2 years ago

Made a new pullrequest to remove some typos