Some sort of GC livelock issue...

[mikanystrom-intel]

Hello everyone, does this ring a bell for anybody?

I am running many instances (100K+) of a relatively complicated and computationally intensive program. A few instances fail, and it looks like concurrency bugs, which may be in my own code and not in CM3. It is also a complicated system in the sense that it links with third-party C++ software through pipes ... the C++ is linked with C to make a simple front-end, the M3 talks to the C++/C code via two-way pipes (send commands, retrieve results).

I attached to one of the instances stuck at 100% CPU and see the following in what seems to be the active thread:

#0 ThreadPThread__SignalThread (M3_DMxDjQ_act=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/thread/PTHREAD/ThreadPThread.m3:1078
#1 0x00000000004dbb57 in ThreadPThread__StartWorld () at ../src/thread/PTHREAD/ThreadPThread.m3:1234
#2 0x00000000004daa43 in RTThread__ResumeOthers () at ../src/thread/PTHREAD/ThreadPThread.m3:893
#3 0x00000000004c0f96 in RTCollector__CollectSomeInStateZero () at ../src/runtime/common/RTCollector.m3:911
#4 0x00000000004c060f in RTCollector__CollectSome () at ../src/runtime/common/RTCollector.m3:731
#5 0x00000000004c028a in RTHeapRep__CollectEnough () at ../src/runtime/common/RTCollector.m3:665
#6 0x00000000004bce2e in RTAllocator__AllocTraced (M3_Cwb5VA_dataSize=<error reading variable: inner value printing not implemented for language "Auto">, M3_Cwb5VA_dataAlignment=<error reading variable: inner value printing not implemented for language "Auto">, M3_A1A6Wn_thread=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTAllocator.m3:367
#7 0x00000000004bbf08 in RTAllocator__GetTracedObj (M3_Eic7CK_def=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTAllocator.m3:224
#8 0x00000000004bb8ab in RTHooks__AllocateTracedObj (M3_AJWxb1_defn=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTAllocator.m3:122
#9 0x0000000000497f8e in TextRd__New (M3_Bd56fi_t=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/rw/TextRd.m3:41
#10 0x00000000004a52e9 in Scan__ScanWord (M3_Bd56fi_txt=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/fmtlex/Scan.m3:41
#11 0x00000000004a5438 in Scan__Int (M3_Bd56fi_txt=<error reading variable: inner value printing not implemented for language "Auto">, M3_AwZxt9_defaultBase=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/fmtlex/Scan.m3:53
#12 0x000000000047b8d1 in TextReader__GetInt (M3_A0o49i_t=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/TextReader.m3:283
#13 0x000000000041b8f6 in Fsdb__Parse__GetTimesteps.1255 (M3_Cwb5VA_fsdbId=<error reading variable: inner value printing not implemented for language "Auto">, M3_DRfo9P_steps=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/Fsdb.m3:585
#14 0x000000000041a987 in Fsdb__Parse (M3_Bd56fi_wd=<error reading variable: inner value printing not implemented for language "Auto">, M3_Bd56fi_ofn=<error reading variable: inner value printing not implemented for language "Auto">, M3_DKdYgt_names=<error reading variable: inner value printing not implemented for language "Auto">, M3_Cwb5VA_maxFiles=<error reading variable: inner value printing not implemented for language "Auto">,
M3_B4NT1D_nFiles=<error reading variable: inner value printing not implemented for language "Auto">, M3_CtKayy_timeScaleFactor=<error reading variable: inner value printing not implemented for language "Auto">, M3_CtKayy_timeOffset=<error reading variable: inner value printing not implemented for language "Auto">, M3_CtKayy_voltageScaleFactor=<error reading variable: inner value printing not implemented for language "Auto">,
M3_CtKayy_voltageOffset=<error reading variable: inner value printing not implemented for language "Auto">, M3_Bd56fi_dutName=<error reading variable: inner value printing not implemented for language "Auto">, M3_Bd56fi_fsdbPath=<error reading variable: inner value printing not implemented for language "Auto">, M3_AicXUJ_wait=<error reading variable: inner value printing not implemented for language "Auto">,
M3_CT76zs_restrictNodes=<error reading variable: inner value printing not implemented for language "Auto">, M3_DbnU2S_restrictRegEx=<error reading variable: inner value printing not implemented for language "Auto">, M3_Cwb5VA_maxNodes=<error reading variable: inner value printing not implemented for language "Auto">, M3_AicXUJ_translate=<error reading variable: inner value printing not implemented for language "Auto">,
M3_AicXUJ_noX=<error reading variable: inner value printing not implemented for language "Auto">, M3_Bd56fi_scopesep=<error reading variable: inner value printing not implemented for language "Auto">, M3_Bd56fi_cmdPath=<error reading variable: inner value printing not implemented for language "Auto">, M3_Ehfbg0_compress=<error reading variable: inner value printing not implemented for language "Auto">,
M3_Cwb5VA_threads=<error reading variable: inner value printing not implemented for language "Auto">, M3_CtKayy_interpolate=<error reading variable: inner value printing not implemented for language "Auto">, M3_CtKayy_maxTime=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/Fsdb.m3:766
#15 0x0000000000409275 in ConvertTrace__DoConversion (M3_DfYBRk_conv=...) at ../src/ConvertTrace.m3:348
#16 0x000000000040e112 in ConvertTrace_M3 (M3_AcxOUs_mode=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/ConvertTrace.m3:762
#17 0x00000000004cb75a in RTLinker__RunMainBody (M3_DjPxE3_m=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTLinker.m3:408
#18 0x00000000004ca965 in RTLinker__AddUnitI (M3_DjPxE3_m=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTLinker.m3:115
#19 0x00000000004caa11 in RTLinker__AddUnit (M3_DjPxE5_b=<error reading variable: inner value printing not implemented for language "Auto">) at ../src/runtime/common/RTLinker.m3:124
#20 0x00000000004061f8 in main (argc=21, argv=0x7fffffffcbd8, envp=0x7fffffffcc88) at _m3main.c:31

