Opened 5 years ago

Closed 5 years ago

#2834 closed defect (fixed)

Changes from perforce server not correctly listed in waterfall view since 0.8.9

Reported by: lunochod Owned by:
Priority: major Milestone: 0.9.0
Version: 0.8.9 Keywords: p4, changes
Cc:

Description

After upgrading to version 0.8.9 something mixes up the "Changed at" time of the changes. This results in an incorrect occurrence of the changes in the waterfall view (the changes are shown 2 hours later as they occur).

The sources reside in a perforce depot. The perforce server uses CEST time zone. Output of "p4 info" is: "Server date: 2014/07/10 11:10:47 +0200 CEST"

Time zone on the buildbot server machine is the same. Output of "date -R" is "Thu, 10 Jul 2014 11:12:33 +0200"

When I look at a specific change on the web interface, I would see for instance: Change #603 ... Changed at Wed 09 Jul 2014 17:46:58 ... Comments

Change 21778 by foo@bar on 2014/07/09 15:46:58

With buildbot 0.8.8 a change would look like: Change #550 ... Changed at Thu 12 Jun 2014 14:55:22 ... Comments

Change 21630 by foo@bar on 2014/06/12 14:55:22

I tried to use the newly introduced P4Source parameter server_tz. I set it to "Europe/Berlin?" (hope this is correct). But it didn't changed the behaviour.

Change History (9)

comment:1 Changed 5 years ago by dustin

  • Keywords waterfall removed
  • Milestone changed from undecided to 0.9.+
  • Type changed from undecided to defect

Can you tell if this is a display error or an error in the P4Poller? You can tell by looking in the 'changes' table in the db. The column is UNIX timestamps, which are implicitly UTC. If those are correct, then it's a display issue. If those are off by 7200, then it's a P4Poller issue.

The code to handle server_tz looks correct, if a little redundant (it converts from the server tz to the local tz with astimezone, then to UTC with datetime2epoch, when it could just go straight from server_tz to UTC with datetime2epoch).

Some examples of the input to that code (m.group('when')) would be helpful to writing additional tests.

comment:2 Changed 5 years ago by lunochod

The entries in the 'changes' table are incorrect.

For instance, the timestamp for change "#603" from the example above is 1404920818. "date -u -d @1404920818" gives Mi 9. Jul 15:46:58 UTC 2014. But the checkin was at 15:46:58 local time. So the database entry should be 13:46:58 UTC.

comment:3 Changed 5 years ago by dustin

OK, thanks!

Can you provide the sample output from p4 describe -s for that change?

comment:4 Changed 5 years ago by lunochod

Yes, of course! (I changed the content of user, workspace, comment and file for privacy reasons.)

The output of p4 describe -s 21778

Change 21778 by foo@bar on 2014/07/09 15:46:58

	added a missing function call

Affected files ...

... //depot/bla/bla/file.c#2 edit

The output of p4 fstat depot/bla/bla/file.c#2 is:

... depotFile //depot/bla/bla/file.c
... headAction edit
... headType text
... headTime 1404913618
... headRev 2
... headChange 21778
... headModTime 1404913442

From p4 help:

headTime             -- head rev changelist time, if in depot

date -u -d @1404913618 gives:

Mi 9. Jul 13:46:58 UTC 2014

comment:5 Changed 5 years ago by dustin

Ah, indeed, so setting server_tz is the solution here. However, *if* you set it to "Europe/Berlin", you'll see that Buildbot will crash with something like

TypeError: tzinfo argument must be None or of a tzinfo subclass, not type 'str'

In fact, supporting string timezones requires pytz, which we do not currently use. You can work around that by installing pytz and passing server_tz=pytz.timezone('Europe/Berlin') to P4Poller.

I'll see if I can get this fixed up in the codebase.

comment:7 Changed 5 years ago by lunochod

Thank you very much for your help!

You're right. There is this exception. I didn't see it until now because I only did a "reconfig" which apparently did not change the p4poller. I had to "stop/start" the server to set the server_tz. By the way (offtopic), is this behaviour a bug or a feature?

After installing pytz, setting server_tz=pytz.timezone('Europe/Berlin') and check something into the perforce depot I see:

         File ".../buildbot-0.8.9-py2.7.egg/buildbot/changes/p4poller.py", line 182, in _poll
            when = when.astimezone(dateutil.tz.tzlocal())
        exceptions.AttributeError: 'module' object has no attribute 'tz'

With my limited python knowledge and the help of the web I added from dateutil import tz to p4poller.py.

Now, the code runs. But, sorry to say: The problem stays but has changed a little bit: For instance, a change with perforce describe -s 21831:

Change 28131 by foo@bar on 2014/07/16 16:58:52

gets the buildbot time stamp 1405526752 (Wed Jul 16 16:05:52 CEST 2014).

Hmmm, almost an hour off. Do I have to specify a daylight-saving time component in the timezone?

Anyway, I shouldn't have to use "server_tz" at all since the BuildBot manual states:

server_tz
    The timezone of the Perforce server, using the usual timezone format (e.g: Europe/Stockholm) in case it's in a different timezone than the buildbot master.

But the time zones of the perforce server and the buildbot server are the same.

comment:8 Changed 5 years ago by Dustin J. Mitchell <dustin@…>

In 3d5a9447a8e504af7fd26aaf837f51c003fc6859:

Merge djmitche/buildbot:bug2834 (PR #1178)

comment:9 Changed 5 years ago by dustin

  • Milestone changed from 0.9.+ to 0.9.0
  • Resolution set to fixed
  • Status changed from new to closed

Most of those things are fixed in https://github.com/buildbot/buildbot/pull/1178 and the need for a restart is addressed in [25ee372a40b6f2949785017c8496621b55b39a66].

You should be able to copy https://raw.githubusercontent.com/djmitche/buildbot/25ee372a40b6f2949785017c8496621b55b39a66/master/buildbot/changes/p4poller.py directly into your code to get all of the fixes in one go.

Note: See TracTickets for help on using tickets.