Tried to cd() already freed item

[tavmem]

This is a relatively minor issue that appeared in MacOS after the fix to #571. When you run ./k_test and then you exit, it happens in the cleanup process. It does not occur in Fedora or in Windows. It is not known whether it occurs in FreeBSD.

$ ./k_test
t:0
t:50
t:100
t:150
t:200
t:250
t:300
t:350
t:400
t:450
t:500
t:550
t:600
t:650
t:700
t:750
t:800
t:850
t:900
t:950
t:1000
t:1050
t:1100
Test pass rate: 1.0000, Total: 1125, Passed: 1092, Skipped: 33, Failed: 0, Time: 0.493934s
OK
kona      \ for help. \\ to exit.

  \\
src/km.c:68: Tried to cd() already freed item
src/km.c:68: (I)tests=1125
src/km.c:68: (I)(L)x=4481466112
src/km.c:68: (I)rc(x)=0
src/km.c:68: (I)x->t=0
src/km.c:68: (I)x->n=0
()
$

The problem does NOT occur if the test for issue 571 is commented out. The problem does NOT occur if ONLY the test for issue 571 is run.

[tavmem]

If we add/change the following 4 lines:

$ git diff
diff --git a/src/k.c b/src/k.c
index ffacbd9..a275e85 100644
--- a/src/k.c
+++ b/src/k.c
@@ -24,6 +24,7 @@
 extern I listener;
 #endif

+extern K sd(K x);     extern K sd_(K x,I f);      I ABC=0;
 K stopDict=0;
 I fStop=0;

@@ -559,7 +560,7 @@ void finally()
 {
   nfinish();
 #ifdef DEBUG
-  tf(SYMBOLS); cd(KTREE); cd(KFIXED);
+  tf(SYMBOLS); cd(KTREE); O("sd(KFIXED):");sd(KFIXED); ABC=1; cd(KFIXED); ABC=0; O("\n");
   //valgrind --leak-check=full --show-reachable=yes /tmp/a.out
 #endif
 }
diff --git a/src/km.c b/src/km.c
index 8496150..c6cb34a 100644
--- a/src/km.c
+++ b/src/km.c
@@ -9,6 +9,7 @@
 #include "k.h"
 #include "km.h"

+extern I ABC;

 //Notes on memory manager: seems like atoms (and small lists?) are not released
 //by K4 (see Skelton's remark: only contiguous arrays greater than 32MB are