Looking at what's happening, I see this:

(gdb) dir /p/cth/rtl/cad/x86-64_linux44/opensource/cm3/d5.11.0-20210425/pkg/m3core/src/
Source directories searched: /p/cth/rtl/cad/x86-64_linux44/opensource/cm3/d5.11.0-20210425/pkg/m3core/src:$cdir:$cwd
(gdb) list
1074 BEGIN
1075 <ASSERT SIG_SUSPEND # 0>
1076 LOOP
1077 WITH z = pthread_kill(act.handle, SIG_SUSPEND) DO
1078 IF z = 0 THEN EXIT END;
1079 IF z # Uerror.EAGAIN THEN DieI(ThisLine(), z) END;
1080 (* try it again... *)
1081 END;
1082 END;
1083 END SignalThread;
(gdb) next
1077 WITH z = pthread_kill(act.handle, SIG_SUSPEND) DO
(gdb)
1078 IF z = 0 THEN EXIT END;
(gdb)
1079 IF z # Uerror.EAGAIN THEN DieI(ThisLine(), z) END;
(gdb)
1077 WITH z = pthread_kill(act.handle, SIG_SUSPEND) DO
(gdb)
1078 IF z = 0 THEN EXIT END;
(gdb)
1079 IF z # Uerror.EAGAIN THEN DieI(ThisLine(), z) END;
(gdb)
1077 WITH z = pthread_kill(act.handle, SIG_SUSPEND) DO
(gdb)
1078 IF z = 0 THEN EXIT END;
(gdb)
1079 IF z # Uerror.EAGAIN THEN DieI(ThisLine(), z) END;
(gdb)
1077 WITH z = pthread_kill(act.handle, SIG_SUSPEND) DO
(gdb)
1078 IF z = 0 THEN EXIT END;

