Bug - Fixed Performance issues

lostcalpolydude

Developer
Staff member
Using 12676, so far today I have had mafia's GUI become completely unresponsive twice. I was able to do things in the relay browser, but the CLI stopped updating. I couldn't click in the text entry area of the CLI, I couldn't click to do anything else, and I couldn't even click the X to close windows.
 

xKiv

Active member
Yep, I see deadlocks (two threads each wait on a LockableListModel locked by the other thread). Wrong amount of synchronization. Either there has to be a bigger common lock somewhere up, or less synchronization.
Yesterday I had no problem when I synchronized just .sort and .updateSingleFilter.
I think I will try locally "fixing" this by putting in a static object to use as a lock instead of "this".

ETA: that didn't help. I am going to revert myself to yesterday's version of the file.

(also - sorry for not remembering to write down which two threads it was)
 
Last edited:

Veracity

Developer
Staff member
Try 12678.

Thread info will be helpful in the future - in particular, which two threads, and where, exactly, they are deadlocked.
Thanks.
 

magered

New member
I'm experiencing the same deadlock as lostcalpolydude and xKiv, starting with KoLmafia-12675.jar through (and including) KoLmafia-12678.jar. I reverted back to my last downloaded known good version KoLmafia-12657.jar (the version between that and 675 I did not try) without experiencing the lock up problem.

While you cannot manipulate mafia in anyway (including not being able to close it) once it locks up, you can still use the relay browser (FF23.0.1 w/GM) to play (as it's already opened when I experience the deadlock) but I experience a lot of failure to transition in the main pane during adventure.php instances requiring a use of a link in either the character or links pane to get the main pane working again.

*edit*
Went back and downloaded KoLmafia-12674.jar and it runs fine.

V/R,
MageRed
 
Last edited:
OK, I have some more data to report. Since KoLmafia r12674:

On a character with nothing equipped at all, trying to equip something from the the Gear Manager does NOT deadlock Mafia.
On a character with stuff equipped already, changing equipment from the Gear Manager deadlocks Mafia.
 

Veracity

Developer
Staff member
Seems only fair, considering I created the problem. ;)

Now - I will be interested to see if this resolves the bugs that xKiv described that led me to add the additional synchronization to LockableListModel.
 

zarqon

Well-known member
Back on the subject of caching things, I've noticed that now when I edit one of the .js files (in the relay folder) linked to by one of my relay scripts, I now need to force the browser to refresh that file (I open the actual .js file in a separate tab, where I can see it's not using my edits yet, and then hit refresh). It used to always use the updated file without needing a force-refresh. Is this a side effect of one of the image caching updates?
 

Veracity

Developer
Staff member
Maybe. Perhaps we are now erroneously sending LastModified on .js files from the Relay folder. I'll look at it; what you describe is clearly wrong.
 

Veracity

Developer
Staff member
I'm not seeing where that would happen.

Can I see a DEBUG log, complete with "show browser interactions", of you "refreshing" a .js file, please? Thanks.
 

xKiv

Active member
Seems only fair, considering I created the problem. ;)

Now - I will be interested to see if this resolves the bugs that xKiv described that led me to add the additional synchronization to LockableListModel.

Probably. That should be entirely covered by syncrhonizing sort(actualElements) and sort(visibleElements) in the same block + synchronizing updateSingleFilter on the same "this".
But that issue only appeared once in a while for me [1], so absence of symptoms won't *prove* absence of problem.

[1] seemed to be most frequent on days with slow servers/internet - makes sense, since slower responses give threads more time to tangle.
 

Veracity

Developer
Staff member
I've seen plenty of inexplicable things over the years that seem to indicate duplicating visibleElements. For example, the enite session tally in the AdventureFrame being doubled, items in Booze panel of the Item Manager being duplicated multiple times, and so on.
 

zarqon

Well-known member
Ok, I made a test .js file ztest.js:

PHP:
jQuery(function($){
   alert('Hey there!');
});

And a test relay script relay_ztest.ash, which imports jQuery and my test script:

PHP:
buffer page;
page.append("<html><head>\n<title>Test</title>\n");
page.append("<script src=\"jquery1.10.1.min.js\"></script>\n<script src=\"ztest.js\"></script>\n");
page.append("<link href='/images/styles.20120512.css' type='text/css' rel='stylesheet'/>\n");
page.append("</head>\n<body>This is a test.</body>");
page.write();

Then I turned on debug logging and performed the following steps:

  1. I ran the script once by selecting it from the relay menu in the browser and got the "Hey there!" alert.
  2. I edited the .js file to alert "How is it going?" instead of "Hey there!"
  3. I ran the script again and still got the "Hey there!" alert.
  4. I opened up a separate tab pointing to http://127.0.0.1:60080/ztest.js. It showed the "Hey there!" code.
  5. I hit refresh on the browser, causing it to update to the "How is it going?" code.
  6. I ran the script again, and got the correct, updated alert message.
Hopefully this debug log containing all the above will help you to find the problem.

EDIT: Although, looking at it, all it really seems to contain is the append() function being called 12 times (running the script 3x). Do I need to configure something differently to get more useful results?
 

Attachments

  • DEBUG_20130921.txt
    6.1 KB · Views: 38
Last edited:

Veracity

Developer
Staff member
I see no request/response whatsoever from the browser in your DEBUG log.
Did you forget to turn on the "Verbosely log communication between KoLmafia and browser" setting like I requested?
 

zarqon

Well-known member
Yes. I blame the page break. And myself. :) Here is the exact same sequence, except I edited the .js file to contain only alert('First'); and I edited the ash script to link only to the .js file, not jQuery or the stylesheet.

ETA: Looks like mafia always reported the .js file as being not modified, though I did edit it in between the first and second calls to the script.
 

Attachments

  • DEBUG_20130921.txt
    8.1 KB · Views: 43
Last edited:

Veracity

Developer
Staff member
OK. I see that the Browser is asking for If-Modified-Since and we are sending back Not Modified.
I will look at that code. Later. I am about to leave for the rest of the day.
 

xKiv

Active member
Zarquon, do your file timestamps change when you save the files? Better check *that* too! (maybe report listed modification time before and after editing?)

I've seen plenty of inexplicable things over the years that seem to indicate duplicating visibleElements. For example, the enite session tally in the AdventureFrame being doubled, items in Booze panel of the Item Manager being duplicated multiple times, and so on.

So if we go years (= at least two) without anybody seeing anything like that, we can close the issue ?-)
 

Veracity

Developer
Staff member
Looks like mafia always reported the .js file as being not modified, though I did edit it in between the first and second calls to the script.
There were a couple of bugs here. I couldn't see why your Browser asked for If-Modified-Since for a .js file since I didn't think we were sending Last-Modifed for such files. Alas, we were.

Also, the whole code for checking if a file in the relay folder was modified was bogus; it "assumed" that any such file was not modified if it had seen it before; after all, that "saves time", as the comment said.

Both issues should be fixed in 12689.

Unfortunately, you need to clear your browser cache - but not KoLmafia's image cache, so it will reload quickly. ;)

So if we go years (= at least two) without anybody seeing anything like that, we can close the issue ?-)
I don't guarantee that corruption of the visible elements of LockableListModel is what is causing everybody's slowdown as KoLmafia keeps running. It was an issue for you, but let's see if people continue to see issues and report them on this thread.

I don't think we can close this thread until Darzil declares himself happy. :)
 

Bale

Minion
I don't think we can close this thread until Darzil declares himself happy. :)

Since this has been noted by many KoLmafia users, I thought we might want to get feedback from a cross-section of them to help us decide if it was time to close the thread. I asked people to chime in on the subject here.
 
Top