Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pretty-print-hash-table is not thread safe #31

Open
bo-tato opened this issue May 10, 2023 · 2 comments
Open

pretty-print-hash-table is not thread safe #31

bo-tato opened this issue May 10, 2023 · 2 comments

Comments

@bo-tato
Copy link

bo-tato commented May 10, 2023

I was printing hash tables to debug a very concurrent program, and it would crash with:

The value
  -1
is not of type
  UNSIGNED-BYTE
when binding SB-PRETTY::COLNUM
   [Condition of type TYPE-ERROR]

Restarts:
 0: [ABORT] abort thread (#<THREAD "Anonymous thread" RUNNING {1004CD4883}>)

Backtrace:
 0: (PPRINT-TAB :LINE -1 1 #<SB-PRETTY:PRETTY-STREAM {10051B11A3}>) [external]
 1: ("fmt$~vt) " #<SB-PRETTY:PRETTY-STREAM {10051B11A3}> -1)
 2: (FORMAT #<SB-PRETTY:PRETTY-STREAM {10051B11A3}> #<FUNCTION "fmt$~vt) " {52E6EBDB}> -1)
 3: (FORMAT #<SB-PRETTY:PRETTY-STREAM {10051B11A3}> #<FUNCTION "fmt$~vt) " {52E6EBDB}> -1) [more]
 4: ((FLET "WITH-PRETTY-STREAM0" :IN SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER) #<SB-PRETTY:PRETTY-STREAM {10051B11A3}>)
 5: (SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER #<FUNCTION (FLET "PPRINT-BLOCK" :IN PRETTY-PRINT-HASH-TABLE) {7F098F0BE7EB}> #<SYNONYM-STREAM :SYMBOL SLYNK::*CURRENT-STANDARD-OUTPUT* {1004047373}> NIL NIL "" N..
 6: (PRETTY-PRINT-HASH-TABLE #<HASH-TABLE :TEST EQUAL :COUNT 2 {10051B0793}> #<SYNONYM-STREAM :SYMBOL SLYNK::*CURRENT-STANDARD-OUTPUT* {1004047373}>)
...

it seems all threads share the same *current-pprint-indentation*, and incf and decf is not atomic, so sometimes when two threads both incf at same time it will only increment once, or when two threads decf at same time it will only decrement once, for minimal example run:

(bt:make-thread
 (lambda ()
   (loop repeat 5000 do
     (pretty-print-hash-table
      (dict "one" "b"
            "c" (dict 4 5))))))
(bt:make-thread
 (lambda ()
   (loop repeat 5000 do
     (pretty-print-hash-table
      (dict "two" "b"
            "c" (dict 4 5))))))

randomly *current-pprint-indentation* will get incremented or decremented too much, you will either get that error as it reaches -1, or after finishing both threads it's value will be 5 or something rather than 1 as it should be.

I added *current-pprint-indentation* to the let binding at the start of pretty-print-hash-table in ciel.lisp:

(let ((*print-pretty* t)
        (*current-pprint-indentation* 1)
        (i 0))
...

so then each thread modifies it's own thread-local *current-pprint-indentation*. I don't know whether this is really a real issue as I should put some locking around debugging prints in multithreaded program anyway so the output doesn't get intermixed, but at least this way when I'm too lazy to add locking it's just some interleaved output rather than crashing

@vindarel
Copy link
Contributor

Thanks for the nice report.

I originally ported this function from Rutils to Serapeum.

https://github.com/ruricolist/serapeum/blob/master/REFERENCE.md#pretty-print-hash-table-ht-optional-stream

https://github.com/ruricolist/serapeum/blob/master/hash-tables.lisp#L568

rutils: https://github.com/vseloved/rutils/blob/master/core/hash-table.lisp#L120

So, I suggest you open an issue on Serapeum first and we see what happens?

Your solution is simple and non-intrusive so it looks like an acceptable patch.

@bo-tato
Copy link
Author

bo-tato commented May 11, 2023

interesting, it seems the issue isn't present though in the serapeum and rutils version, they are using pprint-indent to manage the nested indentation which works multithreaded where it seems in ciel that got replaced with *current-pprint-indentation* with the comment:

We use custom indentation instead of the pretty printer, because it doesn't print correctly in the shell (indentations are way too large).

I'm just using ciel in emacs repl where they both look the same with exception that the ciel version prints fresh-line at the end, but it's true in the ciel standalone shell the serapeum version has way too large indentation, I'm not sure what is difference between shell and repl that would cause it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants