Bug 733008

Summary: ResourceChangeScanner fails when trying to scan package from Guvnor
Product: [JBoss] JBoss Enterprise BRMS Platform 5 Reporter: Jiri Svitak <jsvitak>
Component: BRE (Expert, Fusion)Assignee: Nobody <nobody>
Status: VERIFIED --- QA Contact: Marek Baluch <mbaluch>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: BRMS 5.2.0.GACC: manstis, mbaluch, trevor.quinn, trikkola
Target Milestone: ---   
Target Release: BRMS 5.3.0.GA   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
In JBoss BRMS 5.2 ResourceChangeScanner failed to scan a package in the BRMS Repository. This issue was present in BRMS 5.2 but is no longer present in BRMS 5.3.
Story Points: ---
Clone Of: Environment:
Last Closed: Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Class to reproduce bug
none
Improved test case none

Description Jiri Svitak 2011-08-24 13:02:50 UTC
Description of problem:
Knowledge agent after start loads sample package 'mortgages' correctly. But after first scan ResourceChangeScanner throws this exception (including SystemEventListener's log):

[2011-08-24 14:37:11,867:info] ResourceChangeNotification created
[2011-08-24 14:37:11,869:info] ResourceChangeNotification has started listening for ChangeSet publications
[2011-08-24 14:37:11,869:debug] ResourceChangeNotification thread is waiting for queue update
[2011-08-24 14:37:11,881:info] ResourceChangeScanner reconfigured with interval=60
[2011-08-24 14:37:11,881:info] ResourceChangeScanner created with default interval=60
[2011-08-24 14:37:11,882:info] ResourceChangeNotification scanner has started
[2011-08-24 14:37:11,882:debug] ResourceChangeScanner attempt to scan 0 resources
[2011-08-24 14:37:11,883:debug] ResourceChangeScanner thread is waiting for 60 seconds.
[2011-08-24 14:37:12,060:info] ResourceChangeScanner reconfigured with interval=2
[2011-08-24 14:37:12,060:info] ResourceChangeNotification scanner has stopped
[2011-08-24 14:37:12,060:info] ResourceChangeScanner reconfigured with interval=2
[2011-08-24 14:37:12,060:info] ResourceChangeNotification scanner has stopped
[2011-08-24 14:37:12,061:info] ResourceChangeNotification scanner has started
[2011-08-24 14:37:12,061:debug] ResourceChangeScanner attempt to scan 0 resources
[2011-08-24 14:37:12,061:debug] ResourceChangeScanner thread is waiting for 2 seconds.
[2011-08-24 14:37:12,072:debug] ResourceChangeNotification monitor added monitor=org.drools.io.impl.ResourceChangeScannerImpl@5ece2187
[2011-08-24 14:37:12,073:debug] KnowledgeAgent building resource map
[2011-08-24 14:37:12,073:info] KnowledgeAgent has started listening for ChangeSet notifications
[2011-08-24 14:37:12,077:info] KnowledgeAgent created, with configuration:
monitorChangeSetEvents=true scanResources=true scanDirectories=true newInstance=true
[2011-08-24 14:37:12,516:info] KnowledgeAgent applying ChangeSet
[2011-08-24 14:37:12,518:debug] KnowledgeAgent notifier subscribing to resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST']
[2011-08-24 14:37:12,518:debug] ResourceChangeNotification subscribing listener=org.drools.agent.impl.KnowledgeAgentImpl@7c138c63 to resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST']
[2011-08-24 14:37:12,518:debug] ResourceChangeScanner subcribing notifier=org.drools.io.impl.ResourceChangeNotifierImpl@6765f738 to resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST']
[2011-08-24 14:37:12,518:debug] KnowledgeAgent rebuilding KnowledgeBase using ChangeSet
[2011-08-24 14:37:12,898:debug] KnowledgeAgent building resource map
[2011-08-24 14:37:12,899:debug] KnowledgeAgent no resource mapped for rule=[Rule name=Dummy rule, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Dummy rule, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Underage, agendaGroup=MAIN, salience=10, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Bankruptcy history, agendaGroup=MAIN, salience=10, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=No bad credit checks, agendaGroup=MAIN, salience=10, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=no NINJAs, agendaGroup=MAIN, salience=10, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Row 3 Pricing loans, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Row 1 Pricing loans, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=Row 2 Pricing loans, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=CreditApproval, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] to KnowledgeDefinition=[Rule name=RegexDslRule, agendaGroup=MAIN, salience=0, no-loop=false]
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[ReaderResource resource=null encoding='null'] to KnowledgeDefinition=org.drools.rule.TypeDeclaration@451c0d60
[2011-08-24 14:37:12,899:debug] KnowledgeAgent notifier subscribing to resource=[ReaderResource resource=null encoding='null']
[2011-08-24 14:37:12,899:debug] ResourceChangeNotification subscribing listener=org.drools.agent.impl.KnowledgeAgentImpl@7c138c63 to resource=[ReaderResource resource=null encoding='null']
[2011-08-24 14:37:12,899:debug] ResourceChangeScanner subcribing notifier=org.drools.io.impl.ResourceChangeNotifierImpl@6765f738 to resource=[ReaderResource resource=null encoding='null']
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[ReaderResource resource=null encoding='null'] to KnowledgeDefinition=org.drools.rule.TypeDeclaration@34b23d12
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[ReaderResource resource=null encoding='null'] to KnowledgeDefinition=org.drools.rule.TypeDeclaration@21c783c5
[2011-08-24 14:37:12,899:debug] KnowledgeAgent mapping resource=[ReaderResource resource=null encoding='null'] to KnowledgeDefinition=org.drools.rule.TypeDeclaration@319c0bd6
[2011-08-24 14:37:12,899:info] KnowledgeAgent new KnowledgeBase now built and in use
[2011-08-24 14:37:12,900:debug] KnowledgeAgent finished rebuilding KnowledgeBase using ChangeSet
[2011-08-24 14:37:14,061:debug] ResourceChangeScanner attempt to scan 2 resources
Exception in thread "Thread-3" java.lang.IllegalStateException: reader does have a modified date
	at org.drools.io.impl.ReaderResource.getLastModified(ReaderResource.java:64)
	at org.drools.io.impl.ResourceChangeScannerImpl.scan(ResourceChangeScannerImpl.java:166)
	at org.drools.io.impl.ResourceChangeScannerImpl$ProcessChangeSet.run(ResourceChangeScannerImpl.java:311)
	at java.lang.Thread.run(Thread.java:679)


Version-Release number of selected component (if applicable):
BRMS 5.2.0 ER2

How reproducible:
Create knowledge agent and specify Guvnor's package in changeset. First time it loads package and its rules correctly. But after first scan interval it fails to load resource again.

Steps to Reproduce:
1. Launch Guvnor and after login create sample packages, for this bug is necessary to have 'mortgages' sample package in Guvnor's repository.
2. Run AgentTest.java
  
Actual results:
Scan of resource fails.

Expected results:
Scan of resource should not fail.

Additional info:
Scan of .drl file resource works fine.
It is curious that it attempts to scan 2 resources. (In case of file just 1 resource).
I have also tried multiple agents subscribed to the same resource but this error occurs only in the first agent's scanner service, next agents are fine.

Comment 1 Jiri Svitak 2011-08-24 13:26:23 UTC
Created attachment 519637 [details]
Class to reproduce bug

Comment 2 manstis 2011-10-12 07:56:20 UTC
Added link to (probable) identical JIRA issue.

Comment 4 Jiri Svitak 2012-01-06 11:41:22 UTC
manstis: It seems that this is not identical issue, because fixing bug https://issues.jboss.org/browse/GUVNOR-1699
did not solve this problem. I have added link to external issues
https://issues.jboss.org/browse/JBRULES-3282
https://issues.jboss.org/browse/JBRULES-3287
which were created by Geoffrey De Smet. He tried to solve them, but there is a deeper problem which should be solved by someone else who works on engine. Just for information the same problem appears for other types of resources, like XLS, CSV, BPMN and he wrote some comments on XLS scanning issue:
https://bugzilla.redhat.com/show_bug.cgi?id=741219

Comment 5 JBoss JIRA Server 2012-01-16 21:54:31 UTC
Edson Tirelli <ed.tirelli> updated the status of jira JBRULES-3287 to Resolved

Comment 6 JBoss JIRA Server 2012-01-16 21:54:31 UTC
Edson Tirelli <ed.tirelli> made a comment on jira JBRULES-3287

Geoffrey, I am trying to get my head around this ticket and all the related ones. I applied your test case and after removing a couple lines from the test that I think were wrong, the test no longer fails. I added the test to both master and 5.3.x branches anyway and I am closing this ticket. Please let me know if you think there is still a problem here.

Comment 7 JBoss JIRA Server 2012-01-16 21:54:43 UTC
Edson Tirelli <ed.tirelli> updated the status of jira JBRULES-3287 to Closed

Comment 8 JBoss JIRA Server 2012-01-16 21:56:46 UTC
Edson Tirelli <ed.tirelli> updated the status of jira JBRULES-3282 to Closed

Comment 9 manstis 2012-01-25 10:12:51 UTC
Tested using provided class (many thanks) following Edson's changes. Could not replicate issue hence believe Edson's changes have fixed.

Comment 10 Ryan Zhang 2012-02-15 09:11:57 UTC
Please verify the issue on 5.3 ER4.

Comment 11 Jiri Svitak 2012-02-27 11:16:12 UTC
Verified in BRMS 5.3 ER4.

Comment 12 Jiri Svitak 2012-02-27 19:10:57 UTC
I have found that this was fixed just partially. The test case shows just exceptions from scanner service thread. Scanner started and after first scan it threw exception. This was fixed. Now scanner scans without exceptions, but scanner didn't have to check for changes in packages.

Scanning of changes in package however doesn't work correctly now. When I have scanner service enabled I can load a package. When I make change in Guvnor manually (for example I add one rule) it behaves differently for two possibilities depending on using kbase:
1.) with incremental rebuilding of KnowledgeBase it works (property newInstance=false)
2.) with building of new KnowledgeBase each time (newInstance=true) it detects change, but it fails with exception and KnowledgeBase is empty

