david at kineticode
Feb 4, 2009, 10:50 AM
Post #17 of 27
On Feb 4, 2009, at 10:09 AM, Matthew Rolf wrote:
>> NO, it wasn't:
>>> Story Checked Out 2008-04-07 20:39:17
>>> Story Moved into Workflow 2008-04-07 20:39:16 Workflow:
>>> Recreation Pages
>>> Story Republished Maintainance, Bricolage 2008-01-11 14:10:27
> What? It was republished in january, and checked out in April.
Oh, sorry, was reading it backward. I forgot that the log was reverse
cron. Duh. Let me start over.
> That's not the way I read it. I read that that it was checked in,
> and then republished and expired at the same time. This log is in
> chronological order from the bottom up - just like the log screen
> displays. My apologies if that caused confusion.
It's not your fault that I'm a moron.
>> But, I ask you, what user is capable of checking a story in and,
>> within two seconds, finding it on a desk and checking it out again?
> They can check it in on a desk and check it out very rapidly. The
> Check In/Out button changes with the page refresh. It is entirely
That's crazy. Is this 1.11? That would help to explain it…
>> Or, better, how likely is it that some other user checked it out
>> exactly two seconds after it was checked in? Seems kind of weird,
>> though not out of the question.
> The log shows it being checked out by the same user. I omitted
> their name, because I didn't want to past it on the list.
> Right, so what I'm saying is that looking at the log, the first
> check in from 5 to 6 looks like it worked. But when the user checked
> it out and in again, it went to version 5, and didn't increment, and
> didn't create a new db entry. Then when they came back months later
> and checked it out, it stayed at version 5, which is the out of
> sequence id. They then could not check it in, because there was
> already a version 6, and the unique key index wouldn't let them
> duplicate it.
Okay, let me reverse the log and look at it again:
> Story Checked In 2007-11-11 15:41:25 Version: 4
> Story Removed from Workflow 2007-11-11 15:41:25
> Story Changes Saved 2007-11-11 15:41:25
Okay, fine. I should probably update the logging to use real time
instead of transaction start time so that these are properly ordered,
but that's a minor issue.
> Story Republished Maintainance, Bricolage 2007-11-11 15:41:29
> Story Expired Maintainance, Bricolage 2007-11-11 15:41:36
> Story Republished Maintainance, Bricolage 2007-12-20 16:47:06
> Story Republished Maintainance, Bricolage 2007-12-20 16:47:37
> Story Republished Maintainance, Bricolage 2008-01-11 14:10:27
That all looks fine.
> Story Moved into Workflow 2008-04-07 20:39:16 Workflow: Recreation
> Story Checked Out 2008-04-07 20:39:17
> Story Moved to Desk 2008-04-07 20:39:17 Desk: Recreation Edit Alerts
Fine. So this would be version 4, checked_out true, a new row.
> Story Checked In 2008-04-07 20:46:27 Version: 5
That changes v4/true to v5/false. Fine.
> Story Checked Out 2008-04-07 20:46:30
This should create v5/true as a new row.
> Story Checked In 2008-04-07 20:50:19 Version: 6
That changes v5/true to v6/false. Fine.
> Story Checked Out 2008-04-07 20:50:21
This should create v6/true as a new row.
> Story Checked In 2008-04-07 20:51:11 Version: 5
Clearly wrong. So I wonder if that last checkout copied v4 instead of
v6? Let's have a look at your table results now (sorry if you've done
all this already, I'm just thinking it through here…). I've
reformatted to get just the columns that interest us (plus type) and
ordered by ID, so it's chronological:
id | version | type | checked_out
64244 | 5 | sgolf | f
64245 | 6 | sgolf | f
64246 | 6 | sgolf | t
102717 | 5 | sgolf | t
So first, we have version 5 not checked out. That was created when
version 4 was checked in.
Then we have version 6/false, which was created when version 5 was
Then we have version 6/true, which was created when version 6 was
Then, a long time later, the story was checked in…and the version was
set to 5 instead of 7. WTF?
So, what we've figured out is that this tends to happen when a user
has a story checked out for a long time, and, maybe, that there were
publishes while it was checked out. Yes?
Is there a bug report for this? I don't really have time to fiddle
with it right now, but we should add this info to a bug report.