Bug #4139: Error when deleting a newly created Directive ("Exception when trying to update a change request:: Error when deleting policy instanc with ID DirectiveId(...)") - Rudder - Issue Tracker

Actions

Copy link

Bug #4139

closed

Error when deleting a newly created Directive ("Exception when trying to update a change request:: Error when deleting policy instanc with ID DirectiveId(...)")

Added by Jonathan CLARKE over 10 years ago. Updated about 7 years ago.

Status:

Rejected

Priority:

Assignee:

Vincent MEMBRÉ

Category:

Web - Config management

Target version:

3.1.19

Pull Request:

Severity:

UX impact:

User visibility:

Effort required:

Priority:

Name check:

Fix check:

Regression:

Description

On a brand new install of 2.8.0, I went into the web interface, and modified the config of the change message (that is the message that is displayed to users). I don't know if this is relevant, but I thought it worth mentioning. I did not enable Change Requests, or change any other configs.

Then, I created a Directive (from Technique "zypperPackageManagerSettings" version 1.0, in case that matters), this worked fine. The exact technical details from the event log are:

<entry>
  <directive fileFormat="4" changeType="add">
    <id>90d9c3fe-97a1-47ca-8f48-610abe0ecd94</id>
    <displayName>DSDSDS</displayName>
    <techniqueName>zypperPackageManagerSettings</techniqueName>
    <techniqueVersion>1.0</techniqueVersion>
    <section name="sections">
      <section name="General settings">
        <var name="ZYPPER_INSTALLRECOMMENDS">dontchange</var>
      </section>
      <section name="Repository settings">
        <var name="ZYPPER_ADDREPOSITORIES">false</var>
        <var name="ZYPPER_DISABLEREPOSITORIES">false</var>
        <section name="Repository">
          <var name="ZYPPER_ENABLED">1</var>
          <var name="ZYPPER_NAME"/>
          <var name="ZYPPER_TYPE">yast2</var>
          <var name="ZYPPER_URL"/>
        </section>
      </section>
    </section>
    <shortDescription/>
    <longDescription/>
    <priority>5</priority>
    <isEnabled>true</isEnabled>
    <isSystem>false</isSystem>
  </directive>
</entry>

Then, I deleted the Directive. I got a change message dialog box, filled it and pressed save (no problem so far). Then, I saw a rule generation start, and I got a "Cannot contact server at this time" dialog box.

Since then, I have two symptoms something is wrong:

The rule generation never finishes, it is continually "generation"
I noticed this in the logs:

[2013-11-07 19:26:15] INFO  com.normation.rudder.services.servers.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: root
[2013-11-07 19:26:24] INFO  changeRequest - Saving and deploying change request 1
[2013-11-07 19:26:29] INFO  changeRequest - Saving and deploying change request 2
[2013-11-07 19:26:29] ERROR com.normation.rudder.web.components.popup.ModificationValidationPopup - Exception when trying to update a change request:: Error when deleting policy instanc with ID DirectiveId(90d9c3fe-97a1-47ca-8f48-610abe0ecd94). All dependent rules where deleted  ().

I assume that "change request 1" was when I created the Directive, and "change request 2" was when I deleted it. However, change requests are not enabled, so there is obviously something wrong here (or else the log messages are extremely misleading and should be changed).

I have not continued to test, in case showing the current state to a developer may help debug this problem. I'm keeping the VM in a safe place in it's broken status.

Actions

Copy link

Updated by Vincent MEMBRÉ over 10 years ago

I reproduced the bug Jon,

I created a new server 2.8, changed the message in the change message, and created the same Directive as you. then deleted it with a "server cannot be contacted at this time.

However my webapp restarted at this time, and this is clearly the cause of the server cannot be contacted at this time.

I need to look deeper into why the webapp restarted, but at first webapp boot, a deployment occurs, replacing all promises of the server (when rudder is installed, the server has initial promises and lots of parameters are defined at this first deployment)

Did your webapp restarted too when deleting the change?

After the restart, replaying the same pattern works without problem on my VM.

Actions

Copy link

Updated by Jonathan CLARKE over 10 years ago

No, my webapp did definitely not restart. I am sure of this, because it continued responding the whole time, and the logs show a constant flow of "Store Agent Run Times" tasks (see #4128).

This is the full, unedited, logs output (I previously removed the task specific logs for clarity):

[2013-11-07 19:26:10] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #92: Starting analysis for run times from 2013/11/07 19:26:05 up to 2013/11/07 19:26:10 (runs after SQL table ID 126)
[2013-11-07 19:26:10] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #92: Finished analysis in 23 ms. Added or updated 0 agent runs (up to SQL table ID 126)
[2013-11-07 19:26:15] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #93: Starting analysis for run times from 2013/11/07 19:26:10 up to 2013/11/07 19:26:15 (runs after SQL table ID 126)
[2013-11-07 19:26:15] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #93: Finished analysis in 16 ms. Added or updated 0 agent runs (up to SQL table ID 126)
[2013-11-07 19:26:15] INFO  com.normation.rudder.services.servers.NodeConfigurationServiceImpl - Configuration of following nodes were updated, their promises are going to be written: root
[2013-11-07 19:26:20] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #94: Starting analysis for run times from 2013/11/07 19:26:15 up to 2013/11/07 19:26:20 (runs after SQL table ID 126)
[2013-11-07 19:26:20] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #94: Finished analysis in 13 ms. Added or updated 0 agent runs (up to SQL table ID 126)
[2013-11-07 19:26:24] INFO  changeRequest - Saving and deploying change request 1
[2013-11-07 19:26:25] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #95: Starting analysis for run times from 2013/11/07 19:26:20 up to 2013/11/07 19:26:25 (runs after SQL table ID 126)
[2013-11-07 19:26:25] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #95: Finished analysis in 20 ms. Added or updated 1 agent runs, up to SQL table ID 129 (last run time was 2013/11/07 19:26:21)
[2013-11-07 19:26:29] INFO  changeRequest - Saving and deploying change request 2
[2013-11-07 19:26:29] ERROR com.normation.rudder.web.components.popup.ModificationValidationPopup - Exception when trying to update a change request:: Error when deleting policy instanc with ID DirectiveId(90d9c3fe-97a1-47ca-8f48-610abe0ecd94). All dependent rules where deleted  ().
[2013-11-07 19:26:30] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #96: Starting analysis for run times from 2013/11/07 19:26:21 up to 2013/11/07 19:26:30 (runs after SQL table ID 129)
[2013-11-07 19:26:30] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #96: Finished analysis in 15 ms. Added or updated 0 agent runs (up to SQL table ID 129)
[2013-11-07 19:26:35] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #97: Starting analysis for run times from 2013/11/07 19:26:30 up to 2013/11/07 19:26:35 (runs after SQL table ID 129)
[2013-11-07 19:26:35] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #97: Finished analysis in 15 ms. Added or updated 0 agent runs (up to SQL table ID 129)
[2013-11-07 19:26:40] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #98: Starting analysis for run times from 2013/11/07 19:26:35 up to 2013/11/07 19:26:40 (runs after SQL table ID 129)
[2013-11-07 19:26:40] INFO  com.normation.rudder.reports.execution.ReportsExecutionService - [Store Agent Run Times] Task #98: Finished analysis in 12 ms. Added or updated 0 agent runs (up to SQL table ID 129)

And these messages continue forever. The rule generation is still "going on".

Actions

Copy link