I'll create a new test case for this issue and perhaps I'll raise a new Bugzilla too.

Comment 13 Jiri Svitak 2012-02-29 14:25:53 UTC
So here are the steps for reproducing the problem:

1. Download Guvnor. Make sure that version of Guvnor and engine is the same. I have used version BRMS 5.3.0 ER4.
2. Start Guvnor and import sample 'mortgages' package.
3. Run the improved test case (see the second attached java file above).
4. You have one minute to change mortgages package. For example add a rule and build mortgages package in Guvnor.
5. Every 10s scanner polls for changes. Your change will be noticed, but KnowledgeAgent fails to build new KnowledgeBase with following exception:

[2012-02-29 15:13:06,110:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:06,116:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:16,116:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:16,121:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:26,122:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:26,127:debug] ResourceChangeScanner modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] : 1330528367000 : 1330528400000
[2012-02-29 15:13:26,127:debug] ResourceChangeNotification received ChangeSet notification
[2012-02-29 15:13:26,127:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:26,127:debug] ResourceChangeNotification processing ChangeSet
[2012-02-29 15:13:26,127:debug] ResourceChangeNotification ChangeSet modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] for listener=org.drools.agent.impl.KnowledgeAgentImpl@2a8ceeea
[2012-02-29 15:13:26,127:debug] KnowledgeAgent received ChangeSet changed notification
[2012-02-29 15:13:26,127:debug] ResourceChangeNotification thread is waiting for queue update
[2012-02-29 15:13:26,127:info] KnowledgeAgent applying ChangeSet
[2012-02-29 15:13:26,127:debug] KnowledgeAgent removing mappings for resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] with unsubscribe=false
[2012-02-29 15:13:26,127:debug] KnowledgeAgent rebuilding KnowledgeBase using ChangeSet
Exception in thread "Thread-4" java.lang.NullPointerException
	at org.drools.io.impl.ReaderResource.getInputStream(ReaderResource.java:75)
	at org.drools.compiler.PackageBuilder.addPackageFromDrl(PackageBuilder.java:445)
	at org.drools.compiler.PackageBuilder.addKnowledgeResource(PackageBuilder.java:638)
	at org.drools.builder.impl.KnowledgeBuilderImpl.add(KnowledgeBuilderImpl.java:41)
	at org.drools.agent.impl.KnowledgeAgentImpl.createPackageFromResource(KnowledgeAgentImpl.java:725)
	at org.drools.agent.impl.KnowledgeAgentImpl.addResourcesToKnowledgeBase(KnowledgeAgentImpl.java:1018)
	at org.drools.agent.impl.KnowledgeAgentImpl.rebuildResources(KnowledgeAgentImpl.java:801)
	at org.drools.agent.impl.KnowledgeAgentImpl.buildKnowledgeBase(KnowledgeAgentImpl.java:670)
	at org.drools.agent.impl.KnowledgeAgentImpl.applyChangeSet(KnowledgeAgentImpl.java:201)
	at org.drools.agent.impl.KnowledgeAgentImpl$ChangeSetNotificationDetector.run(KnowledgeAgentImpl.java:1213)
	at java.lang.Thread.run(Thread.java:679)
