You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@mahout.apache.org by Stanley Ipkiss <sa...@gmail.com> on 2010/09/24 02:50:16 UTC

Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

For the class PreferenceEstimateCallable, the parent thread does not wait for
all the child threads of this class to complete. On just adding a few simple
log statements around the call() function (shown below), I have observed
that there were a lot more "Starting" (622 in number) as compared to
"Stopping" (1 in number) in my logfile. I ran it multiple times and
everytime I got some difference in the total number of logged start and
stop. I will try to fix this issue in my checked out code, but just wanted
to know if anyone else has noted this?

   public Void call() throws TasteException {
      log.info("Starting - analysis for pref size:" + prefs.length());
      for (Preference realPref : prefs) {
    	....
      }
      log.info("Stopping - analysis for pref size:" + prefs.length());
      return null;
    }

-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571411.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Ted Dunning <te...@gmail.com>.
I don't think that the future.get() will ever be done.  Testing for
!future.done() will always return false after
invokeAll because invokeAll waits for all tasks to complete.

On Thu, Sep 23, 2010 at 7:57 PM, Stanley Ipkiss <sa...@gmail.com>wrote:

> According to me, the first line is redundant (checking for
> future.isDone()).
> future.get() will alone serve the purpose.  The snippet of code that I had
> attached was from the latest revision of mahout.
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Stanley Ipkiss <sa...@gmail.com>.
According to me, the first line is redundant (checking for future.isDone()).
future.get() will alone serve the purpose.  The snippet of code that I had
attached was from the latest revision of mahout.
-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571781.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Ted Dunning <te...@gmail.com>.
Isn't the test here backwards?

On Thu, Sep 23, 2010 at 6:42 PM, Stanley Ipkiss <sa...@gmail.com>wrote:

>    if (!future.isDone()) {
>          future.get();
>        }
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Stanley Ipkiss <sa...@gmail.com>.
I have no clue why this is happening, even though we have the appropriate
future implementation -

      List<Future<Void>> futures = executor.invokeAll(callables);
      // Go look for exceptions here, really
      for (Future<Void> future : futures) {
        if (!future.isDone()) {
          future.get();
        }
      }

I tried looking for exceptions; there aren't any in this case. For about
every 1 in 5 times, it causes this issue of quitting even when a lot threads
are still running. Any pointers?
-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571579.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
I committed something for this.

Along the way of figuring out the corner case here, I realized that
there are about 8 similar versions of this code elsewhere that could
be standardized, and simplified, mostly by not trying to lazy-load the
data.

Give it a spin.

On Sat, Sep 25, 2010 at 10:44 AM, Sean Owen <sr...@gmail.com> wrote:
> This is a different issue. I see it and will put in a fix today.
>
> On Fri, Sep 24, 2010 at 9:07 PM, Stanley Ipkiss <sa...@gmail.com> wrote:
>>
>> I did that change yesterday in my code, but forgot to post the update here.
>> The error that I get sometimes is -
>>
>> Caused by: java.lang.NullPointerException
>>        at
>> org.apache.mahout.cf.taste.impl.similarity.file.FileItemSimilarity.itemSimilarities(FileItemSimilarity.java:108)
>>        at
>> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.doEstimatePreference(GenericItemBasedRecommender.java:195)
>>        at
>> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.estimatePreference(GenericItemBasedRecommender.java:126)
>>        at
>> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:214)
>>        at
>> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:1)
>>        at
>> org.apache.mahout.cf.taste.impl.common.Cache.getAndCacheValue(Cache.java:127)
>>        at org.apache.mahout.cf.taste.impl.common.Cache.get(Cache.java:96)
>>        at
>> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender.estimatePreference(CachingRecommender.java:128)
>>
>> I am still looking into for what particular case, does the
>> FileItemSimilarity go crazy.
>> --
>> View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1576371.html
>> Sent from the Mahout User List mailing list archive at Nabble.com.
>>
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
This is a different issue. I see it and will put in a fix today.