That is pthread_kill keeps getting EAGAIN repeatedly from ... attempting to start the other thread?

Here is the calling code:

(gdb) list
1229 newlySent := 0;
1230 act := me.next;
1231 WHILE act # me DO
1232 <ASSERT act.state # ActState.Stopping>
1233 IF act.state # ActState.Started THEN
1234 SignalThread(act); <======= HERE
1235 INC(newlySent);
1236 END;
1237 act := act.next;
1238 END;
(gdb)

and the caller of that

888 PROCEDURE ResumeOthers () =
889 (* LL=activeMu. Always preceded by SuspendOthers. *)
890 BEGIN
891 <ASSERT suspended>
892 suspended := FALSE;
893 StartWorld(); <============ HERE
894 WITH r = pthread_mutex_unlock(activeMu) DO <ASSERT r=0> END;
895 END ResumeOthers;

Any thoughts, hints?

[VictorMiasnikov]

}
}/cm3/d5.11.0-20210425/
}

Please public output of
cm3 --version

Thank You!

P.S. and please see my e-mail message ( content inside is other)

[mikanystrom-intel]

sccc05123707> cm3 --version
Critical Mass Modula-3 version d5.11.0
GitInfo: 7b6738b
https://github.com/modula3/cm3/commits/master
remote: https://github.com/modula3/cm3
revision: 7b6738b
branch: master
last updated: 2021-02-24
compiled: 2021-04-29 01:38:45
configuration: /p/cth/rtl/cad/x86-64_linux44/opensource/cm3/d5.11.0-20210425//bin/cm3.cfg
host: AMD64_LINUX
target: AMD64_LINUX

[VictorMiasnikov]

As small remark

Of course, this version affected too

https://github.com/VictorMiasnikov/cm3/releases/tag/d5.11.9-ZZYYXX-20241118_21-50

= =
Critical Mass Modula-3 version d5.11.9
GitInfo: /commit/08d84d1b6d6e82bee52a4aea2684ceb87ee216d9
/commits/heads/d5.11.9-ZZYYXX-20241118_21-50
remote:
revision: 08d84d1
branch: heads/d5.11.9-ZZYYXX-20241118_21-50
last updated: 2022-02-05
compiled: 2025-01-17 20:00:03
configuration: /usr/local/cm3/bin/cm3.cfg
host: AMD64_LINUX
target: AMD64_LINUX
= =

[VictorMiasnikov]

VVM}}} P.S. and please see my e-mail message ( content inside is other)

I have analog of Issue 1200 on other OS.
I use emulator AMD SimNow ( this is way for reproduce problem on relative common hardware).

Main idea for solving is:

ZG8gbm90IERpYWwoVGhpcyBMaW5lIHNtYikgYnV0Og0KUnVuICggIGkuZS4gc2xlZXAgc3RhdGUg
LS0tfSB3b3JrIHN0YXRlKSBzdGFydCBhbGwgKG90aGVycykgdGhyZWFkcw0KDQpCdXQgaW5jcmVh
c2Ugc3BlY2lhbCB2YXJpYWJsZSBDb3VudGVyc09mRmFpbEF0dGVtcE9mU3RhcnRHQw0KDQpJZiBD
b3VudGVyVHJMYUxhID4gOTk5OTk5OTk5IHRoZW4NCiAgIERpZWwoIGFsbCkNCkVuZA0KDQpPZiBj
b3Vyc2UsIGRvbid0IHJ1biBuZXh0IEdDIHthbGdvcml0bSBzdGVwc30gdGhlbiBDb3VudGVyIGRv
bid0IGVxdWFsIHplcm8NCg0KSW4gY2FzZSBzdWNjZXNzZnVsbHkgc3RvcCB3b3JsZCB0aGVuIHNl
dCBDb3VudGVyVHJMYUxhIHRvIHplcm8gDQo=

