Unhandled exception after failed upload

[Brett Smith]

My friend is trying to install MediaGoblin but it breaks when he tries to upload a JPG. That might not be the end of the world by itself, but there's an unhandled exception when the code tries to save information about the failure, so it's really difficult to tell what went on. This bug is about fixing that exception.

[Ward]

This is the backtrace.

$ ./lazyserver.sh -c paste.ini 
Using paster config: paste.ini
Using ./bin/paster
+ export CELERY_ALWAYS_EAGER=true
+ ./bin/paster serve paste.ini --reload
Starting subprocess with file monitor
2012-05-14 21:27:49,041 INFO    [mediagoblin.app] GNU MediaGoblin 0.3.1.dev main server starting
Starting server in PID 26849.
serving on http://127.0.0.1:6543



/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/engine/default.py:518: SAWarning: Unicode type received non-unicode bind param value.
  param[key.encode(encoding)] = processors[key](compiled_params[key])
2012-05-14 21:28:00,669 WARNING [mediagoblin.processing] No idea what happened here, but it failed: FlushError("Instance <ImageData at 0xa8bfb6c> is an unsaved, pending instance and is an orphan (is not attached to any parent 'MediaEntry' instance via that classes' 'image__media_data' attribute)",)
Error - <class 'sqlalchemy.orm.exc.FlushError'>: Instance <ImageData at 0xa8bfb6c> is an unsaved, pending instance and is an orphan (is not attached to any parent 'MediaEntry' instance via that classes' 'image__media_data' attribute)
URL: http://localhost:6543/submit/
File '/usr/src/mediagoblin/lib/python2.7/site-packages/Paste-1.7.5.1-py2.7.egg/paste/exceptions/errormiddleware.py', line 144 in __call__
  app_iter = self.application(environ, sr_checker)
File '/usr/src/mediagoblin/lib/python2.7/site-packages/Paste-1.7.5.1-py2.7.egg/paste/urlmap.py', line 203 in __call__
  return app(environ, start_response)
File '/usr/src/mediagoblin/lib/python2.7/site-packages/Beaker-1.6.3-py2.7.egg/beaker/middleware.py', line 155 in __call__
  return self.wrap_app(environ, session_start_response)
File '/usr/src/mediagoblin/mediagoblin/app.py', line 201 in __call__
  return self.call_backend(environ, start_response)
File '/usr/src/mediagoblin/mediagoblin/app.py', line 188 in call_backend
  response = controller(request)
File '/usr/src/mediagoblin/mediagoblin/decorators.py', line 50 in new_controller_func
  return controller(request, *args, **kwargs)
File '/usr/src/mediagoblin/mediagoblin/submit/views.py', line 134 in submit_start
  mark_entry_failed(entry._id, exc)
File '/usr/src/mediagoblin/mediagoblin/processing/__init__.py', line 99 in mark_entry_failed
  u'fail_metadata': {}})
File '/usr/src/mediagoblin/mediagoblin/db/sql/util.py', line 284 in atomic_update
  synchronize_session=False)
File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/query.py', line 2198 in update
  session._autoflush()
File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 843 in _autoflush
  self.flush()
File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 1359 in flush
  self._flush(objects)
File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 1422 in _flush
  mapperutil.state_str(state), path))
