[Sbcl-help] (no subject)

[73budden . <bud...@gm...>]

Hi!

I initially posted to sbcl-devel, but now I see sbcl-help is more
adequate place for this question.

I use SBCL 1.3.0 on Windows 7 32 bit, disabled DEP and antivirus
(which conflicts to SBCL and some other programs too). I copied SBCL
executables to another location and start it from cmd file.

There are :swank, :clcon-server, :hunchentoot, :postmodern in my lisp
image, and tried some load test. My hunchentoot web page handler
connects to postgres, retrieves simple query, prints that data and
output of (room) to the page, closes database connection and returns.
Most of the output, excluding *trace-output* is processed by SWANK and
passed to clcon tcl/tk frontend via sockets (no essential difference
to EMACS). *trace-output* is printed just to SBCL's black console.

Also I run (sb-ext:gc :full t) every 3 seconds to avoid memory
overflow (in a dedicated thread).

*evaluation-mode* is :interpret. I tuned Hunchentoot to catch errors
in worker threads (setting *catch-errors-p* to true).

I arranged things so that I send ~30 simultaneous queries to the
server. In a time, SBCL printed several times a backtrace of error in
hunchentoot worker thread like this:

[2015-11-19 15:51:42 [ERROR]] Unrecognized widetag #x72 in reconstitute-object
Backtrace for: #<SB-THREAD:THREAD "hunchentoot-worker-127.0.0.1:27155"
RUNNING {2617ACE1}>
7: ((FLET #:H0 :IN HUNCHENTOOT:HANDLE-REQUEST) #<SIMPLE-ERROR
"Unrecognized widetag #x~2,'0X in reconstitute-object" {280CE1F1}>)
8: (SIGNAL #<SIMPLE-ERROR "Unrecognized widetag #x~2,'0X in
reconstitute-object" {280CE1F1}>)
9: (ERROR "Unrecognized widetag #x~2,'0X in reconstitute-object" 114)
10: (SB-VM::RECONSTITUTE-OBJECT 167483394)
11: (SB-VM::MAP-OBJECTS-IN-RANGE #<CLOSURE (LAMBDA (SB-VM::OBJ TYPE
SB-VM::SIZE) :IN SB-VM::TYPE-BREAKDOWN) {27C82E95}> 167483394
167484386)
12: ((FLET #:WITHOUT-GCING-BODY-380 :IN SB-VM::MAP-ALLOCATED-OBJECTS))
13: (SB-VM::MAP-ALLOCATED-OBJECTS #<CLOSURE (LAMBDA (SB-VM::OBJ TYPE
SB-VM::SIZE) :IN SB-VM::TYPE-BREAKDOWN) {27C82E95}> :DYNAMIC)
14: (SB-VM::TYPE-BREAKDOWN :DYNAMIC)
15: (SB-VM:MEMORY-USAGE :PRINT-SPACES T :COUNT-SPACES (:DYNAMIC)
:PRINT-SUMMARY NIL :CUTOFF 0.05)
16: (ROOM :DEFAULT)

After that, SBCL stopped responding in a few minutes. Several 10000's
of queries were served by hunchentoot totally. After that, I took
stack traces of some SBCL threads with sysinternals Process Explorer:

Thread 1476:
ntdll.dll!KiFastSystemCallRet
kernel32.dll!WaitForSingleObjectEx+0x43
kernel32.dll!WaitForSingleObject+0x12
sbcl.exe!pthread_cond_wait+0x124
sbcl.exe!thread_in_safety_transition+0x308
sbcl.exe!handle_exception+0x66e
sbcl.exe!exception_handler_wrapper+0x28
ntdll.dll!RtlRaiseStatus+0xb4
sbcl.exe!gc_alloc_large+0x8b2
ntdll.dll!LdrGetDllHandleEx+0x272
KERNELBASE.dll!GetModuleHandleW+0x51
ntdll.dll!ZwSetEvent+0xc
KERNELBASE.dll!SetEvent+0x10
sbcl.exe!futex_wake+0xcf

Thread 6156:
ntdll.dll!KiFastSystemCallRet
kernel32.dll!WaitForSingleObjectEx+0x43
kernel32.dll!WaitForSingleObject+0x12
sbcl.exe!pthread_cond_wait+0x124
sbcl.exe!thread_in_lisp_raised+0x1d5
sbcl.exe!handle_exception+0x680
sbcl.exe!exception_handler_wrapper+0x28
ntdll.dll!RtlRaiseStatus+0xb4
LIBEAY32.dll!SRP_create_verifier+0xb0b0
ntdll.dll!EtwSetMark+0x1faa
ntdll.dll!EtwpNotificationThread+0xaa
ntdll.dll!RtlInitializeExceptionChain+0x1e0
ntdll.dll!ZwTestAlert+0xc
ntdll.dll!RtlAllocateActivationContextStack+0x12a
ntdll.dll!NtContinue+0xc
ntdll.dll!LdrInitializeThunk+0x1a

22576:
ntdll.dll!KiFastSystemCallRet
kernel32.dll!WaitForSingleObjectEx+0x43
kernel32.dll!WaitForSingleObject+0x12
sbcl.exe!pthread_cond_wait+0x124
sbcl.exe!gc_stop_the_world+0x284
sbcl.exe!call_into_c+0x24
sbcl.exe!call_into_lisp+0x90
sbcl.exe!funcall0+0x47
sbcl.exe!check_pending_gc+0x21d
sbcl.exe!thread_interrupted+0xc1
sbcl.exe!handle_exception+0x626
sbcl.exe!exception_handler_wrapper+0x28
ntdll.dll!RtlRaiseStatus+0xb4
sbcl.exe!alloc_overflow_ecx+0x12

(room) retrieved with web page not long before lockout was
Dynamic space usage is:   84,127,600 bytes.
Read-only space usage is:      3,240 bytes.
Static space usage is:         3,200 bytes.
Control stack usage is:        3,896 bytes.
Binding stack usage is:          496 bytes.
Control and binding stack usage is for the current thread only.
Garbage collection is currently enabled.

Breakdown for dynamic space:
  20,211,888 bytes for    29,713 code objects.
  12,315,832 bytes for   223,106 simple-vector objects.
  11,572,744 bytes for 1,446,593 cons objects.
  11,346,936 bytes for   127,959 simple-character-string objects.
   7,829,496 bytes for   197,094 instance objects.
   6,187,136 bytes for    44,893 simple-array-unsigned-byte-8 objects.
   4,869,520 bytes for    60,787 simple-array-unsigned-byte-32 objects.
  11,198,800 bytes for   685,913 other objects.
  85,532,352 bytes for 2,816,058 dynamic objects (space total.)


What should I do next, what to read, what to study, how to debug, how
to diagnose?

Thanks!