Author Connor.Wolf
Recipients Connor.Wolf, Giovanni.Bajo, bobbyi, dan.oreilly, emptysquare, forest_atq, gregory.p.smith, ionelmc, jcea, lesha, neologix, nirai, nirs, pitrou, sbt, sdaoden, tshepang, vinay.sajip, vstinner
Date 2016-07-09.04:44:43
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1468039484.83.0.243817345714.issue6721@psf.upfronthosting.co.za>
In-reply-to
Content
> Python 3.5.1+ (default, Mar 30 2016, 22:46:26)

Whatever the stock 3.5 on ubuntu 16.04 x64 is.

I've actually been running into a whole horde of really bizarre issues related to what I /think/ is locking in stdout. 

Basically, I have a context where I have thousands and thousands of (relatively short lived) `multiprocessing.Process()` processes, and over time they all get wedged (basically, I have ~4-32 processes alive at any time, but they all get recycled every few minutes).

After doing some horrible (https://github.com/fake-name/ReadableWebProxy/blob/master/logSetup.py#L21-L78) hackery in the logging module, I'm not seeing processes get wedged there, but I do still encounter issues with what I can only assume is a lock in the print statement. I'm hooking into a wedged process using [pystuck](https://github.com/alonho/pystuck)

durr@rwpscrape:/media/Storage/Scripts/ReadableWebProxy⟫ pystuck --port 6675
Welcome to the pystuck interactive shell.
Use the 'modules' dictionary to access remote modules (like 'os', or '__main__')
Use the `%show threads` magic to display all thread stack traces.

In [1]: show threads
<_MainThread(MainThread, started 140574012434176)>
  File "runScrape.py", line 74, in <module>
    go()
  File "runScrape.py", line 57, in go
    runner.run()
  File "/media/Storage/Scripts/ReadableWebProxy/WebMirror/Runner.py", line 453, in run
    living = sum([manager.check_run_jobs() for manager in managers])
  File "/media/Storage/Scripts/ReadableWebProxy/WebMirror/Runner.py", line 453, in <listcomp>
    living = sum([manager.check_run_jobs() for manager in managers])
  File "/media/Storage/Scripts/ReadableWebProxy/WebMirror/Runner.py", line 364, in check_run_jobs
    proc.start()
  File "/usr/lib/python3.5/multiprocessing/process.py", line 105, in start
    self._popen = self._Popen(self)
  File "/usr/lib/python3.5/multiprocessing/context.py", line 212, in _Popen
    return _default_context.get_context().Process._Popen(process_obj)
  File "/usr/lib/python3.5/multiprocessing/context.py", line 267, in _Popen
    return Popen(process_obj)
  File "/usr/lib/python3.5/multiprocessing/popen_fork.py", line 20, in __init__
    self._launch(process_obj)
  File "/usr/lib/python3.5/multiprocessing/popen_fork.py", line 74, in _launch
    code = process_obj._bootstrap()
  File "/usr/lib/python3.5/multiprocessing/process.py", line 249, in _bootstrap
    self.run()
  File "/usr/lib/python3.5/multiprocessing/process.py", line 93, in run
    self._target(*self._args, **self._kwargs)
  File "/media/Storage/Scripts/ReadableWebProxy/WebMirror/Runner.py", line 145, in run
    run.go()
  File "/media/Storage/Scripts/ReadableWebProxy/WebMirror/Runner.py", line 101, in go
    self.log.info("RunInstance starting!")
  File "/usr/lib/python3.5/logging/__init__.py", line 1279, in info
    self._log(INFO, msg, args, **kwargs)
  File "/usr/lib/python3.5/logging/__init__.py", line 1415, in _log
    self.handle(record)
  File "/usr/lib/python3.5/logging/__init__.py", line 1425, in handle
    self.callHandlers(record)
  File "/usr/lib/python3.5/logging/__init__.py", line 1487, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.5/logging/__init__.py", line 855, in handle
    self.emit(record)
  File "/media/Storage/Scripts/ReadableWebProxy/logSetup.py", line 134, in emit
    print(outstr)

<Thread(Thread-4, started daemon 140573656733440)>
  File "/usr/lib/python3.5/threading.py", line 882, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.5/threading.py", line 862, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.5/dist-packages/rpyc/utils/server.py", line 241, in start
    self.accept()
  File "/usr/local/lib/python3.5/dist-packages/rpyc/utils/server.py", line 128, in accept
    sock, addrinfo = self.listener.accept()
  File "/usr/lib/python3.5/socket.py", line 195, in accept
    fd, addr = self._accept()

<Thread(Thread-5, started daemon 140573665126144)>
  File "/usr/local/lib/python3.5/dist-packages/pystuck/thread_probe.py", line 15, in thread_frame_generator
    yield (thread_, frame)


So, somehow the print() statement is blocking, which I have /no/ idea how to go about debugging. I assume there's a lock /in/ the print statement function call, and I'm probably going to look into wrapping both the print() call and the multiprocessing.Process() call  execution in a single, shared multiprocessing lock, but that
seems like a very patchwork solution to something that should just work.
History
Date User Action Args
2016-07-09 04:44:45Connor.Wolfsetrecipients: + Connor.Wolf, gregory.p.smith, vinay.sajip, jcea, nirs, pitrou, vstinner, nirai, forest_atq, ionelmc, bobbyi, neologix, Giovanni.Bajo, sdaoden, tshepang, sbt, lesha, emptysquare, dan.oreilly
2016-07-09 04:44:44Connor.Wolfsetmessageid: <1468039484.83.0.243817345714.issue6721@psf.upfronthosting.co.za>
2016-07-09 04:44:44Connor.Wolflinkissue6721 messages
2016-07-09 04:44:43Connor.Wolfcreate