 |
Malach
Apprentice
Joined: 03 Nov 2007
Posts: 132
|
 Posted: Sun Nov 18, 2007 3:18 pm
[2.12] Problem with string list variables
|
With the debugger open, type on the command line "#ADDITEM TestList dog". Debugger should show something like this:
08:09:25.084a | ---
08:09:25.086a | c CleanLus | [9] CleanLusternia Comline : start : #ADDITEM TestList dog
08:09:25.090a | d CleanLus | [9] CleanLusternia Comline : stopped
Type in #ADDITEM TestList cat:
08:09:36.956a | ---
08:09:36.959a | c CleanLus | [9] CleanLusternia Comline : start : #ADDITEM TestList cat
08:09:36.962a | k CleanLus | [9] Var "TestList" changed from "" to "dog"
08:09:36.964a | d CleanLus | [9] CleanLusternia Comline : stopped
Type in #ADDITEM TestList mouse:
08:09:47.870a | c CleanLus | [9] CleanLusternia Comline : start : #ADDITEM TestList mouse
08:09:47.873a | k CleanLus | [9] Var "TestList" changed from "" to "dog"
08:09:47.876a | d CleanLus | [9] CleanLusternia Comline : stopped
I did thise with no packages loaded. Anyone else get similar results? What's even more curious is when I go to delete dog with #DELITEM TestList dog, I get:
08:12:51.363a | c CleanLus | [9] CleanLusternia Comline : start : #DELITEM TestList dog
08:12:51.366a | k CleanLus | [9] Var "TestList" changed from "" to "dog|cat|mouse"
08:12:51.368a | d CleanLus | [9] CleanLusternia Comline : stopped
Then I go to add another item, #ADDITEM TestList parrot, and I get:
08:13:05.970a | c CleanLus | [9] CleanLusternia Comline : start : #ADDITEM TestList parrot
08:13:05.972a | k CleanLus | [9] Var "TestList" changed from "" to "dog|cat|mouse"
08:13:05.974a | d CleanLus | [9] CleanLusternia Comline : stopped
TestList was set with the proper items each time but it's kind of curious that the debugger is showing this. Why would it be doing this? |
|
Last edited by Malach on Sun Nov 18, 2007 3:42 pm; edited 1 time in total |
 |