[2012-02-29 15:13:36,127:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:36,133:debug] ResourceChangeScanner modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] : 1330528367000 : 1330528400000
[2012-02-29 15:13:36,133:debug] ResourceChangeNotification received ChangeSet notification
[2012-02-29 15:13:36,133:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:36,133:debug] ResourceChangeNotification processing ChangeSet
[2012-02-29 15:13:36,134:debug] ResourceChangeNotification ChangeSet modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] for listener=org.drools.agent.impl.KnowledgeAgentImpl@2a8ceeea
[2012-02-29 15:13:36,134:debug] KnowledgeAgent received ChangeSet changed notification
[2012-02-29 15:13:36,134:debug] ResourceChangeNotification thread is waiting for queue update
[2012-02-29 15:13:46,134:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:46,140:debug] ResourceChangeScanner modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] : 1330528367000 : 1330528400000
[2012-02-29 15:13:46,140:debug] ResourceChangeNotification received ChangeSet notification
[2012-02-29 15:13:46,140:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:46,140:debug] ResourceChangeNotification processing ChangeSet
[2012-02-29 15:13:46,140:debug] ResourceChangeNotification ChangeSet modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] for listener=org.drools.agent.impl.KnowledgeAgentImpl@2a8ceeea
[2012-02-29 15:13:46,140:debug] KnowledgeAgent received ChangeSet changed notification
[2012-02-29 15:13:46,141:debug] ResourceChangeNotification thread is waiting for queue update
[2012-02-29 15:13:56,141:debug] ResourceChangeScanner attempt to scan 2 resources
[2012-02-29 15:13:56,147:debug] ResourceChangeScanner modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] : 1330528367000 : 1330528400000
[2012-02-29 15:13:56,147:debug] ResourceChangeNotification received ChangeSet notification
[2012-02-29 15:13:56,147:debug] ResourceChangeScanner thread is waiting for 10 seconds.
[2012-02-29 15:13:56,147:debug] ResourceChangeNotification processing ChangeSet
[2012-02-29 15:13:56,147:debug] ResourceChangeNotification ChangeSet modified resource=[UrlResource path='http://localhost:8080/jboss-brms/org.drools.guvnor.Guvnor/package/mortgages/LATEST'] for listener=org.drools.agent.impl.KnowledgeAgentImpl@2a8ceeea
[2012-02-29 15:13:56,147:debug] KnowledgeAgent received ChangeSet changed notification
[2012-02-29 15:13:56,147:debug] ResourceChangeNotification thread is waiting for queue update


