[ckan-dev] Stuck DataPusher / DataStore job
Florian.Brucker at it.karlsruhe.de
Florian.Brucker at it.karlsruhe.de
Tue Jan 9 08:27:09 UTC 2018
It seems that the job finally went through successfully after more than 1
hour. I'd still be interested in any pointers regarding the exceptions and
for a better control of DataPusher jobs.
Best regards
Florian
"ckan-dev" <ckan-dev-bounces at lists.okfn.org> schrieb am 09.01.2018
08:59:58:
> Von: Florian.Brucker at it.karlsruhe.de
> An: ckan-dev at lists.okfn.org,
> Datum: 09.01.2018 09:20
> Betreff: [ckan-dev] Stuck DataPusher / DataStore job
> Gesendet von: "ckan-dev" <ckan-dev-bounces at lists.okfn.org>
>
> Hi everybody,
>
> after manually changing the title of a resource in my CKAN 2.7
> instance I ended up with a stuck DataPusher / DataStore job for that
> resource's CSV file: if I edit the resource and check the
> "DataStore" tab then it tells me that the resource is still being
> uploaded to the DataStore. This has been going on for more than 30
> minutes, while the CSV file is rather small (17KB, around 450 records).
>
> I tried re-submitting the job by editing the resource again manually
> (this did not change anything or reset the job's timer) and by using
> paster. The latter also failed:
>
> -----
> paster --plugin=ckan datapusher submit
> 6dfd8a0c-019f-401c-82b6-4f808e31f7f9 -c /etc/ckan/default/production.ini
> Data in any datastore resource that isn't in their source files
> (e.g. data added using the datastore API) will be permanently lost.
> Are you sure you want to proceed? [y/n] y
> Submitting 1 datastore resources
> Submitting 15e317b3-0e17-4451-9d4e-5d5478620f1c... Fail
> -----
>
> Querying the resource's datastore entry via the datastore_info API
> function works as expected.
>
> I tried to figure out what's going wrong, but the DataPusher's
> documentation and its debugging options seem to be limited (any
> pointers are very welcome!). In the log files I found the following:
>
> -----
> [Tue Jan 09 08:15:03.544059 2018] [wsgi:error] [pid 9913] /usr/lib/
> ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/sql/
> sqltypes.py:219: SAWarning: Unicode type received non-unicode bind
> param value '9b75e6b9-59a5-4b8b-9a93-1...'. (this warning may be
> suppressed after 10 occurrences)
> [Tue Jan 09 08:15:03.544114 2018] [wsgi:error] [pid 9913]
> (util.ellipses_string(value),))
> [Tue Jan 09 08:15:13.892433 2018] [wsgi:error] [pid 9913] Error
> notifying listener
> [Tue Jan 09 08:15:13.892464 2018] [wsgi:error] [pid 9913] Traceback
> (most recent call last):
> [Tue Jan 09 08:15:13.892468 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/apscheduler/
> scheduler.py", line 239, in _notify_listeners
> [Tue Jan 09 08:15:13.892471 2018] [wsgi:error] [pid 9913] cb(event)
> [Tue Jan 09 08:15:13.892473 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/
> ckanserviceprovider/web.py", line 184, in job_listener
> [Tue Jan 09 08:15:13.892476 2018] [wsgi:error] [pid 9913]
> db.mark_job_as_errored(job_id, error_object)
> [Tue Jan 09 08:15:13.892479 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/
> ckanserviceprovider/db.py", line 413, in mark_job_as_errored
> [Tue Jan 09 08:15:13.892482 2018] [wsgi:error] [pid 9913]
> _update_job(job_id, update_dict)
> [Tue Jan 09 08:15:13.892484 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/
> ckanserviceprovider/db.py", line 361, in _update_job
> [Tue Jan 09 08:15:13.892487 2018] [wsgi:error] [pid 9913]
> .values(**job_dict))
> [Tue Jan 09 08:15:13.892489 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 2064, in execute
> [Tue Jan 09 08:15:13.892492 2018] [wsgi:error] [pid 9913] return
> connection.execute(statement, *multiparams, **params)
> [Tue Jan 09 08:15:13.892495 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 945, in execute
> [Tue Jan 09 08:15:13.892497 2018] [wsgi:error] [pid 9913] return
> meth(self, multiparams, params)
> [Tue Jan 09 08:15:13.892500 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/sql/
> elements.py", line 263, in _execute_on_connection
> [Tue Jan 09 08:15:13.892503 2018] [wsgi:error] [pid 9913] return
> connection._execute_clauseelement(self, multiparams, params)
> [Tue Jan 09 08:15:13.892506 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1053, in _execute_clauseelement
> [Tue Jan 09 08:15:13.892508 2018] [wsgi:error] [pid 9913]
> compiled_sql, distilled_params
> [Tue Jan 09 08:15:13.892511 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1209, in _execute_context
> [Tue Jan 09 08:15:13.892514 2018] [wsgi:error] [pid 9913]
> self._root._commit_impl(autocommit=True)
> [Tue Jan 09 08:15:13.892516 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 726, in _commit_impl
> [Tue Jan 09 08:15:13.892519 2018] [wsgi:error] [pid 9913]
> self.connection._reset_agent is self.__transaction:
> [Tue Jan 09 08:15:13.892521 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 351, in connection
> [Tue Jan 09 08:15:13.892524 2018] [wsgi:error] [pid 9913]
> self._handle_dbapi_exception(e, None, None, None, None)
> [Tue Jan 09 08:15:13.892527 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1405, in _handle_dbapi_exception
> [Tue Jan 09 08:15:13.892529 2018] [wsgi:error] [pid 9913]
> util.reraise(*exc_info)
> [Tue Jan 09 08:15:13.892532 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 349, in connection
> [Tue Jan 09 08:15:13.892534 2018] [wsgi:error] [pid 9913] return
> self._revalidate_connection()
> [Tue Jan 09 08:15:13.892555 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 429, in _revalidate_connection
> [Tue Jan 09 08:15:13.892558 2018] [wsgi:error] [pid 9913] raise
> exc.ResourceClosedError("This Connection is closed")
> [Tue Jan 09 08:15:13.892561 2018] [wsgi:error] [pid 9913]
> ResourceClosedError: This Connection is closed
> [Tue Jan 09 08:15:13.911894 2018] [wsgi:error] [pid 9913] Job
> "push_to_datastore (trigger: RunTriggerNow, run = True, next run at:
> None)" raised an exception
> [Tue Jan 09 08:15:13.911906 2018] [wsgi:error] [pid 9913] Traceback
> (most recent call last):
> [Tue Jan 09 08:15:13.911909 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/apscheduler/
> scheduler.py", line 512, in _run_job
> [Tue Jan 09 08:15:13.911912 2018] [wsgi:error] [pid 9913] retval
> = job.func(*job.args, **job.kwargs)
> [Tue Jan 09 08:15:13.911914 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/src/datapusher/datapusher/jobs.py", line
> 307, in push_to_datastore
> [Tue Jan 09 08:15:13.911917 2018] [wsgi:error] [pid 9913]
> logger.info('Fetching from: {0}'.format(resource.get('url')))
> [Tue Jan 09 08:15:13.911920 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/python2.7/logging/__init__.py", line 1160, in info
> [Tue Jan 09 08:15:13.911923 2018] [wsgi:error] [pid 9913]
> self._log(INFO, msg, args, **kwargs)
> [Tue Jan 09 08:15:13.911925 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/python2.7/logging/__init__.py", line 1279, in _log
> [Tue Jan 09 08:15:13.911928 2018] [wsgi:error] [pid 9913]
> self.handle(record)
> [Tue Jan 09 08:15:13.911930 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/python2.7/logging/__init__.py", line 1289, in handle
> [Tue Jan 09 08:15:13.911933 2018] [wsgi:error] [pid 9913]
> self.callHandlers(record)
> [Tue Jan 09 08:15:13.911935 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/python2.7/logging/__init__.py", line 1329, in callHandlers
> [Tue Jan 09 08:15:13.911938 2018] [wsgi:error] [pid 9913]
> hdlr.handle(record)
> [Tue Jan 09 08:15:13.911940 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/python2.7/logging/__init__.py", line 757, in handle
> [Tue Jan 09 08:15:13.911943 2018] [wsgi:error] [pid 9913]
> self.emit(record)
> [Tue Jan 09 08:15:13.911945 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/
> ckanserviceprovider/util.py", line 58, in emit
> [Tue Jan 09 08:15:13.911948 2018] [wsgi:error] [pid 9913]
> lineno=record.lineno))
> [Tue Jan 09 08:15:13.911951 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 945, in execute
> [Tue Jan 09 08:15:13.911953 2018] [wsgi:error] [pid 9913] return
> meth(self, multiparams, params)
> [Tue Jan 09 08:15:13.911956 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/sql/
> elements.py", line 263, in _execute_on_connection
> [Tue Jan 09 08:15:13.911959 2018] [wsgi:error] [pid 9913] return
> connection._execute_clauseelement(self, multiparams, params)
> [Tue Jan 09 08:15:13.911961 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1053, in _execute_clauseelement
> [Tue Jan 09 08:15:13.911964 2018] [wsgi:error] [pid 9913]
> compiled_sql, distilled_params
> [Tue Jan 09 08:15:13.911967 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1209, in _execute_context
> [Tue Jan 09 08:15:13.911969 2018] [wsgi:error] [pid 9913]
> self._root._commit_impl(autocommit=True)
> [Tue Jan 09 08:15:13.911972 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 723, in _commit_impl
> [Tue Jan 09 08:15:13.911974 2018] [wsgi:error] [pid 9913]
> self._handle_dbapi_exception(e, None, None, None, None)
> [Tue Jan 09 08:15:13.911977 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 1402, in _handle_dbapi_exception
> [Tue Jan 09 08:15:13.911989 2018] [wsgi:error] [pid 9913] exc_info
> [Tue Jan 09 08:15:13.911992 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/util/
> compat.py", line 203, in raise_from_cause
> [Tue Jan 09 08:15:13.911995 2018] [wsgi:error] [pid 9913]
> reraise(type(exception), exception, tb=exc_tb, cause=cause)
> [Tue Jan 09 08:15:13.911997 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/base.py", line 721, in _commit_impl
> [Tue Jan 09 08:15:13.912000 2018] [wsgi:error] [pid 9913]
> self.engine.dialect.do_commit(self.connection)
> [Tue Jan 09 08:15:13.912002 2018] [wsgi:error] [pid 9913] File "/
> usr/lib/ckan/datapusher/lib/python2.7/site-packages/sqlalchemy/
> engine/default.py", line 443, in do_commit
> [Tue Jan 09 08:15:13.912005 2018] [wsgi:error] [pid 9913]
> dbapi_connection.commit()
> [Tue Jan 09 08:15:13.912008 2018] [wsgi:error] [pid 9913]
> OperationalError: (sqlite3.OperationalError) database is locked
> -----
>
> The timestamps of these messages match the time that I've updated
> the resource, so I'm assuming that these belong to the stuck job. I
> don't know enough about the DataStore / DataPusher internals to
> really understand what's going on.
>
> How can I resubmit that job so that the resource data is
> successfully uploaded to the DataStore?
>
>
> Best regards,
> Florian _______________________________________________
> ckan-dev mailing list
> ckan-dev at lists.okfn.org
> https://lists.okfn.org/mailman/listinfo/ckan-dev
> Unsubscribe: https://lists.okfn.org/mailman/options/ckan-dev
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.okfn.org/pipermail/ckan-dev/attachments/20180109/bc156d2d/attachment-0003.html>
More information about the ckan-dev
mailing list