✊🏿 Black Lives Matter. Please consider donating to Black Girls Code today.
🧬 Learn how to build RNA-Seq data apps with Python & Dash. Register for the May 20 Webinar!

Deepcopy() Error when deploying Dash app to Heroku

Hi,

I’ve been chasing an odd bug for a while now.

I have a Dash app that works fine locally, but when deploying to Heroku fails about 60% of the time. Sometimes it works!?

I’m using Dash because I’m not that familiar with webdevelopment. So, I’m likely out of my element here, but I believe it has something to do with Heroku spawning the app to a worker, trying to make a copy of the the trace properties, getting an error and hitting a maximum recursion depth when logging the error. I’m not actually trying to use deepcopy(), Heroku is doing that for me in spawning the worker… I think?

Here are two errors from the Heroku logs:

The first is a Heroku log Error telling me the Traceback is firing the error a lot: 
2021-04-16T14:58:27.334811+00:00 app[web.1]: [2021-04-16 14:58:27 +0000] [4] [CRITICAL] WORKER TIMEOUT (pid:28)
2021-04-16T14:58:27.343620+00:00 app[web.1]: --- Logging error ---
2021-04-16T14:58:27.349661+00:00 app[web.1]: [2021-04-16 14:58:27 +0000] [27] [INFO] Worker exiting (pid: 27)
2021-04-16T14:58:27.351689+00:00 app[web.1]: --- Logging error ---
2021-04-16T14:58:27.358652+00:00 app[web.1]: 
2021-04-16T14:58:27.358654+00:00 app[web.1]: Error: maximum recursion depth exceeded while calling a Python object

The second is the Traceback:

2021-04-16T14:31:06.054915+00:00 app[web.1]: The above exception was the direct cause of the following exception:
2021-04-16T14:31:06.054915+00:00 app[web.1]: 
2021-04-16T14:31:06.054915+00:00 app[web.1]: Traceback (most recent call last):
2021-04-16T14:31:06.054916+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/arbiter.py", line 583, in spawn_worker
2021-04-16T14:31:06.054916+00:00 app[web.1]: worker.init_process()
2021-04-16T14:31:06.054917+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base.py", line 119, in init_process
2021-04-16T14:31:06.054917+00:00 app[web.1]: self.load_wsgi()
2021-04-16T14:31:06.054917+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/workers/base.py", line 144, in load_wsgi
2021-04-16T14:31:06.054918+00:00 app[web.1]: self.wsgi = self.app.wsgi()
2021-04-16T14:31:06.054920+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/app/base.py", line 67, in wsgi
2021-04-16T14:31:06.054920+00:00 app[web.1]: self.callable = self.load()
2021-04-16T14:31:06.054921+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/app/wsgiapp.py", line 49, in load
2021-04-16T14:31:06.054946+00:00 app[web.1]: return self.load_wsgiapp()
2021-04-16T14:31:06.054946+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/app/wsgiapp.py", line 39, in load_wsgiapp
2021-04-16T14:31:06.054946+00:00 app[web.1]: return util.import_app(self.app_uri)
2021-04-16T14:31:06.054947+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/gunicorn/util.py", line 358, in import_app
2021-04-16T14:31:06.054947+00:00 app[web.1]: mod = importlib.import_module(module)
2021-04-16T14:31:06.054947+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/importlib/__init__.py", line 126, in import_module
2021-04-16T14:31:06.054948+00:00 app[web.1]: return _bootstrap._gcd_import(name[level:], package, level)
2021-04-16T14:31:06.054948+00:00 app[web.1]: File "<frozen importlib._bootstrap>", line 994, in _gcd_import
2021-04-16T14:31:06.054948+00:00 app[web.1]: File "<frozen importlib._bootstrap>", line 971, in _find_and_load
2021-04-16T14:31:06.054948+00:00 app[web.1]: File "<frozen importlib._bootstrap>", line 955, in _find_and_load_unlocked
2021-04-16T14:31:06.054949+00:00 app[web.1]: File "<frozen importlib._bootstrap>", line 665, in _load_unlocked
2021-04-16T14:31:06.054949+00:00 app[web.1]: File "<frozen importlib._bootstrap_external>", line 678, in exec_module
2021-04-16T14:31:06.054949+00:00 app[web.1]: File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
2021-04-16T14:31:06.054949+00:00 app[web.1]: File "/app/app.py", line 534, in <module>
2021-04-16T14:31:06.054949+00:00 app[web.1]: app.layout = serve_layout
2021-04-16T14:31:06.054950+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/dash/dash.py", line 473, in layout
2021-04-16T14:31:06.054950+00:00 app[web.1]: layout_value = self._layout_value()
2021-04-16T14:31:06.054950+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/dash/dash.py", line 439, in _layout_value
2021-04-16T14:31:06.054951+00:00 app[web.1]: return self._layout() if self._layout_is_function else self._layout
2021-04-16T14:31:06.054951+00:00 app[web.1]: File "/app/app.py", line 524, in serve_layout
2021-04-16T14:31:06.054954+00:00 app[web.1]: figure=build_sponsored_chart_2()
2021-04-16T14:31:06.054954+00:00 app[web.1]: File "/app/app.py", line 114, in build_sponsored_chart_2
2021-04-16T14:31:06.054954+00:00 app[web.1]: mode='lines', name='Rolling Average'))
2021-04-16T14:31:06.054954+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/plotly/basedatatypes.py", line 1652, in add_trace
2021-04-16T14:31:06.054955+00:00 app[web.1]: secondary_ys=[secondary_y] if secondary_y is not None else None,
2021-04-16T14:31:06.054955+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/plotly/basedatatypes.py", line 1769, in add_traces
2021-04-16T14:31:06.054955+00:00 app[web.1]: new_traces_data = [deepcopy(trace._props) for trace in data]
2021-04-16T14:31:06.054956+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/site-packages/plotly/basedatatypes.py", line 1769, in <listcomp>
2021-04-16T14:31:06.054956+00:00 app[web.1]: new_traces_data = [deepcopy(trace._props) for trace in data]
2021-04-16T14:31:06.054956+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/copy.py", line 150, in deepcopy
2021-04-16T14:31:06.054956+00:00 app[web.1]: y = copier(x, memo)
2021-04-16T14:31:06.054957+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/copy.py", line 240, in _deepcopy_dict
2021-04-16T14:31:06.054957+00:00 app[web.1]: y[deepcopy(key, memo)] = deepcopy(value, memo)
2021-04-16T14:31:06.054957+00:00 app[web.1]: File "/app/.heroku/python/lib/python3.6/copy.py", line 161, in deepcopy
2021-04-16T14:31:06.054961+00:00 app[web.1]: y = copier(memo)
2021-04-16T14:31:06.055443+00:00 app[web.1]: SystemError: <built-in method __deepcopy__ of numpy.ndarray object at 0x7f48c9658da0> returned a result with an error set
2021-04-16T14:31:06.057122+00:00 app[web.1]: [2021-04-16 14:31:06 +0000] [10] [INFO] Worker exiting (pid: 10)
2021-04-16T14:31:06.797372+00:00 app[web.1]: [2021-04-16 14:31:06 +0000] [28] [INFO] Booting worker with pid: 28