I have tried to reproduce this issue with just PKG files, changing them on disk, but I was unable to reproduce exception above.

Comment 14 Jiri Svitak 2012-02-29 14:28:39 UTC
Created attachment 566556 [details]
Improved test case

Comment 15 Geoffrey De Smet 2012-04-05 09:34:28 UTC
Hi Jiri,

You talked about making an arquillian test case to reproduce this issue. Thanks :) Can you notify me with the pull request url when it's added to the pulls?
  https://github.com/droolsjbpm/droolsjbpm-integration/pulls

Comment 16 Geoffrey De Smet 2012-04-18 13:02:35 UTC
Tried with that AgentTest class (the improved testcase, which isn't an arq testcase yet) with guvnor: cannot reproduce the NPE on master, nor on 5.3.x. Jiri said he can reproduce on ER5, so maybe it's fixed for ER6?

Comment 17 Jiri Svitak 2012-04-18 13:15:08 UTC
I can confirm that the bug appears in BRMS 5.3 ER4 and ER5. I have not tested Drools master. Perhaps this bug was fixed by fixing 732085. I'll try to test master branch to double check that bug was fixed.

I have created an automated test case for this bug, which uses the Arquillian. See https://github.com/droolsjbpm/guvnor/pull/47

However, this test case needs to be fixed, because REST client which modifies the repository is not yet able to delete asset rule2.

Comment 18 Geoffrey De Smet 2012-04-18 15:11:36 UTC
I've partially fixed the testcase, and got it to succeed on master by manually rebuilding the package at the correct time.
https://github.com/droolsjbpm/guvnor/commit/79f073360c15ddae1d280a1fd5134e3582e136b1
I 'll further look into automating it completely so we can unignore it and have a good regression test for future work.


Since I can't reproduce on 5.3.x or on master, we're presuming it was fixed from ER5 to ER6. Once ER6 is build, jiri will confirm and reopen the issue if needed.

Comment 19 Ryan Zhang 2012-04-23 07:38:55 UTC
Update status to ON_QA. Please verify them against ER6.

Comment 20 Jiri Svitak 2012-04-23 09:06:29 UTC
Verified in BRMS 5.3.0 ER6.

Comment 24 lcarlon 2012-06-05 05:40:02 UTC
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
In JBoss BRMS 5.2 ResourceChangeScanner failed to scan a package in the BRMS Repository. This issue was present in BRMS 5.2 but is no longer present in BRMS 5.3.