August 27, 2014 at 1:57 pm
Last night the test team opened a strange ticked.
The app have a grid where the user can check incidents to be postponed
the tester selected two incidents (ids: 1 and 5), postponed both but one don't got the status updated
I know the [Incident] table must be updated and one new record inserted at the [IncidentDetail] table
I queried both and fond this:
Id IncidentKindCode TransportEntryId CreateDate IncidentStatus CloseDate
-- ---------------- ---------------- ---------------------- -------------- ---------
1 11301 52 2014-08-26 19:23:21.47 1 NULL
5 11301 56 2014-08-26 20:06:17.94 0 NULL
Id IncidentId InsertDate DetailKind Reason IncidentUser PostponeDate
-- ----------- ---------------------- ---------- --------- ------------ -----------------------
9 1 2014-08-26 20:28:37.37 1 TEST TEST 8 2014-08-27 00:00:00.000
10 5 2014-08-26 20:28:37.37 1 TEST TEST 8 2014-08-27 00:00:00.000
The tester complain is valid since both [Incident].[IncidentStatus] values must be zero at this point.
After digging in it I captured the exact query the app sent to the server (thanks to the profiler).
declare @p1 int
set @p1=2
exec sp_prepexec @p1 output,N'@IDINCIDENT varchar(max) ,@REASON varchar(max) ,@USERCODE varchar(max) ,@POSTPONEDATE varchar(max) ',N'
DECLARE @ARRAY VARCHAR(8000), @DELIMITADOR VARCHAR(100), @SELECTEDID VARCHAR(8000);
SELECT @ARRAY = @IDINCIDENT
SELECT @DELIMITADOR = '';''
IF LEN(@ARRAY) > 0 SET @ARRAY = @ARRAY + @DELIMITADOR
WHILE LEN(@ARRAY) > 0
BEGIN
SELECT @SELECTEDID = LTRIM(SUBSTRING(@ARRAY, 1,
CHARINDEX(@DELIMITADOR, @ARRAY) - 1))
BEGIN
UPDATE [dbo].Incident SET INCIDENTSTATUS = 1 WHERE ID = @SELECTEDID
INSERT [dbo].IncidentDetail (INCIDENTID, DETAILKIND, REASON, INCIDENTUSER, POSTPONEDATE)
VALUES (@SELECTEDID, 1, @REASON, @USERCODE, @POSTPONEDATE);
END
SELECT @ARRAY = SUBSTRING(@ARRAY,
CHARINDEX(@DELIMITADOR, @ARRAY) + 1, LEN(@ARRAY))
END
',@IDINCIDENT='1;5',@REASON='querty',@USERCODE='1',@POSTPONEDATE='2014-08-28 00:00:00'
select @p1
No triggers, no other update no pending transactions
As far I know, even if the first loop iteration blocked the second one to the the point the update fails, a exception must be raised and all the transaction be rolled back.
Seems ilogical the update can fail while the insert works.
All columns got standart types (Int, Varchar(100), DateTime, etc) also I tested for implicit casts issues.
This issue happened only once and cannot be reproduced, even using a backup but I'm afraid it can happen again at production if I cannot find why it happened.
August 27, 2014 at 2:28 pm
You cannot block yourself.
What were the errors raised?
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
August 27, 2014 at 3:10 pm
Is there a last modified date on the incidents? Maybe the user changed the status again after setting it to postponed.
August 28, 2014 at 6:29 am
ZZartin,
That [IncidentDetails].[InsertDate] columns keeps the modification timestamp.
No no other operation and the user is a trained tester looking for this kind of issue, unless he manualy updated that value at MSMSM it must be some sort of TSQL problem.
Gail,
My app itself is just a front-end calling a service responsible to all DB operations.
I managed to get the logs but they are .txt files automatically truncated to save disk space. If that service logged something usefull it's now lost.
Anyway can you explain how the insert can work and the update fail?
I can try to automate that test in a try to reproduce (maybe its one in one million issue) but can be nice to get some idea of what happened, I'm lost.
August 28, 2014 at 6:57 am
jcb (8/28/2014)
Anyway can you explain how the insert can work and the update fail?
Maybe, if you explain what exactly you mean by 'fail'?
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
August 28, 2014 at 7:47 am
jcb (8/28/2014)
ZZartin,That [IncidentDetails].[InsertDate] columns keeps the modification timestamp.
No no other operation and the user is a trained tester looking for this kind of issue, unless he manualy updated that value at MSMSM it must be some sort of TSQL problem.
Yes the incident detail insert date looks like it tracks the time that record was inserted, it does not however track the last modified date of the incident parent record which is why I was asking.
Not blaming your tester just that the simplest explanation to the data you're seeing is that the code you posted ran exactly as expected then something else modified the status on the parent record later.
August 28, 2014 at 2:42 pm
Thanks guys for your time it appear I overlooked it on the wrong place.
After double checking everything else I checked a schedule thing that services uses to expires the postponed incidents.
Well that feature was know to be sound and safe and run smothly and only once at midnight.
Some developer from another team screwed up that thing, putting it ro run every hour and changing the [IncidentDetail] table to [Incident] in a subquery.
(because that team changed a lot of tables names a few weeks ago).
That thing was supposed to add a record to IncidentDetail and update the Incident status but was only updating the last (and wrong) record.
By "coincidence" it updated one of the Incidents the tester was working on and at the exact second the screen reloaded making this a bug almost impossible to reproduce.
Viewing 7 posts - 1 through 6 (of 6 total)
You must be logged in to reply to this topic. Login to reply