On Fri, Sep 24, 2010 at 9:07 PM, Stanley Ipkiss <sa...@gmail.com> wrote:
>
> I did that change yesterday in my code, but forgot to post the update here.
> The error that I get sometimes is -
>
> Caused by: java.lang.NullPointerException
>        at
> org.apache.mahout.cf.taste.impl.similarity.file.FileItemSimilarity.itemSimilarities(FileItemSimilarity.java:108)
>        at
> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.doEstimatePreference(GenericItemBasedRecommender.java:195)
>        at
> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.estimatePreference(GenericItemBasedRecommender.java:126)
>        at
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:214)
>        at
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:1)
>        at
> org.apache.mahout.cf.taste.impl.common.Cache.getAndCacheValue(Cache.java:127)
>        at org.apache.mahout.cf.taste.impl.common.Cache.get(Cache.java:96)
>        at
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender.estimatePreference(CachingRecommender.java:128)
>
> I am still looking into for what particular case, does the
> FileItemSimilarity go crazy.
> --
> View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1576371.html
> Sent from the Mahout User List mailing list archive at Nabble.com.
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Stanley Ipkiss <sa...@gmail.com>.
Yah, I am trying to see if I can again get the same error. I will update the
thread, after running it on different datasets. Thanks for updating the
code.
-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1598058.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
Yes, try the latest code from HEAD please.

On Tue, Sep 28, 2010 at 8:02 PM, Stanley Ipkiss <sa...@gmail.com> wrote:
>
> Here is the complete stack -

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Stanley Ipkiss <sa...@gmail.com>.
Here is the complete stack -

Exception in thread "main" java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at
org.eclipse.jdt.internal.jarinjarloader.JarRsrcLoader.main(JarRsrcLoader.java:56)
Caused by: org.apache.mahout.cf.taste.common.TasteException:
java.lang.NullPointerException
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator.execute(AbstractDifferenceRecommenderEvaluator.java:209)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator.getEvaluation(AbstractDifferenceRecommenderEvaluator.java:188)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator.evaluate(AbstractDifferenceRecommenderEvaluator.java:132)
        at
org.tsr.recommender.TSRRecommenderEvaluatorRunner.computeMAE(TSRRecommenderEvaluatorRunner.java:65)
        at
org.tsr.recommender.TSRRecommenderEvaluatorRunner.main(TSRRecommenderEvaluatorRunner.java:40)
        ... 5 more
Caused by: java.lang.NullPointerException
        at
org.apache.mahout.cf.taste.impl.similarity.file.FileItemSimilarity.itemSimilarities(FileItemSimilarity.java:109)
        at
org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.doEstimatePreference(GenericItemBasedRecommender.java:195)
        at
org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.estimatePreference(GenericItemBasedRecommender.java:126)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:214)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:1)
        at
org.apache.mahout.cf.taste.impl.common.Cache.getAndCacheValue(Cache.java:127)
        at org.apache.mahout.cf.taste.impl.common.Cache.get(Cache.java:96)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender.estimatePreference(CachingRecommender.java:128)
        at
org.TSR.recommender.TSRRecommender.estimatePreference(TSRRecommender.java:391)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator$PreferenceEstimateCallable.call(AbstractDifferenceRecommenderEvaluator.java:256)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator$PreferenceEstimateCallable.call(AbstractDifferenceRecommenderEvaluator.java:1)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator$StatsCallable.call(AbstractDifferenceRecommenderEvaluator.java:301)
        at
org.apache.mahout.cf.taste.impl.eval.AbstractDifferenceRecommenderEvaluator$StatsCallable.call(AbstractDifferenceRecommenderEvaluator.java:1)
        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown
Source)
        at java.lang.Thread.run(Unknown Source)


(Sorry for the late reply; I was travelling)
-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1597994.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Ted Dunning <te...@gmail.com>.
Is that the complete stack trace?  Threaded code like this usually has two
or three levels of "Caused by" seconds.  The last is the critical one.

On Fri, Sep 24, 2010 at 1:07 PM, Stanley Ipkiss <sa...@gmail.com>wrote:

>
> I did that change yesterday in my code, but forgot to post the update here.
> The error that I get sometimes is -
>
> Caused by: java.lang.NullPointerException
>        at
>
> org.apache.mahout.cf.taste.impl.similarity.file.FileItemSimilarity.itemSimilarities(FileItemSimilarity.java:108)
>        at
>
> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.doEstimatePreference(GenericItemBasedRecommender.java:195)
>        at
>
> org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.estimatePreference(GenericItemBasedRecommender.java:126)
>        at
>
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:214)
>        at
>
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:1)
>        at
>
> org.apache.mahout.cf.taste.impl.common.Cache.getAndCacheValue(Cache.java:127)
>        at org.apache.mahout.cf.taste.impl.common.Cache.get(Cache.java:96)
>        at
>
> org.apache.mahout.cf.taste.impl.recommender.CachingRecommender.estimatePreference(CachingRecommender.java:128)
>
> I am still looking into for what particular case, does the
> FileItemSimilarity go crazy.
> --
> View this message in context:
> http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1576371.html
> Sent from the Mahout User List mailing list archive at Nabble.com.
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Stanley Ipkiss <sa...@gmail.com>.
I did that change yesterday in my code, but forgot to post the update here.
The error that I get sometimes is - 

Caused by: java.lang.NullPointerException
        at
org.apache.mahout.cf.taste.impl.similarity.file.FileItemSimilarity.itemSimilarities(FileItemSimilarity.java:108)
        at
org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.doEstimatePreference(GenericItemBasedRecommender.java:195)
        at
org.apache.mahout.cf.taste.impl.recommender.GenericItemBasedRecommender.estimatePreference(GenericItemBasedRecommender.java:126)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:214)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender$EstimatedPrefRetriever.get(CachingRecommender.java:1)
        at
org.apache.mahout.cf.taste.impl.common.Cache.getAndCacheValue(Cache.java:127)
        at org.apache.mahout.cf.taste.impl.common.Cache.get(Cache.java:96)
        at
org.apache.mahout.cf.taste.impl.recommender.CachingRecommender.estimatePreference(CachingRecommender.java:128)

I am still looking into for what particular case, does the
FileItemSimilarity go crazy.
-- 
View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1576371.html
Sent from the Mahout User List mailing list archive at Nabble.com.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
Ah you're right. It says:

"Executes the given tasks, returning a list of Futures holding their
status and results when all complete. Future.isDone() is true for each
element of the returned list."

... which reads to me like "when all complete" modifies "holding"
rather than "returning". Quite changes the meaning. Yes I looked
inside the implementation and it does wait on all results.

The original snippet makes more sense now, since i had written the comment:
// Go look for exceptions here, really

Calling get() is just about looking for exceptions, rather than
waiting on the result. OK, that much was sensible then, but then
isDone() counteracts that.

So it does need to go to accomplish its purpose (good, that was the
last change). Now it should properly report exceptions.


I'm still guessing the original behavior is due to an exception. This
would make that turn up directly.


On Fri, Sep 24, 2010 at 7:43 AM, Ted Dunning <te...@gmail.com> wrote:
> I think not.  See
> http://download.oracle.com/javase/6/docs/api/java/util/concurrent/ExecutorService.htmlfor
> a definition of invokeAll.

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Ted Dunning <te...@gmail.com>.
I think not.  See
http://download.oracle.com/javase/6/docs/api/java/util/concurrent/ExecutorService.htmlfor
a definition of invokeAll.

By definition, invokeAll returns only when *all* tasks are done.  The only
reason for calling get is, as the comment says, in order to transplant
exceptions into the main calling threads stack so they will be delivered
coherently.  Unfortunately, the !isDone idiom prevents get from ever running
(because all tasks are already done).

Removing the if statement as you suggest in a later followup is the correct
thing to do.  There is no possible purpose for the if, even were it
inverted.

On Thu, Sep 23, 2010 at 11:15 PM, Sean Owen <sr...@gmail.com> wrote:

> The logic seems OK to me. invokeAll() kicks off all the Callables. It
> waits for all to finish on account of the calls to get(), which block
> until a result is ready. I think the isDone() call is redundant indeed
> but shouldn't hurt -- get() isn't called in the case that it's already
> done.
>
> Nevertheless I'll try to reproduce this.
>
> On Fri, Sep 24, 2010 at 1:50 AM, Stanley Ipkiss <sa...@gmail.com>
> wrote:
> >
> > For the class PreferenceEstimateCallable, the parent thread does not wait
> for
> > all the child threads of this class to complete. On just adding a few
> simple
> > log statements around the call() function (shown below), I have observed
> > that there were a lot more "Starting" (622 in number) as compared to
> > "Stopping" (1 in number) in my logfile. I ran it multiple times and
> > everytime I got some difference in the total number of logged start and
> > stop. I will try to fix this issue in my checked out code, but just
> wanted
> > to know if anyone else has noted this?
> >
> >   public Void call() throws TasteException {
> >      log.info("Starting - analysis for pref size:" + prefs.length());
> >      for (Preference realPref : prefs) {
> >        ....
> >      }
> >      log.info("Stopping - analysis for pref size:" + prefs.length());
> >      return null;
> >    }
> >
> > --
> > View this message in context:
> http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571411.html
> > Sent from the Mahout User List mailing list archive at Nabble.com.
> >
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
Remember that because it randomly selects test data, the number of
Callabes will changes from run to run.

The only scenario in which I can reproduce this is the case in which
the Callable throws an Exception. That should stop the whole process,
but, actually the isDone() thing prevents it from being detected in
many cases, since it prevents get() from being called.

It's not that the Callable isn't called, or continues running later,
or otherwise starts but doesn't finish.

I'll remove isDone() since that's more correct. For me it works either
way though -- if no exception occurs. I used counters to double-check
the number of results was as expected.

On Fri, Sep 24, 2010 at 7:15 AM, Sean Owen <sr...@gmail.com> wrote:
> The logic seems OK to me. invokeAll() kicks off all the Callables. It
> waits for all to finish on account of the calls to get(), which block
> until a result is ready. I think the isDone() call is redundant indeed
> but shouldn't hurt -- get() isn't called in the case that it's already
> done.
>
> Nevertheless I'll try to reproduce this.
>
> On Fri, Sep 24, 2010 at 1:50 AM, Stanley Ipkiss <sa...@gmail.com> wrote:
>>
>> For the class PreferenceEstimateCallable, the parent thread does not wait for
>> all the child threads of this class to complete. On just adding a few simple
>> log statements around the call() function (shown below), I have observed
>> that there were a lot more "Starting" (622 in number) as compared to
>> "Stopping" (1 in number) in my logfile. I ran it multiple times and
>> everytime I got some difference in the total number of logged start and
>> stop. I will try to fix this issue in my checked out code, but just wanted
>> to know if anyone else has noted this?
>>
>>   public Void call() throws TasteException {
>>      log.info("Starting - analysis for pref size:" + prefs.length());
>>      for (Preference realPref : prefs) {
>>        ....
>>      }
>>      log.info("Stopping - analysis for pref size:" + prefs.length());
>>      return null;
>>    }
>>
>> --
>> View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571411.html
>> Sent from the Mahout User List mailing list archive at Nabble.com.
>>
>

Re: Possible multi thread issue in AbstractDifferenceRecommenderEvaluator

Posted by Sean Owen <sr...@gmail.com>.
The logic seems OK to me. invokeAll() kicks off all the Callables. It
waits for all to finish on account of the calls to get(), which block
until a result is ready. I think the isDone() call is redundant indeed
but shouldn't hurt -- get() isn't called in the case that it's already
done.

Nevertheless I'll try to reproduce this.

On Fri, Sep 24, 2010 at 1:50 AM, Stanley Ipkiss <sa...@gmail.com> wrote:
>
> For the class PreferenceEstimateCallable, the parent thread does not wait for
> all the child threads of this class to complete. On just adding a few simple
> log statements around the call() function (shown below), I have observed
> that there were a lot more "Starting" (622 in number) as compared to
> "Stopping" (1 in number) in my logfile. I ran it multiple times and
> everytime I got some difference in the total number of logged start and
> stop. I will try to fix this issue in my checked out code, but just wanted
> to know if anyone else has noted this?
>
>   public Void call() throws TasteException {
>      log.info("Starting - analysis for pref size:" + prefs.length());
>      for (Preference realPref : prefs) {
>        ....
>      }
>      log.info("Stopping - analysis for pref size:" + prefs.length());
>      return null;
>    }
>
> --
> View this message in context: http://lucene.472066.n3.nabble.com/Possible-multi-thread-issue-in-AbstractDifferenceRecommenderEvaluator-tp1571411p1571411.html
> Sent from the Mahout User List mailing list archive at Nabble.com.
>