History | Log In     View a printable version of the current page.  
Issue Details (XML | Word | Printable)

Key: CCNET-748
Type: New Feature New Feature
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Ruben Willems
Reporter: Owen Rogers
Votes: 2
Watchers: 2
Operations

If you were logged in you would be able to see more operations.
CruiseControl .NET

Provide better trigger exception logging

Created: 01/Oct/06 11:48 PM   Updated: 25/Jul/10 12:48 PM
Component/s: Console
Affects Version/s: 1.0
Fix Version/s: 1.4.3

Original Estimate: Unknown Remaining Estimate: Unknown Time Spent: Unknown
File Attachments: 1. Text File 748_4.patch (31 kb)
2. Text File 748_5.patch (31 kb)
3. Text File 748_6.patch (55 kb)
4. Text File 748_8.patch (60 kb)
5. Text File 748_9.patch (63 kb)
6. Text File ccnetExceptionspatch.patch (2 kb)

Issue Links:
Relationship
This issue Relates to:
CCNET-137 Successful build status indicated on ... Major Closed
CCNET-129 exception during VSS doesn't show up ... Minor Closed
This issue Relates to:
CCNET-1251 Integration builds triggered by sched... Major Closed
CCNET-1448 latest updates to improve exception l... Major Closed
CCNET-816 Vault source control exception during... Major Closed
CCNET-1441 finetune source control error handlin... Major Closed
CCNET-1113 Proposed changes for handling integra... Minor Closed


 Description  « Hide
Exceptions that prior to a build -- such as problems connecting to the sourcecontrol provider -- are only logged to the console window. This makes it easy to miss these problems when they occur. An alternate exception publishing mechanism is required so that these exceptions can be viewed either through the webdashboard or via cctray.

 All   Comments   Work Log   Change History      Sort Order:
Ross Patterson [17/Dec/07 01:35 PM]
This is still a problem in 1.3, as noted by email from strefethen@gmail.com to the ccnet-users list on 2007-12-12:

I'm working on an ISourceControl implementation and need exceptions that get raised published using the email publisher. I noticed as of
1.1 the publishExceptions tag is no longer supported so is there a different way to publish exceptions that occur in a <sourcecontrol> block?

The error is displayed to the console but not published.

I'm using CC.NET 1.3. Stepping through the code all I see is that logger.Error gets called with the exception contents.

Ross Patterson [17/Dec/07 01:37 PM]
strefethen@gmail.com updated his blog with an answer, albeit not one that produces nice results:

Prior to v1.1 this used to work using if you had following tag in your ccnet.config file:
<publishExceptions>true</publishExceptions>

With v1.1 came support for log4net replacing the functionality of this tag which is mentioned here but without further details as to the alternative. To publish these exceptions you have to configure a log4net SmtpAppender to sent email which can be done from app.config as follows:
<appender name="SmtpAppender" type="log4net.Appender.SmtpAppender">
      <to value="to@b.com" />
      <from value="from@b.com" />
      <subject value="test logging message" />
      <smtpHost value="smtpserver" />
      <bufferSize value="512" />
      <lossy value="true" />
      <evaluator type="log4net.Core.LevelEvaluator">
        <threshold value="WARN"/>
      </evaluator>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern
          value="%newline%date [%thread] %-5level %logger [%property{NDC}] -
%message%newline%newline%newline" />
      </layout>
    </appender>

Btw, don't forget to configure this appender in the <root> node of the <log4net> section as well. It's a bit of a bummer that you have to have two Smtp setups to handle these kinds of exceptions but at least you have the capability to get the information published.

Ross Patterson [18/Dec/07 01:20 PM]
I'm not sure this is still a problem. Using current development code, I'm getting sourcecontrol exceptions in my build logs, in the dashboard, and in the emails from the email publisher.

Ross Patterson [19/Dec/07 12:05 PM]
I have confirmed with strefethen@gmail.com (via the ccnet-users list) that his problem is that exceptions thown *before the build starts*, such as from ISourceControl.GetModifications(), do not appear in the build log. Alas, they cannot do so, since there is not yet a build running and in fact a build may not actually occur (e.g., if GetModifications() were to report "no changes"). The same thing is true of exceptions during triggers, or anything else that happens before the build itself begins.

I don't believe we can fix this.

Ross Patterson [04/Feb/08 03:52 PM]
Steve Trefethen updated his blog on 2008-01-04 with some comments and a patch:

Exceptions in CruiseControl.NET revisited
The other day I wrote about configuring CruiseControl.NET to send email when an exception occurred at the project level, meaning outside of the actual "build" which technically equates to the <tasks> block. I've since spent some time trying to understand why the CCNet was changed to remove support for PublishExceptions and found revision 2567 to IntegrationRunner.cs where it was removed with a comment of "all exceptions during build break the build
deprecating PublishExceptions attribute". That didn't exactly provide the explanation I was looking for and AFAICT, this change has now left a gap in CruiseControl.NET where exceptions occurring outside of the <tasks> block can't be published using a build publisher. So, unless you're checking the log files regularly, or you've configured log4net using an SmtpAppender they'll go unnoticed.

