Error loading fonts on OSX 10.11

[matthew-brett]

A colleague ran into the following error after installing a fresh copy of Matplotlib on OSX 10.11:

$ python -c 'import matplotlib.pyplot'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/pyplot.py", line 29, in <module>
    import matplotlib.colorbar
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/colorbar.py", line 34, in <module>
    import matplotlib.collections as collections
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/collections.py", line 27, in <module>
    import matplotlib.backend_bases as backend_bases
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/backend_bases.py", line 62, in <module>
    import matplotlib.textpath as textpath
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/textpath.py", line 15, in <module>
    import matplotlib.font_manager as font_manager
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/font_manager.py", line 1420, in <module>
    _rebuild()
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/font_manager.py", line 1405, in _rebuild
    fontManager = FontManager()
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/font_manager.py", line 1043, in __init__
    self.ttffiles = findSystemFonts(paths) + findSystemFonts()
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/font_manager.py", line 323, in findSystemFonts
    for f in get_fontconfig_fonts(fontext):
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/site-packages/matplotlib/font_manager.py", line 275, in get_fontconfig_fonts
    stderr=subprocess.PIPE)
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 710, in __init__
    errread, errwrite)
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 1334, in _execute_child
    child_exception = pickle.loads(data)
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 1382, in loads
    return Unpickler(file).load()
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 858, in load
    dispatch[key](self)
  File "/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 966, in load_string
    raise ValueError, "insecure string pickle"
ValueError: insecure string pickle

Not surprisingly, the problem turns out to be in get_fontconfig_fonts where the command subprocess.Popen(['fc-list', '--format=%{file}\\n'], ...) returns a ValueError instead of the expected OSError, IOError and so the routine tries to load a pickle from the error message text and fails. fc-list does not exist on my colleague's system.

[mdboom]

Probably the same as #5314.

I think your assessment isn't quite right though. subprocess.Popen(['fc-list', '--format=%{file}\\n'], ...) isn't raising a ValueError that is causing matplotlib to try to load a pickle. subprocess itself is trying to load a pickle containing an exception from a child process, and that pickle is broken, probably due to the pipe not getting properly flushed.

There's something fishy here, but I don't think matplotlib catching a ValueError is the right thing to do. According to the docs, that should only be raised when invalid arguments are passed to Popen, which they aren't here.

I found other reports of similar bugs: this seems to be the new symptom for "file not found" on OSX 10.11, which is definitely broken behavior:

ytdl-org/youtube-dl#6840
healpy/healpy#284

Also, for fun:

https://i.imgur.com/To3DQ6J.jpg

Does:

import subprocess
p = subprocess.Popen(['foo'], stdout=subprocess.PIPE, stderr=subprocess.PIPE)
p.communicate()

also give the same error? If so, definitely a bug that should be reported to CPython and/or Apple.

[tacaswell]

That is an awesome cartoon!

[mdboom]

I found it on the Python bugtracker. https://bugs.python.org/issue18172

[matthew-brett]

Further feedback from my 10.11 source:

$ /usr/bin/python
Python 2.7.10 (default, Aug 22 2015, 20:33:39) 
[GCC 4.2.1 Compatible Apple LLVM 7.0.0 (clang-700.0.59.1)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> p = subprocess.Popen(['foo'], stdout=subprocess.PIPE, stderr=subprocess.PIPE)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 710, in __init__
    errread, errwrite)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 1334, in _execute_child
    child_exception = pickle.loads(data)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 1382, in loads
    return Unpickler(file).load()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 858, in load
    dispatch[key](self)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 966, in load_string
    raise ValueError, "insecure string pickle"
ValueError: insecure string pickle

$ python3.5
Python 3.5.0 (v3.5.0:374f501f4567, Sep 12 2015, 11:00:19) 
[GCC 4.2.1 (Apple Inc. build 5666) (dot 3)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> p = subprocess.Popen(['foo'], stdout=subprocess.PIPE, stderr=subprocess.PIPE)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/subprocess.py", line 950, in __init__
    restore_signals, start_new_session)
  File "/Library/Frameworks/Python.framework/Versions/3.5/lib/python3.5/subprocess.py", line 1540, in _execute_child
    raise child_exception_type(errno_num, err_msg)
FileNotFoundError: [Errno 2] No such file or directory: 'foo'

[mdboom]

