Strange threads/stack size interaction on FreeBSD

[Stefan Schwarzer]

Hi Neal

Unless noted otherwise, the descriptions below refer to the problematic stack size
of 512 MB.

Neal Norwitz wrote:
>>- Should I enter a bug report on this topic?
> 
> Probably, although, there are few people who can test with your
> configuration.  So you may be stuck debugging this yourself.
 >
 > If you have stack traces, are they very long?  where does the crash
 > occur?

It's rather a block than a crash. I was able to reproduce the problem with this
small test script:

-----
import threading

def hello():
     print "Hello"

t = threading.Thread(target=hello)
t.start()
t.join()
-----

The program blocks in t.join(). A backtrace from pdb.py just before blocking is

-----
(Pdb) bt
   <string>(1)?()
   /srv/home/svss/thread_test.py(8)?()
-> t.join()
   /usr/local/lib/python2.2/threading.py(450)join()
-> self.__block.wait()
 > /usr/local/lib/python2.2/threading.py(190)wait()
-> waiter.acquire()
(Pdb) s
-----

So, to be more precise, the program stops on calling waiter.acquire() in
_Condition.wait(). Apart from that, I could stop the python process only with
the kill command from another terminal, but not with Ctrl-C in the xterm where
Python was running.

I also got kernel trace output on FreeBSD and noted that I see the program
blocking here, too. That is, the dump doesn't grow larger when I let hang the
program around longer.

The last entries before the program hangs are:

-----
  21517 python   CALL  mmap(0xbfaef000,0x10000,0x3,0x400,0xffffffff,0,0,0)
  21517 python   RET   mmap -1 errno 12 Cannot allocate memory
  21517 python   CALL  __sysctl(0xbfbff160,0x2,0x8810c440,0xbfbff15c,0,0)
  21517 python   RET   __sysctl 0
  21517 python   CALL  poll(0x8175000,0,0)
  21517 python   RET   poll 0
  21517 python   CALL  poll(0x8104000,0,0)
  21517 python   RET   poll 0
  21517 python   CALL  poll(0x8104000,0,0)
  21517 python   RET   poll 0
  21517 python   CALL  gettimeofday(0x881a97ec,0)
  21517 python   RET   gettimeofday 0
  21517 python   CALL  poll(0x8104000,0x1,0xffffffff)
-----

which is shortly after reading atexit.pyc.

> What compiler are you using?

gcc 2.95.3

> Can you report all the tests that don't pass?

Output from make test:

...
test test_asynchat crashed -- socket.error: 61
...
test test_fork1 failed -- test failed
...
test test_pwd produced unexpected output:
**********************************************************************
*** mismatch between line 7 of expected output and line 7 of actual output:
- caught expected exception
+ fakeuid 4127 did not except pwd.getpwuid()
**********************************************************************
...
test test_socket failed -- (48, 'Address already in use')
...
161 tests OK.
4 tests failed:
     test_asynchat test_fork1 test_pwd test_socket
...

However, in order to let the tests succeed, I disabled all tests beginning with
"test_thread". Suprisingly, after make test was through, it didn't return to the
prompt but I could stop it with Ctrl-C.

> Have you tried with the latest and greatest source?
>   2.2.1+: cvs update -r release22-maint

I got "cvs [update aborted]: no such tag release22-maint".

>   2.3:    cvs update -A

I get all the same symptoms as described above; I didn't look for the kernel
trace dump, but the test script still hangs.

After just reactivating the old kernel with a stack size of 256 MB I get the
expected output "Hello" and the script returns to the prompt. The last entries
in the kernel trace dump are (from the same position onwards as above):

-----
    217 python   CALL  mmap(0xbfaef000,0x10000,0x3,0x400,0xffffffff,0,0,0)
    217 python   RET   mmap -1079054336/0xbfaef000
    217 python   CALL  setitimer(0x2,0xbfbff554,0)
    217 python   RET   setitimer 0
    217 python   CALL  mmap(0xbfade000,0x10000,0x3,0x400,0xffffffff,0,0,0)
    217 python   RET   mmap -1079123968/0xbfade000
    217 python   CALL  __sysctl(0xbfbff524,0x2,0x4810c440,0xbfbff520,0,0)
    217 python   RET   __sysctl 0
    217 python   CALL  poll(0x8193800,0,0)
    217 python   RET   poll 0
    217 python   CALL  fstat(0x1,0xbfafe80c)
    217 python   RET   fstat 0
    217 python   CALL  ioctl(0x1,TIOCGETA,0xbfafe840)
    217 python   RET   ioctl 0
    217 python   CALL  write(0x1,0x8199000,0x6)
    217 python   GIO   fd 1 wrote 6 bytes
        "Hello
        "
    217 python   RET   write 6
    217 python   CALL  clock_gettime(0,0xbfaedfa4)
    217 python   RET   clock_gettime 0
    217 python   CALL  poll(0x8104000,0,0)
    217 python   RET   poll 0
    217 python   CALL  poll(0x8104000,0,0)
    217 python   RET   poll 0
    217 python   CALL  gettimeofday(0x481a97ec,0)
    217 python   RET   gettimeofday 0
    217 python   CALL  sigaction(0x2,0xbfbff8fc,0)
    217 python   RET   sigaction 0
    217 python   CALL  sigprocmask(0x1,0x480dee60,0xbfbff9e0)
    217 python   RET   sigprocmask 0
    217 python   CALL  sigprocmask(0x3,0x480dee70,0)
    217 python   RET   sigprocmask 0
    217 python   CALL  setitimer(0x2,0xbfbffa00,0)
    217 python   RET   setitimer 0
    217 python   CALL  close(0x3)
    217 python   RET   close 0
    217 python   CALL  close(0x4)
    217 python   RET   close 0
    217 python   CALL  fcntl(0,0x3,0)
    217 python   RET   fcntl 6
    217 python   CALL  fcntl(0,0x4,0x2)
    217 python   RET   fcntl 0
    217 python   CALL  fcntl(0x1,0x3,0)
    217 python   RET   fcntl 2
    217 python   CALL  fcntl(0x1,0x4,0x2)
    217 python   RET   fcntl 0
    217 python   CALL  fcntl(0x2,0x3,0)
    217 python   RET   fcntl 2
    217 python   CALL  fcntl(0x2,0x4,0x2)
    217 python   RET   fcntl 0
    217 python   CALL  exit(0)
-----

Probably, the best is to discuss this on one of the FreeBSD mailing lists.
Anyway, thank you very much for your help. :-)

Stefan