@@ -64,6 +65,7 @@ K mrc(K x,I c){I k=sz(xt,xn);I r=lsz(k);x->_c=(c<<8)|r;R x;}
 //This source would be improved by getting ridding of remaing malloc/calloc/realloc
 K cd(K x)
 {
+  if(ABC && x){O("%lld BEG cd   ",ABC); ABC++; show(x); if(0==x->t && 0==x->n)O("**************************************************\n");}
   #ifdef DEBUG
   if(x && rc(x) <=0 ) { er(Tried to cd() already freed item) dd(tests) dd((L)x) dd(rc(x)) dd(x->t) dd(x->n) show(x); }
   #endif
$

we verify that the problem occurs in the "cleanup" of KFIXED. cd(K x) is called 459 times. The problem begins in the 148th call, and occurs in the 155th call:

148 BEG cd   .,(();;)
149 BEG cd   (();;)
150 BEG cd   151 BEG cd   
152 BEG cd   0x35 ` 0x0  
153 BEG cd   .()
154 BEG cd   .()
155 BEG cd   ()
**************************************************
src/km.c:70: Tried to cd() already freed item
src/km.c:70: (I)tests=1125
src/km.c:70: (I)(L)x=4558761728
src/km.c:70: (I)rc(x)=0
src/km.c:70: (I)x->t=0
src/km.c:70: (I)x->n=0
()
156 BEG cd   .()

If we comment out the test for issue 571 and run it again, then cd(K x) is again called 459 times. You can see the difference in call 148 and call 155

148 BEG cd   .,(`"";;)
149 BEG cd   (`"";;)
150 BEG cd   151 BEG cd   
152 BEG cd   0x35 ` 0x0  
153 BEG cd   .()
154 BEG cd   .()
155 BEG cd   `""
156 BEG cd   .()

[tavmem]

If we run ONLY the test for 571, then there is only 1 element in KFIXED, and the problem does not occur:

$ ./k_test
t:0
Test pass rate: 1.0000, Total: 1, Passed: 1, Skipped: 0, Failed: 0, Time: 0.000295s
OK
kona      \ for help. \\ to exit.

  \\
sd(KFIXED):     0x10762f080 0x10762f098            1-6 0 1   
,
1 BEG cd   ,
2 BEG cd   
$ 

[tavmem]

Some interesting observations: If we run only the batch tests02 the problem does not occur, but we can suppress tests01 and the problem does occur. We need to include the testsBook batch of tests for the problem to occur. If we make these code changes:

$ git diff
diff --git a/src/km.c b/src/km.c
index 8496150..00d94ca 100644
--- a/src/km.c
+++ b/src/km.c
@@ -9,6 +9,7 @@
 #include "k.h"
 #include "km.h"

+extern K sd(K x);     extern K sd_(K x,I f);

 //Notes on memory manager: seems like atoms (and small lists?) are not released
 //by K4 (see Skelton's remark: only contiguous arrays greater than 32MB are
@@ -64,8 +65,9 @@ K mrc(K x,I c){I k=sz(xt,xn);I r=lsz(k);x->_c=(c<<8)|r;R x;}
 //This source would be improved by getting ridding of remaing malloc/calloc/realloc
 K cd(K x)
 {
+   if(x && 0==x->t && 0==x->n){ O("BEG cd   "); sd_(x,2); }
   #ifdef DEBUG
-  if(x && rc(x) <=0 ) { er(Tried to cd() already freed item) dd(tests) dd((L)x) dd(rc(x)) dd(x->t) dd(x->n) show(x); }
+  if(x && rc(x) <=0 ) { er(Tried to cd() already freed item) dd(tests) dd((L)x) dd(rc(x)) dd(x->t) dd(x->n) sd_(x,2); }
   #endif

   P(!x,0)
diff --git a/src/tests.c b/src/tests.c
index e67bcb3..e154c0b 100644
--- a/src/tests.c
+++ b/src/tests.c
@@ -66,7 +66,7 @@ I test()
 { testtime=clock();

   testsBook();
-  tests01();
+  //tests01();
   tests02();
   testsIO();  //could become slow - in the future may not want to test by default
   K x; x=_(567);if(!tp(x && *kI(x)==567))fprintf(stderr,"\n\nK string execution broken\n\n"); cd(x);
@@ -91,6 +91,7 @@ Z I testsIO()

 Z I tests02()
 {
+  O("tests02 ******************************************************\n");
   TC(`b,(`a`b)[1])
   TC(2, {1+1} 0)
   TC(2, {a:1;a+a} _n )
$

we get a record of every time cd(K x) is run where 0==x->t && 0==x->n and we can tell when batch tests02 begins. The error does occur

src/km.c:70: Tried to cd() already freed item
src/km.c:70: (I)tests=1012
src/km.c:70: (I)(L)x=4434194176
src/km.c:70: (I)rc(x)=0
src/km.c:70: (I)x->t=0
src/km.c:70: (I)x->n=0
     0x1084c6f00 0x1084c6f18            0-0 0 0   
()

and earlier in the record we get

BEG cd        0x1084da780 0x1084da798            17321072-0 0 0   
()
BEG cd        0x1084e0180 0x1084e0198            1-6 0 0   
()
BEG cd        0x1084c6e80 0x1084c6e98            1-6 0 0   
()
BEG cd        0x1084c6f00 0x1084c6f18            1-0 0 0   
()

There is confirmation that the cd(K x) occurred on 0x1084c6f00 but we also see an entry where the "count" is 173211072 and the "lane" is 0 which is clearly an anomaly.

We can also tell that the problem does not occur in the testsBook batch although the testsBook batch needs to be included to get the problem in tests02.

[tavmem]

If we add this code change:

$ git diff src/p.c
diff --git a/src/p.c b/src/p.c
index a565bda..96420b6 100644
--- a/src/p.c
+++ b/src/p.c
@@ -251,7 +251,7 @@ I mark(I*m,I k,I t){ DO(k, m[i]=i?t:-t) R k; }
 //      so the check probably has to do with whether some useful symbol occurred on the line already
 //other errors: syntax error

-K wd(S s, int n){ lineA=s; fdc=0; R wd_(s,n,denameD(&KTREE,d_,1),0); }
+K wd(S s, int n){ O("s: %s\n",s); lineA=s; fdc=0; R wd_(s,n,denameD(&KTREE,d_,1),0); }

 K wd_(S s, int n, K*dict, K func) //parse: s input string, n length;
 { //assumes: s does not contain a }])([{ mismatch, s is a "complete" expression
$

we can tell what test the problem occurs in

src/km.c:70: Tried to cd() already freed item
src/km.c:70: (I)tests=1012
src/km.c:70: (I)(L)x=4363886336
src/km.c:70: (I)rc(x)=0
src/km.c:70: (I)x->t=0
src/km.c:70: (I)x->n=0
     0x1041b9f00 0x1041b9f18            0-0 0 0   
()

and

s: d:.((`a;0);(`b;1)); `d .`b
BEG cd        0x1041cb840 0x1041cb858            1-6 0 0
()
BEG cd        0x1041cd780 0x1041cd798            17046432-0 0 0
()
s: .[;;;;]
s: .[;;;;]
s: .[]
BEG cd        0x1041d3180 0x1041d3198            1-6 0 0
()
s: .[]
BEG cd        0x1041b9e80 0x1041b9e98            1-6 0 0
()
BEG cd        0x1041b9f00 0x1041b9f18            1-0 0 0
()
BEG cd        0x1041cd780 0x1041cd798            1-0 0 0
()
s: .[*; (3;4); :]

The anomaly occurs in the test for issue 571 TC( 1, d:.((`a;0);(`b;1)); `d .`b ) // issue 571 The problem (cd'ing a k-structure which somehow gets included in KFIXED for cd'ing a second time) occurs in the 2nd run of the 2nd test for issue 543 TC( .[], .[] ) // issue 543 testing for leaks

[tavmem]

If we place the 2nd test for issue 543 before the test for issue 571

$ git diff
diff --git a/src/tests.c b/src/tests.c
index e67bcb3..c6ec8d5 100644
--- a/src/tests.c
+++ b/src/tests.c
@@ -313,9 +313,9 @@ Z I tests02()
   TC( -1, 4: (.((`a;1);(`b;2)))(,`a) )            // issue 561
   TC_( "1 2", "(1 2 1)\\1" )                      // issue 572
   TC_( "12 6 3", "0 1 1 3 2 5 3 7 4 9 5 11 6\\ 12" )       // issue 572
+  TC( .[], .[] )                                  // issue 543  testing for leaks
   TC( 1, d:.((`a;0);(`b;1)); `d .`b )             // issue 571
   TC( .[;;;;], .[;;;;] )                          // issue 543  testing for leaks
-  TC( .[], .[] )                                  // issue 543  testing for leaks

   //Error trap: {[a;b][c;d] a+b} -> parse error ; { {[a][b] }} -> parse error
   TC(.[*; (3;4); :], (0;12) )
$

All tests pass, the current problem with cd(K x) disappears, but we get a memory leak in the remaining test for issue 571 (which is still being run after the test for issue 571).

$ ./k_test
t:0
t:50
t:100
t:150
t:200
t:250
t:300
t:350
t:400
t:450
t:500
t:550
t:600
t:650
t:700
Failed: Memory Leak - .[;;;;], .[;;;;] 
Allocated K: 51
Unfreed K  : 10
Leak %     : 0.196078
c:1 t:7 n:0 | k:0x106261800

c:1 t:5 n:0 | k:0x106277440
.()
c:1 t:5 n:0 | k:0x1062605c0
.()
c:1 t:-4 n:2 | k:0x106260600
0x3a 
0x0  
c:1 t:7 n:0 | k:0x106261780

c:1 t:5 n:0 | k:0x106279780
.()
c:1 t:5 n:0 | k:0x106277940
.()
c:1 t:-4 n:5 | k:0x106278d80
0x1 
0x1 
0x1 
0x1 
0x0  
c:1 t:4 n:1 | k:0x1062659c0
`
c:17180673 t:0 n:0 | k:0x106279040
()
t:750
t:800
t:850
t:900
t:950
t:1000
t:1050
t:1100
Test pass rate: 0.9991, Total: 1125, Passed: 1091, Skipped: 33, Failed: 1, Time: 0.493001s
fail
kona      \ for help. \\ to exit.

  \\
$

[tavmem]

If we place the test for issue 571 after both tests for issue 543, all problems disappear:

$ git diff
diff --git a/src/tests.c b/src/tests.c
index e67bcb3..c223864 100644
--- a/src/tests.c
+++ b/src/tests.c
@@ -313,9 +313,9 @@ Z I tests02()
   TC( -1, 4: (.((`a;1);(`b;2)))(,`a) )            // issue 561
   TC_( "1 2", "(1 2 1)\\1" )                      // issue 572
   TC_( "12 6 3", "0 1 1 3 2 5 3 7 4 9 5 11 6\\ 12" )       // issue 572
-  TC( 1, d:.((`a;0);(`b;1)); `d .`b )             // issue 571
   TC( .[;;;;], .[;;;;] )                          // issue 543  testing for leaks
   TC( .[], .[] )                                  // issue 543  testing for leaks
+  TC( 1, d:.((`a;0);(`b;1)); `d .`b )             // issue 571

   //Error trap: {[a;b][c;d] a+b} -> parse error ; { {[a][b] }} -> parse error
   TC(.[*; (3;4); :], (0;12) )
$

$ ./k_test
t:0
t:50
t:100
t:150
t:200
t:250
t:300
t:350
t:400
t:450
t:500
t:550
t:600
t:650
t:700
t:750
t:800
t:850
t:900
t:950
t:1000
t:1050
t:1100
Test pass rate: 1.0000, Total: 1125, Passed: 1092, Skipped: 33, Failed: 0, Time: 0.494187s
OK
kona      \ for help. \\ to exit.

  \\
$ 

[tavmem]

However, though all problems disappear if the test for issue 571 is run AFTER both tests for issue 543, the anomaly still occurs in issue 571:

Test pass rate: 1.0000, Total: 1125, Passed: 1092, Skipped: 33, Failed: 0, Time: 0.550676s
OK
kona      \ for help. \\ to exit.

  \\

and

s: 0 1 1 3 2 5 3 7 4 9 5 11 6\ 12
s: .[;;;;]
s: .[;;;;]
s: .[]
BEG cd        0x10ae20e40 0x10ae20e58            1-6 0 0   
()
s: .[]
BEG cd        0x10ae0cf80 0x10ae0cf98            1-6 0 0   
()
BEG cd        0x10ae20e80 0x10ae20e98            1-0 0 0   
()
BEG cd        0x10ae21140 0x10ae21158            1-0 0 0   
()
s: 1
s: d:.((`a;0);(`b;1)); `d .`b
BEG cd        0x10ae20e40 0x10ae20e58            1-6 0 0   
()
BEG cd        0x10ae20d80 0x10ae20d98            17490091--128 0 0   
()
s: .[*; (3;4); :]

[tavmem]

and ... if ONLY the test for issue 571 is run

$ git diff src/tests.c
diff --git a/src/tests.c b/src/tests.c
index e67bcb3..17f32eb 100644
--- a/src/tests.c
+++ b/src/tests.c
@@ -69,7 +69,7 @@ I test()
   tests01();
   tests02();
   testsIO();  //could become slow - in the future may not want to test by default
-  K x; x=_(567);if(!tp(x && *kI(x)==567))fprintf(stderr,"\n\nK string execution broken\n\n"); cd(x);
+  //K x; x=_(567);if(!tp(x && *kI(x)==567))fprintf(stderr,"\n\nK string execution broken\n\n"); cd(x);

 //done:
   testtime=(clock()-testtime)/CLOCKS_PER_SEC;
@@ -91,6 +91,8 @@ Z I testsIO()

 Z I tests02()
 {
+  TC( 1, d:.((`a;0);(`b;1)); `d .`b )             // issue 571
+  R 0;
   TC(`b,(`a`b)[1])
   TC(2, {1+1} 0)
   TC(2, {a:1;a+a} _n )
@@ -865,6 +867,7 @@ Z I tests02()

 Z I tests01()
 {
+  R 0;
   //Backslashes must be represented as \\, percent-signs as %%
   //For ' and // use TC_("string","string")
   //TC(skip,1,1) //How to skip a test that used to look like TC(1,1)
@@ -990,6 +993,7 @@ Z I tests01()

 Z I testsBook()
 {
+  R 0;
   //K Manual 2.0 compliance
   TC(1 0 1 0 0 2 0 1 2 1,A.I:1 2 3;A.F:2 5 7;B.F: 5 2 5 2 2 7 2 5 7 5; A.F ?/: B.F )
   //TC((2 1 2 1 1 3 1 2 3 2;5 2 5 2 2 7 2 5 7 5) ,A.I:1 2 3;A.F:2 5 7;B.F: 5 2 5 2 2 7 2 5 7 5; A[;A.F?/:B.F] )
$ 

we still get the anomaly

$ ./k_test
t:0
s: 1
s: d:.((`a;0);(`b;1)); `d .`b
BEG cd        0x1019b7480 0x1019b7498            1-6 0 0   
()
BEG cd        0x1019ba280 0x1019ba298            16882548-64 0 0   
()
Test pass rate: 1.0000, Total: 1, Passed: 1, Skipped: 0, Failed: 0, Time: 0.000352s
OK
kona      \ for help. \\ to exit.

  \\
$

[tavmem]

Bit of a surprise: Based on the above, seems there is a problem with the code used to fix issue 571 For reference, the code change to fix issue 571 was

$ git diff ~/k200108/src/vd.c ~/k200122/src/vd.c
diff --git a/Users/tavmem/k200108/src/vd.c b/Users/tavmem/k200122/src/vd.c
index b35a4db..e13d4f1 100644
--- a/Users/tavmem/k200108/src/vd.c
+++ b/Users/tavmem/k200122/src/vd.c
@@ -118,6 +118,10 @@ K dot(K a, K b) //NB: b can be a cheating 0-type with NULLs .. ?
   //TODO: create dename without path-creation effect. will lookup correct handle or return a _n to use ... but won't create path. K at() also needs this.
   //if(4==a->t)a=retrieveByHandle(a);

+  if(4==a->t && 4==b->t)
+  { S s=(char*)malloc(2+strlen(*kS(a))+strlen(*kS(b)));
+    s=strcpy(s,*kS(a)); strcat(s,"."); strcat(s,*kS(b));
+    R *inKtree(&kK((kK(KTREE))[0])[1],s,0); }
   if(7==a->t) R vf_ex(&a,b); //Verb: "Apply" //TODO: my guess is this fails everywhere vf_ex does (derived verbs?) (|+) . (0;1) ???
   R of(a,b); //TODO: vf_ex might/could implement this itself ?
 }
$ 

To test the content of the K-structure returned by this code, we make these changes:

$ git diff src/vd.c
diff --git a/src/vd.c b/src/vd.c
index f7f7ed9..929d4e4 100644
--- a/src/vd.c
+++ b/src/vd.c
@@ -9,6 +9,8 @@

 /* dot monadic, dyadic, triadic, tetradic */

+extern K sd_(K x,I f);
+
 Z K dot_ref(K *p,K *x,K *z,I s,K c,K y);
 Z K makeable(K a);

@@ -121,7 +123,7 @@ K dot(K a, K b) //NB: b can be a cheating 0-type with NULLs .. ?
   if(4==a->t && 4==b->t)
   { S s=(S)malloc(2+strlen(*kS(a))+strlen(*kS(b)));
     s=strcpy(s,*kS(a)); strcat(s,"."); strcat(s,*kS(b));
-    R *inKtree(&kK((kK(KTREE))[0])[1],s,0); }
+    K z=*inKtree(&kK((kK(KTREE))[0])[1],s,0); O("sd_(z,2):");sd_(z,2); R z; }
   if(7==a->t) R vf_ex(&a,b); //Verb: "Apply" //TODO: my guess is this fails everywhere vf_ex does (derived verbs?) (|+) . (0;1) ???
   R of(a,b); //TODO: vf_ex might/could implement this itself ?
 }
$ 

Then running the single test for issue 571 while documenting all instances of cd(K x) where 0==x->t && 0==x->n, we get

$ ./k_test
t:0
s: 1
s: d:.((`a;0);(`b;1)); `d .`b
BEG cd        0x1077a8480 0x1077a8498            1-6 0 0   
()
sd_(z,2):     0x1077ab280 0x1077ab298            1-6 1 1   1
BEG cd        0x1077ab280 0x1077ab298            17267332-64 0 0   
()
Test pass rate: 1.0000, Total: 1, Passed: 1, Skipped: 0, Failed: 0, Time: 0.000368s
OK
kona      \ for help. \\ to exit.

  \\
$

This says that the K-structure returned by this code seems valid: It has 1==x->t && 1==x->n and has a value of 1 (as expected). However, later on, this same address contains a bogus K-structure which is cd'd.

How & when did the K-structure become bogus?