<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 14 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
{font-family:Tahoma;
panose-1:2 11 6 4 3 5 4 4 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
p.MsoAcetate, li.MsoAcetate, div.MsoAcetate
{mso-style-priority:99;
mso-style-link:"Balloon Text Char";
margin:0in;
margin-bottom:.0001pt;
font-size:8.0pt;
font-family:"Tahoma","sans-serif";}
p.MsoListParagraph, li.MsoListParagraph, div.MsoListParagraph
{mso-style-priority:34;
margin-top:0in;
margin-right:0in;
margin-bottom:0in;
margin-left:.5in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri","sans-serif";
color:windowtext;}
span.BalloonTextChar
{mso-style-name:"Balloon Text Char";
mso-style-priority:99;
mso-style-link:"Balloon Text";
font-family:"Tahoma","sans-serif";}
.MsoChpDefault
{mso-style-type:export-only;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
/* List Definitions */
@list l0
{mso-list-id:423454418;
mso-list-type:hybrid;
mso-list-template-ids:-1217725748 67698703 67698713 67698715 67698703 67698713 67698715 67698703 67698713 67698715;}
@list l0:level1
{mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level2
{mso-level-number-format:alpha-lower;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level3
{mso-level-number-format:roman-lower;
mso-level-tab-stop:none;
mso-level-number-position:right;
text-indent:-9.0pt;}
@list l0:level4
{mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level5
{mso-level-number-format:alpha-lower;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level6
{mso-level-number-format:roman-lower;
mso-level-tab-stop:none;
mso-level-number-position:right;
text-indent:-9.0pt;}
@list l0:level7
{mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level8
{mso-level-number-format:alpha-lower;
mso-level-tab-stop:none;
mso-level-number-position:left;
text-indent:-.25in;}
@list l0:level9
{mso-level-number-format:roman-lower;
mso-level-tab-stop:none;
mso-level-number-position:right;
text-indent:-9.0pt;}
ol
{margin-bottom:0in;}
ul
{margin-bottom:0in;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-US link=blue vlink=purple><div class=WordSection1><p class=MsoNormal>Hi,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Just wanted to pass along this bit of info to anyone using the GitPoller. Maybe the change is worthwhile enough to implement in the main product.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>I was faced with two problems with the GitPoller, as follows…<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoListParagraph style='text-indent:-.25in;mso-list:l0 level1 lfo1'><![if !supportLists]><span style='mso-list:Ignore'>1.<span style='font:7.0pt "Times New Roman"'> </span></span><![endif]>BuildBot polls four different repositories for me, which turns out that’s 100+ branches it’s looking at, every two minutes. Given that there’s a log entry for each branch that it looks at and despite the fact that it’s looking at different branches for each one, the entries in the twistd.log file don’t differentiate. Basically, GitPoller was repeatedly spamming the log with messages like the one below.<br><br><i>gitpoller: processing 0 changes: [] from "ssh://git@host.com/reponame"</i><br><i>gitpoller: processing 0 changes: [] from "ssh://git@host.com/reponame"</i><br><i>gitpoller: processing 0 changes: [] from "ssh://git@host.com/reponame"<br>…<br><br></i><o:p></o:p></p><p class=MsoListParagraph style='text-indent:-.25in;mso-list:l0 level1 lfo1'><![if !supportLists]><span style='mso-list:Ignore'>2.<span style='font:7.0pt "Times New Roman"'> </span></span><![endif]>The next problem was that I kept getting a depreciated warning from twisted in the log, repeatedly, over and over and over again, exactly like the one below. I had no idea what process in BuildBot was causing this. The message had no additional information.<br><br><i>/usr/local/lib/python2.7/site-packages/Twisted-12.1.0-py2.7-linux-i686.egg/twisted/internet/utils.py:25: exceptions.DeprecationWarning: Argument strings and environment keys/values passed to reactor.spawnProcess should be str, not unicode.</i><br><br><o:p></o:p></p><p class=MsoNormal>Between the two above issues, <b>ALL TEN</b> of the twistd.log files were being filled with log messages that spanned only a couple minutes, which was not very helpful for tracking down other issues that would have been logged. For those of you experiencing these problems, read on and I’ll tell you what I did to fix it.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>For the first problem, instead of cutting down on the number of times gitpoller wrote a line for the polling it does, I made the output more helpful.<br><br><o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'><i>From 5a5533d0afeffa86258b20ed00d5663e76d9ddcf Mon Sep 17 00:00:00 2001<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>From: Jeremy Cornett <jeremy.cornett@venafi.com><o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>Date: Wed, 18 Nov 2015 09:22:43 -0700<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>Subject: [PATCH] Add the ref name to the log output so you can see which was<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> examined.<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i><o:p> </o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>---<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> master/buildbot/changes/gitpoller.py | 4 ++--<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> 1 file changed, 2 insertions(+), 2 deletions(-)<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i><o:p> </o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>diff --git a/master/buildbot/changes/gitpoller.py b/master/buildbot/changes/gitp<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>oller.py<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>index e245537..9f943f0 100644<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>--- a/master/buildbot/changes/gitpoller.py<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>+++ b/master/buildbot/changes/gitpoller.py<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>@@ -275,8 +275,8 @@ class GitPoller(base.PollingChangeSource, StateMixin):<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> self.changeCount = len(revList)<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> self.lastRev[branch] = newRev<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i><o:p> </o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>- log.msg('gitpoller: processing %d changes: %s from "%s"'<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>- % (self.changeCount, revList, self.repourl))<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>+ log.msg('gitpoller: processing %d changes for "%s", "%s": %s'<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>+ % (self.changeCount, self.repourl, branch, revList))<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i><o:p> </o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> for rev in revList:<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i> dl = defer.DeferredList([<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>--<o:p></o:p></i></p><p class=MsoNormal style='margin-left:.5in'><i>1.9.5.msysgit.0<o:p></o:p></i></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>The above patch changes the output to look like this, which is a bit more informative…<br><br><o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>gitpoller: processing 0 changes for "ssh://git@host.com/reponame", "refs/heads/branchname": []<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>The next problem I was able to unravel by using a patch already applied to the master branch for the 0.9 release (<a href="https://github.com/buildbot/buildbot/pull/1578">https://github.com/buildbot/buildbot/pull/1578</a>, commit 1ff73110394a8fa23ad2065415ea655ee1b1c92e). The 1ff73110 fix allowed me to see a Git error which allowed me to see the command BuildBot was running to produce the Twistd depreciation warning. Apparently, I had a bad object that the GitPoller was encountering when it tried to run a “git log” command. The bad object is irrelevant to the fix I implemented (it was from a previous polling and stored in state.sqlite, I just had to delete the sqlite file and run update-master to recreate the file anew). Here is the new log message from the above fix I had cherry-picked.<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'><br>buildbot.changes.gitpoller.GitError: command log ['--format=%H', 'bed339b10d9638d6ac8de892e866fb026454f13f', u'^9bc6bce7d5cb6f920cc4c5232fb26dd8c09e4c9e', u'^88713a7d0607b3ec7562843cba414039e96e46a8', …<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>If you notice in that command, after the first hash, all the rest are casted as Unicode strings. That’s oddly familiar. By examining the GitPoller file some more, I came to realize that whatever was storing the values in the dictionary lastRev, was storing them as Unicode. Probably just how they were being extracted from the SQL lite database. I cast the rev as an ASCII string, and all was happy! Twistd deprecation warning was no more.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal style='margin-left:.5in'>From 0f400eab9b275683882683e7828a4a1b32fcea0e Mon Sep 17 00:00:00 2001<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>From: Jeremy Cornett <jeremy.cornett@venafi.com><o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>Date: Tue, 17 Nov 2015 16:41:51 -0700<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>Subject: [PATCH] This is a shot in the dark. Twisted keeps complaining about<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> wanting strings instead of unicode when the gitpoller is running. It looks<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> like the unicode strings are coming from that self.lastRev variable.<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'><o:p> </o:p></p><p class=MsoNormal style='margin-left:.5in'>---<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> master/buildbot/changes/gitpoller.py | 2 +-<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> 1 file changed, 1 insertion(+), 1 deletion(-)<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'><o:p> </o:p></p><p class=MsoNormal style='margin-left:.5in'>diff --git a/master/buildbot/changes/gitpoller.py b/master/buildbot/changes/gitp<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>oller.py<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>index 936027d..e245537 100644<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>--- a/master/buildbot/changes/gitpoller.py<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>+++ b/master/buildbot/changes/gitpoller.py<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>@@ -264,7 +264,7 @@ class GitPoller(base.PollingChangeSource, StateMixin):<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'><o:p> </o:p></p><p class=MsoNormal style='margin-left:.5in'> # get the change list<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> revListArgs = ([r'--format=%H', r'%s' % newRev] +<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>- [r'^%s' % rev for rev in self.lastRev.values()] +<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>+ [r'^%s' % rev.encode('ascii', 'ignore') for rev in self.lastRev.values()] +<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> [r'--'])<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> self.changeCount = 0<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'> results = yield self._dovccmd('log', revListArgs, path=self.workdir)<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>--<o:p></o:p></p><p class=MsoNormal style='margin-left:.5in'>1.9.5.msysgit.0<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>It’s probably not the most elegant solution, but it got the job done. Perhaps someone more into BuildBot coding could use this to implement a better solution.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Thanks,<o:p></o:p></p><p class=MsoNormal>Jeremy Cornett<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p></div></body></html>