To figure this out I've been posting messages to the ccnet-devel group and thankfully I'm getting some response although it's been a very slow conversation that's had it's share of missteps due, in part, to my incorrect phrasing of where exceptions were occurring. Originally, I was looking for guidance thinking I must be missing something. After a few more posts a change request and subsequent revision was made but the change addressed a situation I'm pretty sure can't occur in the current code base short of a plug-in explicitly catching exceptions and setting the build status to "Exception" which isn't what I was looking for.

I believe the necessary change to allow for integration exceptions to be published looks something like this (from IntegrationRunner.cs):

 1 public IIntegrationResult Integrate(IntegrationRequest request) 2 { 3 IIntegrationResult result = resultManager.StartNewIntegration(request); 4 IIntegrationResult lastResult = resultManager.LastIntegrationResult; 5 try
 6 { 7 CreateDirectoryIfItDoesntExist(result.WorkingDirectory); 8 CreateDirectoryIfItDoesntExist(result.ArtifactDirectory); 9 result.MarkStartTime();10 result.Modifications = GetModifications(lastResult, result);11 if (result.ShouldRunBuild())12 {13 Log.Info("Building: " + request);14 Build(result);15 PostBuild(result16 Log.Info(string.Format("Integration complete: {0} - {1}", 17 result.Status, result.EndTime));18 }19 target.Activity = ProjectActivity.Sleeping;20 return result;21 }22 catch (Exception ex)23 {24 result.Status = IntegrationStatus.Exception;25 result.ExceptionResult = ex;26 target.PublishResults(result);27 return result;28 }29 }30 I've added a try...catch to handle exceptions that occur during the integration process and call PostBuild() which calls FinishIntegration() and PublishResults(). That way any exception occurring during the integration process can be handled by any of the available publishers including the email publisher. Btw, the old PublishExceptions code looked similar. Of course, the code presented here isn't the only, nor perhaps even the best way to handle this situation personally, I'm not fond of PostBuild() appearing twice but adding a finally block seemed to unnecessarily complicate the code. Since I don't understand the reasoning behind removing the PublishExceptions tag it's hard to know what the desired behavior here is but I'm pretty sure what's checked in is probably not what was intended.

There is one other change I think is important as well which is to modify IntegrationResult.ShouldRunBuild() as follows (from IntegrationResult.cs):

1 public bool ShouldRunBuild()2 {3 return status == IntegrationStatus.Unknown && 4 (BuildCondition.ForceBuild == BuildCondition || HasModifications());5 } This change rather subtle but it allows for an ISourceControl plug-in to handle it's own exceptions and still prevent the build from executing by setting IntegrationStatus to something other than "Unknown". Without the check for IntegrationStatus.Unknown the build would run regardless of exceptions that occurred within the GetModifications() call. For example, here is a catch block you could use within your implementation of ISourceControl.GetModfications() to prevent the build from executing. However, this will only work if the above proposed changes are made to CCNet.

1 catch(Exception ex)2 {3 to.ExceptionResult = ex;4 to.Status = ThoughtWorks.CruiseControl.Remote.IntegrationStatus.Exception;5 return null;6 } In the event of an exception you'll have the opportunity to have the exception published using your configured publishers. Additionally, the web dashboard will reflect the fact that the build is left in an Exception state.

Anyway, I'm going continue to work this issue and see if I can get either the above changes or some other solution integrated into CCNet though the thread on the groups seems to have died.

[UPDATE: Jan 4, 2008] Here is an SVN patch for these changes.
[UPDATE: Jan 9, 2008] Fix for IntegrationRunner.Integrate to simply publish the results in the event of an exception.
 
Posted at 1/4/2008 1:42PM by Steve Trefethen

(http://www.stevetrefethen.com/blog/ExceptionsInCruiseControlNETRevisited.aspx)

Ross Patterson [06/Feb/08 09:15 AM]
This issue is on the road map for release 1.4.

Ross Patterson [20/May/08 04:28 PM]
I don't understand this well enough to own the issue.

David Cameron [22/May/08 04:05 PM]
I can own this one. Another TW dev is having a look at it too.

Didier Levesque [26/May/08 12:35 PM]
When do plan to finish this feature?? Because it look like it's the only blocker to release 1.4... Am I right?

Ross Patterson [28/May/08 09:02 AM]
Moving off the 1.4 roadmap.

Daniel Hommel [29/Aug/08 06:46 AM]
I tried Steves patch today and it seems to improve the situation quite a bit. The only problem i see is that when an exception occurs during sourcecontrol operation the project shows "Last Build Label: UNKNOWN" afterwards. After this is fixed i'd like to see the patch in the mainline.

Daniel Hommel [29/Aug/08 07:17 AM]
To be more specific it looks like the IntegrationResult is not initialized correctly when an exception occurs:

[RobocopyTest:INFO] Project: 'RobocopyTest' is first in queue: 'RobocopyTest' an
d shall start integration.
[RobocopyTest:INFO] Integration complete: Exception - 01.01.0001 00:00:00

Daniel Hommel [29/Aug/08 09:15 AM]
Attached a slightly modified version of the patch by Steve Trefethen.

I added two lines to the catch clause:
    result.MarkEndTime();
    result.Label = lastResult.LastSuccessfulIntegrationLabel;

I don't know if the label should be increased or not. Comments appreciated.

Daniel Hommel [03/Sep/08 05:21 AM]
After an intervaltrigger fires the project still has the UNKNOWN state.

Ruben Willems [23/Dec/08 04:01 PM]
this patch should work
I tested it in a test environment and it behavied ok

when an error occurst during the getmodifications, the project will be stopped automatically

unit tests are not afjusted yet, waiting for feedback
the problem with the unknown label at server start has been resolved.

Steve Trefethen [23/Dec/08 05:38 PM]
Hi Guys,
  First, thanks very much for your attention to this issue. I've been using my patch and it's worked pretty well with the exception of the issues raised above which weren't critical for my situation. I'll take a look at the latest changes and let you know. I'm right now dealing with a very flakey FTP server for which I've written an ISourceControl provider and it raised exceptions all the time.

Steve Trefethen [29/Dec/08 03:08 PM]
Hi Ruben,
  I finally got a chance to test this patch and indeed it seems to be working as described.

Again, thanks for the attention to this issue. I was on the verge of using the Null source control provider and writing the FTP code in a task as I'd really prefer to run with unmodified CCNet sources.

Steve Trefethen [29/Dec/08 03:38 PM]
Follow-up comment:

It seems the patch is working WRT reporting errors via the email publisher which is great.

I have a problem however with the project being left in the stopped state. In my case, which I know is specific to my situation, I'd like the project to continue running as it may eventually succeed in which case no manual intervention is required. Perhaps specific exception classes for this type of error could be used to control what state the project should be left in when an SCC error occurs.

In my specific case, I've coded my SCC provider to throw an exception after an FTP connection has failed for N minutes which notifies IT manual intervention *may* be required. Potentially, the FTP connection will eventually succeed in which case no manual intervention is required.

Btw, what's necessary to start a stopped project? Forcing a build from the webdashboard?

Steve Trefethen [31/Dec/08 03:48 PM]
Hi Ruben,
  So this patch will *always* call PostBuild() regardless of result.ShouldRunBuild() which is a serious problem.

Here is my modification to IntegrationRunner.cs IntegrationRunner.Integration(...) to fix this problem. These changes more closely mirror the previous code with respect to the result of ShouldRunBuild(). I'm now testing with these changes.

public IIntegrationResult Integrate(IntegrationRequest request)
{
    IIntegrationResult result = resultManager.StartNewIntegration(request);
    IIntegrationResult lastResult = resultManager.LastIntegrationResult;

    CreateDirectoryIfItDoesntExist(result.WorkingDirectory);
    CreateDirectoryIfItDoesntExist(result.ArtifactDirectory);

    result.MarkStartTime();

    bool GettingModifications = true;
    bool RunBuild = false;

    try
    {
        target.CreateLabel(result);

        result.Modifications = GetModifications(lastResult, result);
        GettingModifications = false;

RunBuild = result.ShouldRunBuild();
        if (RunBuild)
        {
            Log.Info("Building: " + request);
            Build(result);
        }

    }
    catch (Exception ex)
    {
        result.ExceptionResult = ex;
        result.SourceControlErrorOccured = GettingModifications;

    }
    finally
    {
if (RunBuild)
{
result.MarkEndTime();
PostBuild(result);
Log.Info(string.Format("Integration complete: {0} - {1}", result.Status, result.EndTime));
}
target.Activity = ProjectActivity.Sleeping;
    }
    return result;
}

-Steve

Ruben Willems [01/Jan/09 03:02 PM]
This fixes the problem that the postbuild is ran on every integration.
Postbuild is now only ran when a build occured, or when there was an error in the getmodifications.

The project is still stopped when an error occured during getmodifications.
I'm working on making this configurable.

Ruben Willems [03/Jan/09 01:28 PM]
it is now configurable how many sourcecontrol exceptions (during getmodifications) are allowed before the project is stopped.
The default is int.maxvalue.

you can set this value by adding maxAmountOfSourceControlExceptions=X in the config of your project
at the project level.
<maxAmountOfSourceControlExceptions>10</maxAmountOfSourceControlExceptions>


unit tests are still not patched

patch file : 748_6

Ruben Willems [04/Jan/09 02:33 PM]
fixed a bug where the label was wrong
good build - exception - good build

the 2nd good build got the label of the first previous good build

this has been fixed in this patch : 748_8


stil unit (mock) problems though

Ruben Willems [10/Jan/09 02:05 PM]
most tests fixed
2 unit tests still failing :-(
help appreciated