Post-save filter not running when using the Postgresql back-end

[Carlo Hamalainen]

Hi,

I am testing experiment ingestion using the atom provider. Everything
works fine when I use an sqlite3 database, but when I flip to Postgresql
I see that the filter's __init__ method is called but the __call__
method is never called. So in my case I get the experiment's files in
MyTardis but no metadata is added.

The weird thing is that I can't see any errors. I've checked the celery
log (loglevel DEBUG), the postgresql log, django's log (I'm running in
debug mode with runserver). Nothing odd appears anywhere.

Are there any known issues with django/celery not starting tasks? Any
ideas on how I can debug this?

Thanks,

--
Carlo Hamalainen
http://carlo-hamalainen.net

[Carlo Hamalainen]

On 14/07/14 08:41, Carlo Hamalainen wrote:
> Are there any known issues with django/celery not starting tasks? Any
> ideas on how I can debug this?

I think I've found the problem - the data files are not in the verified
state when the post-save hook is called. I tweaked filters/__init__.py:

67 # This hook dispatches a datafile save to a datafile filter.
68 # We only dispatch to the filter if the datafile's preferred
69 # replica is verified.
70 def make_datafile_hook(dfh):
71 def datafile_hook(**kw):
72 datafile = kw.get('instance')
73 if datafile.get_preferred_replica(verified=True):
74 logger.debug('ZZZ: datafile is verified,
calling dfh...')
75 dfh(**kw)
76 else:
77 logger.debug('ZZZ: datafile is NOT verified,
NOT calling dfh...')
78 return datafile_hook
79 logger.debug('ZZZ Creating hook for: ' + str((cls, args,
kw,)))
80 datafile_hook =
make_datafile_hook(self._safe_import(cls, args, kw))

and in my logs I see

/var/log/tardis-test.log:[14/Jul/2014 09:20:34] DEBUG __init__
__init__ ZZZ Creating hook for:
('tardis.tardis_portal.filters.dicom.dicompng.make_filter', ['metablob',
'http://cai.uq.edu.au/schema/metadata/1'], {})
/var/log/tardis-test.log:[14/Jul/2014 09:20:37] DEBUG __init__
__init__ ZZZ Creating hook for:
('tardis.tardis_portal.filters.dicom.dicompng.make_filter', ['metablob',
'http://cai.uq.edu.au/schema/metadata/1'], {})
/var/log/tardis-test.log:[14/Jul/2014 09:21:05] DEBUG __init__
datafile_hook ZZZ: datafile is NOT verified, NOT calling dfh...
/var/log/tardis-test.log:[14/Jul/2014 09:21:05] DEBUG __init__
datafile_hook ZZZ: datafile is NOT verified, NOT calling dfh...
/var/log/tardis-test.log:[14/Jul/2014 09:21:05] DEBUG __init__
datafile_hook ZZZ: datafile is NOT verified, NOT calling dfh...
/var/log/tardis-test.log:[14/Jul/2014 09:21:05] DEBUG __init__
datafile_hook ZZZ: datafile is NOT verified, NOT calling dfh...


The odd thing is that when I look at the Replicas table using the
MyTardis admin interface, I see verified=True for each file. So maybe
this is a timing issue with Postgresql?

[James Wettenhall]

Hi Carlo,

On 14 July 2014 09:23, Carlo Hamalainen <carlo.ham...@gmail.com> wrote:

On 14/07/14 08:41, Carlo Hamalainen wrote:
> Are there any known issues with django/celery not starting tasks? Any
> ideas on how I can debug this?

Which version of the atom ingest app (mytardis-app-atom) are you using?  Does your atom_ingest.py's make_local_copy use "reverify=True"?  See: https://github.com/wettenhj/mytardis-app-atom/blob/cvl_master/atom_ingest.py#L296

Do your post_save hooks work OK when you upload data manually through the web interface, rather than using the atom ingestion?

Do your filters work OK when you run bin/django runfilters from the command-line?

tardis/apps/atom/atom_ingest.py's "make_local_copy" method calls tardis/tardis_portal/tasks.py's "verify_replica" method, which for atom-ingested data calls tardis/tardis_portal/staging.py's "stage_replica" method, which does an "update" on the Replica object, not a "save", so the post_save filter might not be triggered.

Maybe you need to add "replica.save(update_fields=['verified'])" immediately after "stage_replica(replica)" in tardis/tardis_portal/tasks.py's verify_replica method?

Cheers,

James

[Carlo Hamalainen]

On 14/07/14 14:54, James Wettenhall wrote:
> Which version of the atom ingest app (mytardis-app-atom) are you
> using? Does your atom_ingest.py's make_local_copy use
> "reverify=True"?
> See: https://github.com/wettenhj/mytardis-app-atom/blob/cvl_master/atom_ingest.py#L296

I was using that branch but my fork was a few days behind (I forked it
just to disable the email feature temporarily for testing). I updated my
fork and now the post-save hooks run. Thanks.

For the sake of the list archive, this is James' commit that fixed my
problem:
https://github.com/wettenhj/mytardis-app-atom/commit/f498c5ceb40de8e092dc4fea378db141408ffbc0