( To M.N.: please write to me -- I resend "pure text" or describe how unpack "good old" UUE )
( To All: this draft. I will try prepare patch)

Best regards, Victor Miasnikov
E-mail: vvm(at)tut.by
Telegram: @ V i c t o r M i a s n i k o v
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ of cource, without spaces

P.S. Last 3 .. 4 lines will be removed later

[demoitem]

Hi Mika,
I did a small test of a threaded program on amd64 and my version of StartWorld looks slightly different to yours.
If you check on github there is a check for SIG_SUSPEND on line 1242 the same as my test and whose value is zero
and thus the resumption is done via StartThread on the next line rather than SignalThread further on. I have no idea if this
has any bearing on your problem. I have always had a suspicion of mixing threads and signals but they seem to work
in M3. That's one area you could look. Have you tried running with nogc to get rid of collector influences that could
shed some light. Also with 100K thread instances (if I read you correctly) you could be running into some
resource limit.
Anyway just my 2c.

Peter

[demoitem]

Actually, spoke too soon. My test is entering SignalThread. (Could have sworn it went via StartThread)
Anyway SignalThread seems fine. So back to square one.

Sorry.

[VictorMiasnikov]

Can You run test on slow hardware or pseudo-hardware? I mean simulator AMD SimNow

…

 ---------------- Кому: modula3/cm3 ***@***.***); Копия: Manual ***@***.***); Тема: [modula3/cm3] Some sort of GC livelock issue... (Issue #1200); 23.01.2025, 15:32, "peter mckinna" ***@***.***>: Actually, spoke too soon. My test is entering SignalThread. (Could have sworn it went via StartThread) Anyway SignalThread seems fine. So back to square one. Sorry.

[dragisha]

Mixing signals is how we implement final step of GC. Long time since I implemented mine but I think there is no other way on POSIX to do it, and also manual pages say some of that stuff is not reentrant or something like. So it may be it is hitting some edge case now.

…

On 23. 1. 2025., at 13:25, peter mckinna ***@***.***> wrote: Hi Mika, I did a small test of a threaded program on amd64 and my version of StartWorld looks slightly different to yours. If you check on github there is a check for SIG_SUSPEND on line 1242 the same as my test and whose value is zero and thus the resumption is done via StartThread on the next line rather than SignalThread further on. I have no idea if this has any bearing on your problem. I have always had a suspicion of mixing threads and signals but they seem to work in M3. That's one area you could look. Have you tried running with nogc to get rid of collector influences that could shed some light. Also with 100K thread instances (if I read you correctly) you could be running into some resource limit. Anyway just my 2c. Peter — Reply to this email directly, view it on GitHub <#1200 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA5ZBWB44UH5VOML6RYDS732MDNVDAVCNFSM6AAAAABVRCU5USVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDMMBZGY3TSOBZGM>. You are receiving this because you are subscribed to this thread.

[demoitem]

Had another dig, and I think you may be overflowing the real time signal queue. On my machine I can get EAGAIN
after 30884 pthread_kill calls. Not many. There should be some way to increase that number. Or there may be something inherently wrong with gc with so many threads doing collections.

[VictorMiasnikov]

(
} Or there may be something inherently wrong with gc with so many threads doing collections.

I.e. "UUE encoded idea" can not sence ?
)

} may be overflowing the real time signal queue.
} There should be some way to increase that number.

Is it on OS level ?

[jaykrell]

There is the idea of cooperative suspend. Not using signals. At least not for when running Modula-3.
Java does this. By polling. By reading a byte, on a page, that is made inaccessible to request suspend.

[VictorMiasnikov]

There is the idea of cooperative suspend. Not using signals. At least not for when running Modula-3. Java does this. By polling. By reading a byte, on a page, that is made inaccessible to request suspend.

"This Issue", looks like, is problem of OS kernel limits
( As I understend )