FlushError: Instance <ImageData at 0xa8bfb6c> is an unsaved, pending instance and is an orphan (is not attached to any parent 'MediaEntry' instance via that classes' 'image__media_data' attribute)


CGI Variables
-------------
  CONTENT_TYPE: 'multipart/form-data; boundary=---------------------------5294293321459577981686239280'
  CSRF_TOKEN: u'10591475841502639015'
  HTTP_ACCEPT: 'text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8'
  HTTP_ACCEPT_ENCODING: 'gzip, deflate'
  HTTP_ACCEPT_LANGUAGE: 'en-us,en;q=0.5'
  HTTP_CONNECTION: 'keep-alive'
  HTTP_COOKIE: 'mediagoblin_csrftoken=10591475841502639015; mediagoblin_csrftoken=10591475841502639015; mediagoblin=b11c735534a54626a32182ac1cdee7bd'
  HTTP_DNT: '1'
  HTTP_HOST: 'localhost:6543'
  HTTP_REFERER: 'http://localhost:6543/submit/'
  HTTP_USER_AGENT: 'Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:13.0) Gecko/20100101 Firefox/13.0'
  PATH_INFO: '/submit/'
  REMOTE_ADDR: '127.0.0.1'
  REQUEST_METHOD: 'POST'
  SERVER_NAME: '127.0.0.1'
  SERVER_PORT: '6543'
  SERVER_PROTOCOL: 'HTTP/1.1'


WSGI Variables
--------------
  application: {(None, '/mgoblin_media'): <StaticURLParser '/usr/src/mediagoblin/user_dev/media/public'>, (None, '/mgoblin_static'): <StaticURLParser '/usr/src/mediagoblin/mediagoblin/static'>, (None, ''): <beaker.middleware.SessionMiddleware object at 0xa4169ec>}
  beaker.get_session: <bound method SessionMiddleware._get_session of <beaker.middleware.SessionMiddleware object at 0xa4169ec>>
  beaker.session: {'user_id': u'1', '_accessed_time': 1337045280.538824, '_creation_time': 1337040602.031518}
  paste.httpserver.thread_pool: <paste.httpserver.ThreadPool object at 0xb67350ec>
  paste.throw_errors: True
  webob._body_file: (<LimitedLengthFile(<socket._fileobject object at 0xa7bb16c length=420536>, maxlen=420536)>, <socket._fileobject object at 0xa7bb16c length=420536>)
  webob._parsed_cookies: ({'mediagoblin_csrftoken': '10591475841502639015', 'mediagoblin': 'b11c735534a54626a32182ac1cdee7bd'}, 'mediagoblin_csrftoken=10591475841502639015; mediagoblin_csrftoken=10591475841502639015; mediagoblin=b11c735534a54626a32182ac1cdee7bd')
  webob._parsed_post_vars: (MultiDict([('file', FieldStorage('file', 'F1020004.jpeg')), ('title', ''), ('description', ''), ('tags', ''), ('license', ''), ('csrf_token', '10591475841502639015')]), <FakeCGIBody at 0xa7cfb2c viewing MultiDict([('fi...5')])>)
  webob._parsed_query_vars: (GET([]), '')
  webob.adhoc_attrs: {'locale': 'en_US', 'staticdirect': <mediagoblin.staticdirect.RemoteStaticDirect object at 0xa41a18c>, 'app': <mediagoblin.app.MediaGoblinApp object at 0xa3f712c>, 'db': <mediagoblin.db.sql.open.DatabaseMaster object at 0xa47476c>, 'urlgen': <routes.util.URLGenerator object at 0xa7cf62c>, 'start_response': <function session_start_response at 0xa7c90d4>, 'session': {'user_id': u'1', '_accessed_time': 1337045280.538824, '_creation_time': 1337040602.031518}, 'full_path': '/submit/', 'template_env': <jinja2.environment.Environment object at 0xa4b7fac>, 'matchdict': {'controller': u'mediagoblin.submit.views:submit_start'}, 'user': <mediagoblin.db.sql.models.User object at 0xa7bf1cc>}
  webob.is_body_readable: True
  webob.is_body_seekable: False
  wsgi process: 'Multithreaded'
------------------------------------------------------------

[Ward]

With the call to mark_entry_failed commented out, this is the backtrace:

$ ./lazyserver.sh -c paste.ini
Using paster config: paste.ini
Using ./bin/paster
+ export CELERY_ALWAYS_EAGER=true
+ ./bin/paster serve paste.ini --reload
Starting subprocess with file monitor

2012-05-14 22:52:54,873 INFO [mediagoblin.app] GNU MediaGoblin 0.3.1.dev main server starting
Starting server in PID 28871.
serving on ​http://127.0.0.1:6543

/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/engine/default.py:518: SAWarning: Unicode type received non-unicode bind param value.

param[key.encode(encoding)] = processors[key](compiled_params[key])

Error - <class 'sqlalchemy.orm.exc.FlushError'>: Instance <ImageData at 0xb31fecc> is an unsaved, pending instance and is an orphan (is not attached to any parent 'MediaEntry' instance via that classes' 'imagemedia_data' attribute)
URL: ​http://localhost:6543/submit/
File '/usr/src/mediagoblin/lib/python2.7/site-packages/Paste-1.7.5.1-py2.7.egg/paste/exceptions/errormiddleware.py', line 144 in call

app_iter = self.application(environ, sr_checker)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/Paste-1.7.5.1-py2.7.egg/paste/urlmap.py', line 203 in call

return app(environ, start_response)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/Beaker-1.6.3-py2.7.egg/beaker/middleware.py', line 155 in call

return self.wrap_app(environ, session_start_response)

File '/usr/src/mediagoblin/mediagoblin/app.py', line 201 in call

return self.call_backend(environ, start_response)

File '/usr/src/mediagoblin/mediagoblin/app.py', line 188 in call_backend

response = controller(request)

File '/usr/src/mediagoblin/mediagoblin/decorators.py', line 50 in new_controller_func

return controller(request, *args, kwargs)

File '/usr/src/mediagoblin/mediagoblin/submit/views.py', line 124 in submit_start

task_id=task_id)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/celery-2.5.3-py2.7.egg/celery/app/task/init.py', line 445 in apply_async

return self.apply(args, kwargs, task_id=task_id, options)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/celery-2.5.3-py2.7.egg/celery/app/task/init.py', line 601 in apply

request=request, propagate=throw)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/celery-2.5.3-py2.7.egg/celery/execute/trace.py', line 248 in eager_trace_task

uuid, args, kwargs, request)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/celery-2.5.3-py2.7.egg/celery/execute/trace.py', line 181 in trace_task

R = retval = fun(*args, kwargs)

File '/usr/src/mediagoblin/mediagoblin/processing/task.py', line 66 in run

entry.save()

File '/usr/src/mediagoblin/mediagoblin/db/sql/base.py', line 80 in save

sess.commit()

File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 595 in commit

self.transaction.commit()

File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 367 in commit

self._prepare_impl()

File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 351 in _prepare_impl

self.session.flush()

File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 1359 in flush

self._flush(objects)

File '/usr/src/mediagoblin/lib/python2.7/site-packages/SQLAlchemy-0.6.4-py2.7.egg/sqlalchemy/orm/session.py', line 1422 in _flush

mapperutil.state_str(state), path))

FlushError: Instance <ImageData at 0xb31fecc> is an unsaved, pending instance and is an orphan (is not attached to any parent 'MediaEntry' instance via that classes' 'imagemedia_data' attribute)

CGI Variables

---

CONTENT_TYPE: 'multipart/form-data; boundary=---------------------------5294293321459577981686239280'
CSRF_TOKEN: u'10591475841502639015'
HTTP_ACCEPT: 'text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8'
HTTP_ACCEPT_ENCODING: 'gzip, deflate'
HTTP_ACCEPT_LANGUAGE: 'en-us,en;q=0.5'
HTTP_CACHE_CONTROL: 'max-age=0'
HTTP_CONNECTION: 'keep-alive'
HTTP_COOKIE: 'mediagoblin_csrftoken=10591475841502639015; mediagoblin_csrftoken=10591475841502639015; mediagoblin=b11c735534a54626a32182ac1cdee7bd'
HTTP_DNT: '1'
HTTP_HOST: 'localhost:6543'
HTTP_REFERER: '​http://localhost:6543/submit/'
HTTP_USER_AGENT: 'Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:13.0) Gecko/20100101 Firefox/13.0'
PATH_INFO: '/submit/'
REMOTE_ADDR: '127.0.0.1'
REQUEST_METHOD: 'POST'
SERVER_NAME: '127.0.0.1'
SERVER_PORT: '6543'
SERVER_PROTOCOL: 'HTTP/1.1'

WSGI Variables

---

application: {(None, '/mgoblin_media'): <StaticURLParser '/usr/src/mediagoblin/user_dev/media/public'>, (None, '/mgoblin_static'): <StaticURLParser '/usr/src/mediagoblin/mediagoblin/static'>, (None, ): <beaker.middleware.SessionMiddleware object at 0xaeac9ec>}
beaker.get_session: <bound method SessionMiddleware._get_session of <beaker.middleware.SessionMiddleware object at 0xaeac9ec>>
beaker.session: {'user_id': u'1', '_accessed_time': 1337050386.647371, '_creation_time': 1337040602.031518}
paste.httpserver.thread_pool: <paste.httpserver.ThreadPool object at 0xa32d82c>
paste.throw_errors: True
webob._body_file: (<LimitedLengthFile(<socket._fileobject object at 0xa2c322c length=420536>, maxlen=420536)>, <socket._fileobject object at 0xa2c322c length=420536>)
webob._parsed_cookies: ({'mediagoblin_csrftoken': '10591475841502639015', 'mediagoblin': 'b11c735534a54626a32182ac1cdee7bd'}, 'mediagoblin_csrftoken=10591475841502639015; mediagoblin_csrftoken=10591475841502639015; mediagoblin=b11c735534a54626a32182ac1cdee7bd')
webob._parsed_post_vars: (MultiDict([('file', FieldStorage('file', 'F1020004.jpeg')), ('title', ), ('description', ), ('tags', ), ('license', ), ('csrf_token', '10591475841502639015')]), <FakeCGIBody at 0xaf520cc viewing MultiDict([('fi...5')])>)
webob._parsed_query_vars: (GET([]), )
webob.adhoc_attrs: {'locale': 'en_US', 'staticdirect': <mediagoblin.staticdirect.RemoteStaticDirect object at 0xaeb018c>, 'app': <mediagoblin.app.MediaGoblinApp object at 0xae8d12c>, 'db': <mediagoblin.db.sql.open.DatabaseMaster object at 0xaf0a76c>, 'urlgen': <routes.util.URLGenerator object at 0xaf49aec>, 'start_response': <function session_start_response at 0xaf0ca74>, 'session': {'user_id': u'1', '_accessed_time': 1337050386.647371, '_creation_time': 1337040602.031518}, 'full_path': '/submit/', 'template_env': <jinja2.environment.Environment object at 0xaf4fe4c>, 'matchdict': {'controller': u'mediagoblin.submit.views:submit_start'}, 'user': <mediagoblin.db.sql.models.User object at 0xaf7138c>}
webob.is_body_readable: True
webob.is_body_seekable: False
wsgi process: 'Multithreaded'

---

[Brett Smith]

I think the problem here is that we don't really define a MediaEntry's relationship to MediaData in the MediaEntry class. There is a relationship, through the media_entry column of the MediaData class, but we don't adequately describe that to SQLAlchemy. That's why media_data is marked as TODO in db/sql/models.py. Without that information, when we try to process an image with GPS and/or EXIF data (not sure if it's one or the other or both), SQLAlchemy flips out because the MediaData looks like an orphan, even though the relationship is described in the SQL well enough.

The proper fix would be to give the relationship a good definition in the MediaEntry class, much like the other attributes have, but I'm going to need to do some reading to figure out the right way to do that.

[Elrond]

Hi brett,

excuse us for taking sooo long to notice your bug!

Your bugreports is one of those with the flusherror. Do you have a way of reproducting it, so that we can also reproduce it?

I probably have a fix for this. But I would like to understand how this can happen at all. It should not happen.

I'll take this one and set it to be fixed for the next release.

[Elrond]

Okay.

Pushed suggested fix to elrond/sql/media_data. Waiting for review and a "go, merge it".

And I have no clue, why this fails only in some cases. It should either fail always (for images with exif/gps data) or never. I don't get it.

[Christopher Allan Webber]

Merged! The branch looks really good. Let's assume it fixes it unless proven otherwise. :)