I’m on the Heroku 20 Stack (python 3.9.4), with these libraries:

backcall==0.2.0
Brotli==1.0.9
certifi==2020.12.5
chardet==4.0.0
chart-studio==1.1.0
click==7.1.2
dash==1.20.0
dash-auth==1.4.1
dash-bootstrap-components==0.12.0
dash-core-components==1.16.0
dash-html-components==1.1.3
dash-renderer==1.9.1
dash-table==4.11.3
decorator==5.0.7
elasticsearch==7.12.0
Flask==1.1.2
Flask-Compress==1.9.0
Flask-SeaSurf==0.3.0
future==0.18.2
greenlet==1.0.0
gunicorn==20.1.0
idna==2.10
ipykernel==5.5.3
ipython==7.22.0
ipython-genutils==0.2.0
itsdangerous==1.1.0
jedi==0.18.0
Jinja2==2.11.3
joblib==1.0.1
jupyter-client==6.1.12
jupyter-core==4.7.1
MarkupSafe==1.1.1
numpy==1.20.2
pandas==1.2.4
parso==0.8.2
pexpect==4.8.0
pickleshare==0.7.5
plotly==4.14.3
prompt-toolkit==3.0.18
psycopg2==2.8.6
ptyprocess==0.7.0
Pygments==2.8.1
python-dateutil==2.8.1
python-dotenv==0.17.0
pytz==2021.1
pyzmq==22.0.3
redis==3.5.3
requests==2.25.1
retrying==1.3.3
scikit-learn==0.24.1
scipy==1.6.2
six==1.15.0
SQLAlchemy==1.4.8
threadpoolctl==2.1.0
tornado==6.1
traitlets==5.0.5
ua-parser==0.10.0
urllib3==1.26.4
wcwidth==0.2.5
Werkzeug==1.0.1

The lines of code that the deepcopy error trace refers to are here:

# load SQL cursor in to Pandas
daily_eng = pd.DataFrame(cur.fetchall(), 
                                 columns=[
                                     "date", "all", "0_5k", "5_10k", "10_25k", "25_50k", "50_100k", "100_250k",
                                     "250k_500k", "500k_1mil", "1mil_plus"
                                 ])
daily_eng.sort_values('date', inplace=True)

#Convert all columns except the first (date) to a rolling 7 day average 
daily_eng.iloc[:, 1:] = daily_eng.iloc[:, 1:].rolling(window=7, center=False).mean().copy() 

fig = go.Figure()
fig.add_trace(go.Scatter(x=daily_eng['date'], y=daily_eng['all'], name='all', mode='lines'))
fig.add_trace(
            go.Scatter(x=daily_eng['date'], y=daily_eng['0_5k'], name='0_5k', mode='lines', visible='legendonly'))
fig.add_trace(
            go.Scatter(x=daily_eng['date'], y=daily_eng['5_10k'], name='5_10k', mode='lines', visible='legendonly'))
fig.add_trace(
            go.Scatter(x=daily_eng['date'], y=daily_eng['10_25k'], name='10_25k', mode='lines', visible='legendonly'))
fig.add_trace(
            go.Scatter(x=daily_eng['date'], y=daily_eng['25_50k'], name='25_50k', mode='lines', visible='legendonly'))
fig.add_trace(
            go.Scatter(x=daily_eng['date'], y=daily_eng['50_100k'], name='50_100k', mode='lines', visible='legendonly'))

I’ve seen a few bug reports on Git from 2018 about a deepcopy problem, but that seemed to be resolved?

Anyone have any thoughts or have run into this in the past?