Great. I'd say it's definitely a bug in Python 2.7.10 and/or an incompatiblity between how Apple builds Python 2.7.10 and El Capitain. I'd report this to CPython and/or Apple. I'd file the report myself, but since I don't have El Capitain to reproduce on, I'm afraid I won't be of much use.

[jenshnielsen]

I can't reproduce it in any way using neither system python nor python 2.7 or 3.5 from homebrew on 10.11.1. Could it be fixed in the 10.11.1 update?

[matthew-brett]

@jenshnielsen - is it possible that you have fc-list installed on your system? In that case I think you would not get the error.

[jenshnielsen]

Yes I have font-config installed. What I meant was that I can't reproduce the issue with a non existing command such as 'foo' with either python version i.e. running

p = subprocess.Popen(['foo'], stdout=subprocess.PIPE, stderr=subprocess.PIPE)

raises a FileNotFoundError as expected.

[matthew-brett]

Ah - sorry for my confusion. My colleague also has 10.11.1. Can you think of any other explanation for the difference.

[jenshnielsen]

Just a shot in the dark but could it be something like a non ascii username/path

[matthew-brett]

I don't think that's the case for my colleague's machine. We just upgraded a machine, and don't get the failure either.

[matthew-brett]

Nicholas Angelides is my colleague with this bug - we sat down with his computer for a few minutes.

This expanded the confusion. We replicated the behavior above, both on his account and a new Test account, with system Python. Then we rebooted the machine and got the expected behavior on his account and the new Test account. I'm a bit lost for ways to proceed. Any suggestions?

[tacaswell]

Hurrah, a Heisenbug!

[mariusae]

It appears python is assuming that a single read() call will read all available data (until EOF). That is not so. This should fix it:

% diff -u /System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py lib/python2.7/subprocess.py
--- /System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py    2015-08-22 20:36:56.000000000 -0700
+++ lib/python2.7/subprocess.py 2015-12-01 14:05:48.000000000 -0800
@@ -1313,7 +1305,13 @@

                 # Wait for exec to fail or succeed; possibly raising exception
                 # Exception limited to 1M
-                data = _eintr_retry_call(os.read, errpipe_read, 1048576)
+                data = ""
+                buf = _eintr_retry_call(os.read, errpipe_read, 1048576)
+                data += buf
+                while buf:
+                  buf = _eintr_retry_call(os.read, errpipe_read, 1048576)
+                  data += buf
+
             finally:
                 if p2cread is not None and p2cwrite is not None:
                     _close_in_parent(p2cread)

[tacaswell]

That needs to be reported upstream, we are not going to ship a monkey patch to a core library.

[mariusae]

Yep, wasn't suggesting that... just giving people a workaround until it is resolved.

[yan12125]

Seems nobody has reported it to Python. Here it is: http://bugs.python.org/issue26083.

[gpshead]

A good workaround for matplotlib would be to use subprocess32 instead of subprocess when running on Python 2. It is better in too many ways to list here (and acts as a drop in replacement). The upstream issue has been fixed in 2.7.

But I wouldn't expect Apple to fix anything in a timely manner. Pro tip: Build and install your own Python, never use the one shipped by your OS distro.

[ludoleg]

I don't see the 2.7.12 release out yet . What is the best way to work around this issue to run matplotlib on El Capitan?

[actongorton]

I'm also having this issue, and my Python is installed through HomeBrew.

Why not go with @gpshead advice instead of waiting for a fix from Python?

➜  ~  python
Python 2.7.11 (default, Jan 22 2016, 08:29:18) 
[GCC 4.2.1 Compatible Apple LLVM 7.0.2 (clang-700.1.81)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import subprocess
>>> p = subprocess.Popen(['foo'], stdout=subprocess.PIPE, stderr=subprocess.PIPE)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 710, in __init__
    errread, errwrite)
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/subprocess.py", line 1334, in _execute_child
    child_exception = pickle.loads(data)
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 1388, in loads
    return Unpickler(file).load()
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 864, in load
    dispatch[key](self)
  File "/usr/local/Cellar/python/2.7.11/Frameworks/Python.framework/Versions/2.7/lib/python2.7/pickle.py", line 972, in load_string
    raise ValueError, "insecure string pickle"
ValueError: insecure string pickle

[tacaswell]

@acer9997 pull requests are always welcome.

[QuLogic]

2.0 will require subprocess32 to work around this bug (see #6576.)