|
|
Malach
Apprentice
Joined: 03 Nov 2007
Posts: 132
|
Posted: Sun Nov 18, 2007 3:37 pm
|
So then this is VERY weird. I reenabled the rest of my packages to continue testing for bugs. I have triggers to capture when I have a certain condition and then add it to a stringlist and for testing purposes they tell me what the stringlist looks like every time they add something. Here is what I got after doing the above test:
08:24:01.397a | a CleanLus |You are:
08:24:01.403a | a CleanLus |afflicted by horrible asthma.
08:24:01.406a | f CleanLus | Pattern: ^afflicted by horrible asthma.$
08:24:01.409a | c CleanLus | [10] CleanLusternia Trigger : start : Pattern "^afflicted by horrible asthma.$" : asthma Verify
08:24:01.413a | m CleanLus | [10] Event "AddAffliction" raised : (%1="hasthma")
08:24:01.415a | c CleanLus | [10] CleanLusternia Trigger : exec : Pattern "^afflicted by horrible asthma.$" : asthma Verify
08:24:01.422a | a CleanLus | adding hasthma nonverified
08:24:01.429a | k CleanLus | [10] Var "AfflictionList" changed from "" to "hshyness"
08:24:01.431a | f CleanLus | Expression: @AfflictionList && @CureTry == 0
08:24:01.434a | c CleanLus | [39] ExpTrig : start : Expression "CureExpression" : #say Cure Expression #T- Cu...
08:24:01.438a | a CleanLus |Cure Expression
08:24:01.444a | k CleanLus | [39] Var "CureTry" changed from "0" to "1"
08:24:01.446a | d CleanLus | [39] ExpTrig : wait 200 ms
08:24:01.449a | a CleanLus |dog|cat
The three things of note are bolded. The AddAffliction event's commands would be #ADDITEM AfflictionList hasthma. The "dog|cat" showed when I had my alias do #SAY @AfflictionList. Further, while my aliases to get items off that list to cure them were curing the proper things, when they were cured, they were not being deleted from the list properly. There is absolutely nothing in any of my packages that would have called up anything to do with that TestList variable. Something is very odd. |
|
|
|
|
Vijilante
SubAdmin
Joined: 18 Nov 2001
Posts: 5182
|
Posted: Sun Nov 18, 2007 4:27 pm
|
I have seen the same kind of variable change messages with #ADDITEM and #DELITEM. There is a nice big log of it in my 100% lock up topic.
I am guessing that the changes Zugg made to suspending and resuming threads are causing these problems. The change he described would be applied to all threads, CMud uses 12 or so for itself. It looks like a data synchonisation problem and I am relatively sure about the cause.
Your having the wrong the variable displayed is the first I have seen of that sort of error outside of the debugger window. |
|
_________________
The only good questions are the ones we have never answered before.
Search the Forums |
|
|
|
Malach
Apprentice
Joined: 03 Nov 2007
Posts: 132
|
Posted: Sun Nov 18, 2007 5:26 pm
|
Yeah I had thought it was just a debugger display issue initially but then all of a sudden I had dog and cat afflictions. Very odd.
|
|
_________________
Intel Core2 Quad CPU @ 2.4 GHZ with Windows Vista Home Premium and 2 GB Ram |
|
|
|
Vijilante
SubAdmin
Joined: 18 Nov 2001
Posts: 5182
|
Posted: Sun Nov 18, 2007 10:13 pm
|
I still haven't quite found it affecting other variables, but I do have a few interesting tests done that show portions of CMud other then the debugger window are affected by this bug.
The different command lines I used during these test are
| Code: |
#LOOP 65,96 {#ADDITEM def {%char(%i)}};#LOOP 65,96 {#DELITEM def {%char(%i)}}
#LOOP 65,96 {#ADDITEM def {%char(%i)}}
#LOOP 65,96 {#DELITEM def {%char(%i)}}
#ALIAS abc {#SHOW @def} |
Each of those lines is seperately for some tests.
First I did the alias line followed by the additem line. I then opened the PE, clicked the alias, and moused over the reference to def. The popup hint displays the contents nicely. I then did the delitem line, clicked back to the PE and moused over def again. It showed the variable as fully populated. After a little bit it updated to show it as empty. This test was repeated a bunch of times.
Then I finally opened the debugger window, checked that variable change messages are active and did the add+del line. This is the output from a bunch of those.
| Code: |
04:50:28.418p | ---
04:50:28.418p | c untitled | [1] untitled Comline : start : #LOOP 65,96 {#ADDITEM def {%char(%i)}};#LOOP 65,96 {#DELI...
04:50:28.438p | d untitled | [1] untitled Comline : stopped
04:50:50.800p | ---
04:50:50.800p | c untitled | [1] untitled Comline : start : #LOOP 65,96 {#ADDITEM def {%char(%i)}};#LOOP 65,96 {#DELI...
04:50:50.820p | d untitled | [1] untitled Comline : stopped
04:51:33.281p | ---
04:51:33.281p | c untitled | [1] untitled Comline : start : #LOOP 65,96 {#ADDITEM def {%char(%i)}}
04:51:33.291p | d untitled | [1] untitled Comline : stopped
04:51:44.848p | k untitled | Var "def" changed from "" to "A|B|C|D|E|F|G|H|I|J|K|L|M|N|O|P|Q|R|S|T|U|V|W|X|Y|Z|[|\|]|^|_|`"
04:52:38.966p | --- |
As you can see no change was reported, and between test I was checking the mouse over to see if it was correct. Finally I did the additem line again. When I check the mouse over in the PE it reported empty. I moused off and moused back over and now it reported populated. You can see the 11 second difference between when the loop finished and when the variable was finally reported as changed.
I ran the delitem line twice more, this time they showed the consistently erronius var change messages
| Code: |
04:55:28.479p | k untitled | [1] Var "def" changed from "" to "A|B|C|D|E|F|G|H|I|J|K|L|M|N|O|P|Q|R|S|T|U|V|W|X|Y|Z|[|\|]|^|_|`"
04:55:28.479p | k untitled | [1] Var "def" changed from "" to "A|B|C|D|E|F|G|H|I|J|K|L|M|N|O|P|Q|R|S|T|U|V|W|X|Y|Z|[|\|]|^|_|`"
04:55:28.479p | k untitled | [1] Var "def" changed from "" to "A|B|C|D|E|F|G|H|I|J|K|L|M|N|O|P|Q|R|S|T|U|V|W|X|Y|Z|[|\|]|^|_|`" |
30 minutes after doing those runs as I consider what else to try and put this together the mouse over in the PE still hadn't changed. So I decided I would look at the variable directly in the PE.
Even after all the time writing this and putting up the image; when I click back to the alias and mouse over the def reference it still shows the variable as populated.
I think those tests pretty well show that it is a synchronisation issue, and leads to further complications as it gets worse. |
|
_________________
The only good questions are the ones we have never answered before.
Search the Forums |
|
|
|
darmir
Sorcerer
Joined: 10 Oct 2000
Posts: 706
Location: USA
|
Posted: Mon Nov 19, 2007 2:55 pm
|
I also notice that my string list variables aren't working either. I will put it through the debugger and see what I get.
|
|
_________________
Run as hard as a wild beast if you will, but you won't get any reward greater than that destined for you.
Source: (Egyptian) |
|
|
|
Zugg
MASTER
Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA
|
Posted: Mon Nov 19, 2007 5:52 pm
|
I know there is definitely a problem with the debugger window with string lists and database variables. But I wasn't aware of any other synchronization issues. I'll run Vijilante's test to see what I can learn.
|
|
|
|
|
Zugg
MASTER
Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA
|
Posted: Mon Nov 19, 2007 7:46 pm
|
Also, I should let people know that using the "Show Var changes" debug option *can* slow down scripts using string lists or database variables, and can also possibly cause interaction with these variables.
CMUD tries to keep string lists and database variables stored internally as hash tables (and linked lists). Converting a string (like "a|b|c") to a hash table adds overhead. And converting a hash table back to a string value also adds overhead.
Since the debugger window needs to display the *string* value of the list, it needs to call the routine to convert the hash table to a string value. This will slow down your script. Since this also updates the internally cached string value, it can cause bad interactions because of the bug in the debugger.
The bug in the debugger is that it is showing the string value of the list *before* the hash table gets updated. But this action causes the cached string value to change. So you might see different script results having this debugger option turned on or off.
I'll obviously fix this bug in the debugger, but I wanted to post more info on this so that people might understand more of how this bug could cause problems in their script. |
|
|
|
|
Zugg
MASTER
Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA
|
Posted: Mon Nov 19, 2007 8:07 pm
|
Also, while I will play with Vijilante's tests to see what I can find, remember that CMUD tries very hard to only convert the hash table into a string value when it absolutely needs to. So, normally when you use #ADDITEM, #DELITEM, etc, you are modifying the hash table, but CMUD doesn't convert this to a string until it is needed.
The act of using the mouse-over will force this conversion to a string. Using the debugger to monitor variable changes will force this conversion to a string (albeit with the bug in the debugger above).
So, this can get quite complicated and is definitely a case where inspecting/debugger can have an effect on the script (since it forces the conversion to a string). |
|
|
|
|
darmir
Sorcerer
Joined: 10 Oct 2000
Posts: 706
Location: USA
|
Posted: Mon Nov 19, 2007 8:09 pm
|
Zugg, You have a copy of my Auto Eat Package. This package uses lists quite a bit. Maybe that pkg will help you research it.
Also not to change the subject but did you find the issue with the Package Library? |
|
_________________
Run as hard as a wild beast if you will, but you won't get any reward greater than that destined for you.
Source: (Egyptian) |
|
|
|
Zugg
MASTER
Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA
|
Posted: Mon Nov 19, 2007 8:12 pm
|
| Quote: |
| After a little bit it updated to show it as empty |
What is happening here is that the background routine that writes the changes to the actual *.PKG file needs to store a string value. So this routine also forces the conversion from the hash table to the string list.
So it sounds maybe like the mouse-over routine isn't performing the string conversion somehow and you are seeing the old cached value instead of the current hash-table value. |
|
|
|
|
Zugg
MASTER
Joined: 25 Sep 2000
Posts: 23379
Location: Colorado, USA
|
Posted: Mon Nov 19, 2007 9:03 pm
|
OK, I *did* find some issues with this. Should be fixed for 2.13.
|
|
|
|
|
|
|
|
