data.py 43.8 KB
Newer Older
Markus Scheidgen's avatar
Markus Scheidgen committed
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
# Copyright 2018 Markus Scheidgen
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
#   http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an"AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.

"""
This module comprises a set of persistent document classes that hold all user related
data. These are information about users, their uploads and datasets, the associated
calculations, and files


.. autoclass:: Calc
Markus Scheidgen's avatar
Markus Scheidgen committed
22

Markus Scheidgen's avatar
Markus Scheidgen committed
23
.. autoclass:: Upload
Markus Scheidgen's avatar
Markus Scheidgen committed
24

Markus Scheidgen's avatar
Markus Scheidgen committed
25
26
"""

Markus Scheidgen's avatar
Markus Scheidgen committed
27
from typing import cast, List, Any, ContextManager, Tuple, Generator, Dict, cast
28
from mongoengine import StringField, DateTimeField, DictField, BooleanField, IntField
Markus Scheidgen's avatar
Markus Scheidgen committed
29
import logging
30
from structlog import wrap_logger
31
from contextlib import contextmanager
32
import os.path
33
34
from datetime import datetime
from pymongo import UpdateOne
35
import hashlib
36
from structlog.processors import StackInfoRenderer, format_exc_info, TimeStamper, JSONRenderer
Markus Scheidgen's avatar
Markus Scheidgen committed
37

38
from nomad import utils, config, infrastructure, search, datamodel
39
from nomad.files import PathObject, UploadFiles, ExtractError, ArchiveBasedStagingUploadFiles, PublicUploadFiles, StagingUploadFiles
40
from nomad.processing.base import Proc, process, task, PENDING, SUCCESS, FAILURE
41
from nomad.parsing import parser_dict, match_parser, LocalBackend
Markus Scheidgen's avatar
Markus Scheidgen committed
42
from nomad.normalizing import normalizers
43
from nomad.datamodel import UploadWithMetadata, Domain
Markus Scheidgen's avatar
Markus Scheidgen committed
44
45


46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
def _pack_log_event(logger, method_name, event_dict):
    try:
        log_data = dict(event_dict)
        log_data.update(**{
            key: value
            for key, value in getattr(logger, '_context', {}).items()
            if key not in ['service', 'release', 'upload_id', 'calc_id', 'mainfile', 'process_status']})
        log_data.update(level=method_name.upper(), logger=logger.name)

        return log_data
    except Exception:
        # raising an exception would cause an indefinite loop
        return event_dict


_log_processors = [
    StackInfoRenderer(),
    _pack_log_event,
    format_exc_info,
    TimeStamper(fmt="%Y-%m-%d %H:%M.%S", utc=False),
    JSONRenderer(sort_keys=True)]


Markus Scheidgen's avatar
Markus Scheidgen committed
69
class Calc(Proc):
Markus Scheidgen's avatar
Markus Scheidgen committed
70
71
72
73
74
75
    """
    Instances of this class represent calculations. This class manages the elastic
    search index entry, files, and archive for the respective calculation.

    It also contains the calculations processing and its state.

76
77
    The attribute list, does not include the various metadata properties generated
    while parsing, including ``code_name``, ``code_version``, etc.
Markus Scheidgen's avatar
Markus Scheidgen committed
78
79

    Attributes:
80
        calc_id: the calc_id of this calc
Markus Scheidgen's avatar
Markus Scheidgen committed
81
82
83
        parser: the name of the parser used to process this calc
        upload_id: the id of the upload used to create this calculation
        mainfile: the mainfile (including path in upload) that was used to create this calc
84

85
        metadata: the metadata record wit calc and user metadata, see :class:`datamodel.CalcWithMetadata`
Markus Scheidgen's avatar
Markus Scheidgen committed
86
    """
87
    calc_id = StringField(primary_key=True)
Markus Scheidgen's avatar
Markus Scheidgen committed
88
89
90
91
    upload_id = StringField()
    mainfile = StringField()
    parser = StringField()

92
93
    metadata = DictField()

Markus Scheidgen's avatar
Markus Scheidgen committed
94
    meta: Any = {
Markus Scheidgen's avatar
Markus Scheidgen committed
95
        'indexes': [
96
97
98
99
            'upload_id',
            ('upload_id', 'mainfile'),
            ('upload_id', 'parser'),
            ('upload_id', 'tasks_status'),
100
            ('upload_id', 'process_status'),
101
102
103
            ('upload_id', 'metadata.nomad_version'),
            'metadata.published',
            'metadata.datasets'
Markus Scheidgen's avatar
Markus Scheidgen committed
104
            'metadata.pid'
Markus Scheidgen's avatar
Markus Scheidgen committed
105
106
107
108
109
        ]
    }

    def __init__(self, *args, **kwargs):
        super().__init__(*args, **kwargs)
110
        self._parser_backend: LocalBackend = None
111
112
        self._upload: Upload = None
        self._upload_files: ArchiveBasedStagingUploadFiles = None
113
        self._calc_proc_logwriter = None
114
        self._calc_proc_logwriter_ctx: ContextManager = None
Markus Scheidgen's avatar
Markus Scheidgen committed
115

116
117
118
119
120
121
122
123
124
125
    @classmethod
    def from_calc_with_metadata(cls, calc_with_metadata):
        calc = Calc.create(
            calc_id=calc_with_metadata.calc_id,
            upload_id=calc_with_metadata.upload_id,
            mainfile=calc_with_metadata.mainfile,
            metadata=calc_with_metadata.to_dict())

        return calc

Markus Scheidgen's avatar
Markus Scheidgen committed
126
127
    @classmethod
    def get(cls, id):
128
        return cls.get_by_id(id, 'calc_id')
Markus Scheidgen's avatar
Markus Scheidgen committed
129

Markus Scheidgen's avatar
Markus Scheidgen committed
130
    @property
131
132
    def mainfile_file(self) -> PathObject:
        return self.upload_files.raw_file_object(self.mainfile)
Markus Scheidgen's avatar
Markus Scheidgen committed
133

134
135
136
137
    @property
    def upload(self) -> 'Upload':
        if not self._upload:
            self._upload = Upload.get(self.upload_id)
138
            self._upload.worker_hostname = self.worker_hostname
139
140
        return self._upload

141
142
143
    @property
    def upload_files(self) -> ArchiveBasedStagingUploadFiles:
        if not self._upload_files:
144
145
            self._upload_files = ArchiveBasedStagingUploadFiles(
                self.upload_id, is_authorized=lambda: True, upload_path=self.upload.upload_path)
146
147
        return self._upload_files

Markus Scheidgen's avatar
Markus Scheidgen committed
148
    def get_logger(self, **kwargs):
149
150
151
152
        """
        Returns a wrapped logger that additionally saves all entries to the calculation
        processing log in the archive.
        """
153
154
155
        logger = super().get_logger()
        logger = logger.bind(
            upload_id=self.upload_id, mainfile=self.mainfile, calc_id=self.calc_id, **kwargs)
156

157
        if self._calc_proc_logwriter_ctx is None:
158
159
160
161
162
163
164
165
166
167
168
169
            try:
                self._calc_proc_logwriter_ctx = self.upload_files.archive_log_file(self.calc_id, 'wt')
                self._calc_proc_logwriter = self._calc_proc_logwriter_ctx.__enter__()  # pylint: disable=E1101
            except KeyError:
                # cannot open log file
                pass

        if self._calc_proc_logwriter_ctx is None:
            return logger
        else:
            def save_to_calc_log(logger, method_name, event_dict):
                if self._calc_proc_logwriter is not None:
170
171
172
                    try:
                        self._calc_proc_logwriter.write(event_dict)
                        self._calc_proc_logwriter.write('\n')
173

174
175
176
                    except Exception:
                        # Exceptions here will cause indefinite loop
                        pass
177
178
179

                return event_dict

180
            return wrap_logger(logger, processors=_log_processors + [save_to_calc_log])
181

182
183
184
185
186
187
188
189
190
191
    @process
    def re_process_calc(self):
        """
        Processes a calculation again. This means there is already metadata and
        instead of creating it initially, we are just updating the existing
        records.
        """
        logger = self.get_logger()

        try:
192
193
194
195
196
197
198
            calc_with_metadata = datamodel.CalcWithMetadata(**self.metadata)
            calc_with_metadata.upload_id = self.upload_id
            calc_with_metadata.calc_id = self.calc_id
            calc_with_metadata.calc_hash = self.upload_files.calc_hash(self.mainfile)
            calc_with_metadata.mainfile = self.mainfile
            calc_with_metadata.nomad_version = config.version
            calc_with_metadata.nomad_commit = config.commit
199
            calc_with_metadata.last_processing = datetime.utcnow()
200
            calc_with_metadata.files = self.upload_files.calc_files(self.mainfile)
201
            self.metadata = calc_with_metadata.to_dict()
202
203
204
205
206
207
208
209
210
211
212
213
214

            self.parsing()
            self.normalizing()
            self.archiving()
        finally:
            # close loghandler that was not closed due to failures
            try:
                if self._calc_proc_logwriter is not None:
                    self._calc_proc_logwriter.close()
                    self._calc_proc_logwriter = None
            except Exception as e:
                logger.error('could not close calculation proc log', exc_info=e)

Markus Scheidgen's avatar
Markus Scheidgen committed
215
    @process
216
    def process_calc(self):
217
218
219
220
        """
        Processes a new calculation that has no prior records in the mongo, elastic,
        or filesystem storage. It will create an initial set of (user) metadata.
        """
221
        logger = self.get_logger()
222
        if self.upload is None:
223
            logger.error('calculation upload does not exist')
Markus Scheidgen's avatar
Markus Scheidgen committed
224
225

        try:
226
227
            # save preliminary minimum calc metadata in case processing fails
            # successful processing will replace it with the actual metadata
228
            calc_with_metadata = datamodel.CalcWithMetadata(
229
230
231
232
233
                upload_id=self.upload_id,
                calc_id=self.calc_id,
                calc_hash=self.upload_files.calc_hash(self.mainfile),
                mainfile=self.mainfile)
            calc_with_metadata.published = False
234
            calc_with_metadata.uploader = self.upload.user_id
235
            calc_with_metadata.upload_time = self.upload.upload_time
236
            calc_with_metadata.upload_name = self.upload.name
237
            calc_with_metadata.nomad_version = config.version
238
            calc_with_metadata.nomad_commit = config.commit
239
            calc_with_metadata.last_processing = datetime.utcnow()
240
241
242
            calc_with_metadata.files = self.upload_files.calc_files(self.mainfile)
            self.metadata = calc_with_metadata.to_dict()

243
244
245
246
247
            if len(calc_with_metadata.files) >= config.auxfile_cutoff:
                self.warning(
                    'This calc has many aux files in its directory. '
                    'Have you placed many calculations in the same directory?')

Markus Scheidgen's avatar
Markus Scheidgen committed
248
249
250
251
            self.parsing()
            self.normalizing()
            self.archiving()
        finally:
Markus Scheidgen's avatar
Markus Scheidgen committed
252
            # close loghandler that was not closed due to failures
253
            try:
254
255
256
                if self._calc_proc_logwriter is not None:
                    self._calc_proc_logwriter.close()
                    self._calc_proc_logwriter = None
257
258
259
            except Exception as e:
                logger.error('could not close calculation proc log', exc_info=e)

260
261
262
263
    def fail(self, *errors, log_level=logging.ERROR, **kwargs):
        # in case of failure, index a minimum set of metadata and mark
        # processing failure
        try:
264
            calc_with_metadata = datamodel.CalcWithMetadata(**self.metadata)
265
266
267
268
269
270
271
272
            calc_with_metadata.formula = config.services.not_processed_value
            calc_with_metadata.basis_set = config.services.not_processed_value
            calc_with_metadata.xc_functional = config.services.not_processed_value
            calc_with_metadata.system = config.services.not_processed_value
            calc_with_metadata.crystal_system = config.services.not_processed_value
            calc_with_metadata.spacegroup = config.services.not_processed_value
            calc_with_metadata.spacegroup_symbol = config.services.not_processed_value
            calc_with_metadata.code_version = config.services.not_processed_value
273
274
275
276
277
278
279

            calc_with_metadata.code_name = config.services.not_processed_value
            if self.parser is not None:
                parser = parser_dict[self.parser]
                if hasattr(parser, 'code_name'):
                    calc_with_metadata.code_name = parser.code_name

280
281
282
283
284
285
286
287
            calc_with_metadata.processed = False
            self.metadata = calc_with_metadata.to_dict()
            search.Entry.from_calc_with_metadata(calc_with_metadata).save()
        except Exception as e:
            self.get_logger().error('could not index after processing failure', exc_info=e)

        super().fail(*errors, log_level=log_level, **kwargs)

288
289
290
291
    def on_process_complete(self, process_name):
        # the save might be necessary to correctly read the join condition from the db
        self.save()
        # in case of error, the process_name might be unknown
292
        if process_name == 'process_calc' or process_name == 're_process_calc' or process_name is None:
293
294
            self.upload.reload()
            self.upload.check_join()
Markus Scheidgen's avatar
Markus Scheidgen committed
295
296
297

    @task
    def parsing(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
298
        """ The *task* that encapsulates all parsing related actions. """
299
        context = dict(parser=self.parser, step=self.parser)
300
        logger = self.get_logger(**context)
301
        parser = parser_dict[self.parser]
302
        self.metadata['parser_name'] = self.parser
Markus Scheidgen's avatar
Markus Scheidgen committed
303

304
        with utils.timer(logger, 'parser executed', input_size=self.mainfile_file.size):
305
306
307
308
            try:
                self._parser_backend = parser.run(
                    self.upload_files.raw_file_object(self.mainfile).os_path, logger=logger)
            except Exception as e:
309
                self.fail('parser failed with exception', exc_info=e, error=str(e), **context)
310
                return
311
            except SystemExit:
312
                self.fail('parser raised system exit', error='system exit', **context)
313
                return
Markus Scheidgen's avatar
Markus Scheidgen committed
314

315
316
        # add the non code specific calc metadata to the backend
        # all other quantities have been determined by parsers/normalizers
317
        self._parser_backend.openNonOverlappingSection('section_entry_info')
318
        self._parser_backend.addValue('upload_id', self.upload_id)
319
        self._parser_backend.addValue('calc_id', self.calc_id)
320
        self._parser_backend.addValue('calc_hash', self.metadata['calc_hash'])
321
        self._parser_backend.addValue('mainfile', self.mainfile)
322
        self._parser_backend.addValue('parser_name', self.parser)
323
324
325
326
327
328
329
330
331
332
333
334
        filepaths = self.metadata['files']
        self._parser_backend.addValue('number_of_files', len(filepaths))
        self._parser_backend.addValue('filepaths', filepaths)
        uploader = self.upload.uploader
        self._parser_backend.addValue(
            'entry_uploader_name', '%s, %s' % (uploader.first_name, uploader.last_name))
        self._parser_backend.addValue(
            'entry_uploader_id', str(uploader.user_id))
        self._parser_backend.addValue('entry_upload_time', int(self.upload.upload_time.timestamp()))
        self._parser_backend.closeNonOverlappingSection('section_entry_info')

        self.add_processor_info(self.parser)
335

Markus Scheidgen's avatar
Markus Scheidgen committed
336
337
        if self._parser_backend.status[0] != 'ParseSuccess':
            error = self._parser_backend.status[1]
338
            self.fail('parser failed', error=error, **context)
339
340
341
342
343
344
345
346

    @contextmanager
    def use_parser_backend(self, processor_name):
        self._parser_backend.reset_status()
        yield self._parser_backend
        self.add_processor_info(processor_name)

    def add_processor_info(self, processor_name: str) -> None:
347
        self._parser_backend.openContext('/section_entry_info/0')
348
349
350
351
352
353
354
        self._parser_backend.openNonOverlappingSection('section_archive_processing_info')
        self._parser_backend.addValue('archive_processor_name', processor_name)

        if self._parser_backend.status[0] == 'ParseSuccess':
            warnings = getattr(self._parser_backend, '_warnings', [])
            if len(warnings) > 0:
                self._parser_backend.addValue('archive_processor_status', 'WithWarnings')
355
                self._parser_backend.addValue('number_of_archive_processor_warnings', len(warnings))
356
357
358
359
                self._parser_backend.addArrayValues('archive_processor_warnings', [str(warning) for warning in warnings])
            else:
                self._parser_backend.addValue('archive_processor_status', 'Success')
        else:
360
            errors = self._parser_backend.status[1]
361
362
363
            self._parser_backend.addValue('archive_processor_error', str(errors))

        self._parser_backend.closeNonOverlappingSection('section_archive_processing_info')
364
        self._parser_backend.closeContext('/section_entry_info/0')
Markus Scheidgen's avatar
Markus Scheidgen committed
365
366
367

    @task
    def normalizing(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
368
        """ The *task* that encapsulates all normalizing related actions. """
Markus Scheidgen's avatar
Markus Scheidgen committed
369
        for normalizer in normalizers:
370
371
372
            if normalizer.domain != config.domain:
                continue

Markus Scheidgen's avatar
Markus Scheidgen committed
373
            normalizer_name = normalizer.__name__
374
            context = dict(normalizer=normalizer_name, step=normalizer_name)
375
            logger = self.get_logger(**context)
Markus Scheidgen's avatar
Markus Scheidgen committed
376
377

            with utils.timer(
378
                    logger, 'normalizer executed', input_size=self.mainfile_file.size):
379
                with self.use_parser_backend(normalizer_name) as backend:
380
381
382
                    try:
                        normalizer(backend).normalize(logger=logger)
                    except Exception as e:
383
                        self._parser_backend.finishedParsingSession('ParseFailure', [str(e)])
384
                        self.fail(
385
386
387
388
389
390
391
392
393
394
                            'normalizer failed with exception', exc_info=e, error=str(e), **context)
                        break
                    else:
                        if self._parser_backend.status[0] != 'ParseSuccess':
                            error = self._parser_backend.status[1]
                            self.fail('normalizer failed', error=error, **context)
                            break
                        else:
                            logger.debug(
                                'completed normalizer successfully', normalizer=normalizer_name)
Markus Scheidgen's avatar
Markus Scheidgen committed
395
396
397

    @task
    def archiving(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
398
        """ The *task* that encapsulates all archival related actions. """
399
400
        logger = self.get_logger()

401
        calc_with_metadata = datamodel.CalcWithMetadata(**self.metadata)
402
        calc_with_metadata.apply_domain_metadata(self._parser_backend)
403
        calc_with_metadata.processed = True
404

405
406
        # persist the calc metadata
        with utils.timer(logger, 'saved calc metadata', step='metadata'):
407
            self.metadata = calc_with_metadata.to_dict()
408
409

        # index in search
410
        with utils.timer(logger, 'indexed', step='index'):
411
            search.Entry.from_calc_with_metadata(calc_with_metadata).save()
412

413
        # persist the archive
Markus Scheidgen's avatar
Markus Scheidgen committed
414
        with utils.timer(
415
                logger, 'archived', step='archive',
Markus Scheidgen's avatar
Markus Scheidgen committed
416
                input_size=self.mainfile_file.size) as log_data:
417
            with self.upload_files.archive_file(self.calc_id, 'wt') as out:
418
                self._parser_backend.write_json(out, pretty=True, root_sections=Domain.instance.root_sections)
419

420
            log_data.update(archive_size=self.upload_files.archive_file_object(self.calc_id).size)
Markus Scheidgen's avatar
Markus Scheidgen committed
421
422
423
424

        # close loghandler
        if self._calc_proc_logwriter is not None:
            with utils.timer(
425
                    logger, 'archived log', step='logs',
Markus Scheidgen's avatar
Markus Scheidgen committed
426
                    input_size=self.mainfile_file.size) as log_data:
427
                self._calc_proc_logwriter_ctx.__exit__(None, None, None)  # pylint: disable=E1101
428
                self._calc_proc_logwriter = None
Markus Scheidgen's avatar
Markus Scheidgen committed
429

430
                log_data.update(log_size=self.upload_files.archive_log_file_object(self.calc_id).size)
Markus Scheidgen's avatar
Markus Scheidgen committed
431

432
    def __str__(self):
433
        return 'calc %s calc_id=%s upload_id%s' % (super().__str__(), self.calc_id, self.upload_id)
434

435

436
class Upload(Proc):
Markus Scheidgen's avatar
Markus Scheidgen committed
437
438
439
440
441
442
    """
    Represents uploads in the databases. Provides persistence access to the files storage,
    and processing state.

    Attributes:
        name: optional user provided upload name
443
444
        upload_path: the path were the uploaded files was stored
        temporary: True if the uploaded file should be removed after extraction
Markus Scheidgen's avatar
Markus Scheidgen committed
445
446
        upload_id: the upload id generated by the database
        upload_time: the timestamp when the system realised the upload
447
        user_id: the id of the user that created this upload
Markus Scheidgen's avatar
Markus Scheidgen committed
448
449
        published: Boolean that indicates the publish status
        publish_time: Date when the upload was initially published
450
        last_update: Date of the last publishing/re-processing
Markus Scheidgen's avatar
Markus Scheidgen committed
451
        joined: Boolean indicates if the running processing has joined (:func:`check_join`)
Markus Scheidgen's avatar
Markus Scheidgen committed
452
453
454
455
    """
    id_field = 'upload_id'

    upload_id = StringField(primary_key=True)
456
457
    upload_path = StringField(default=None)
    temporary = BooleanField(default=False)
458
    embargo_length = IntField(default=36)
Markus Scheidgen's avatar
Markus Scheidgen committed
459
460
461

    name = StringField(default=None)
    upload_time = DateTimeField()
462
    user_id = StringField(required=True)
463
464
    published = BooleanField(default=False)
    publish_time = DateTimeField()
465
    last_update = DateTimeField()
Markus Scheidgen's avatar
Markus Scheidgen committed
466

467
468
    joined = BooleanField(default=False)

Markus Scheidgen's avatar
Markus Scheidgen committed
469
470
    meta: Any = {
        'indexes': [
471
            'user_id', 'tasks_status', 'process_status', 'published', 'upload_time'
Markus Scheidgen's avatar
Markus Scheidgen committed
472
473
474
475
476
        ]
    }

    def __init__(self, **kwargs):
        super().__init__(**kwargs)
477
        self._upload_files: ArchiveBasedStagingUploadFiles = None
Markus Scheidgen's avatar
Markus Scheidgen committed
478

479
480
    @property
    def metadata(self) -> dict:
Markus Scheidgen's avatar
Markus Scheidgen committed
481
482
483
484
485
486
487
        """
        Getter, setter for user metadata. Metadata is pickled to and from the public
        bucket to allow sharing among all processes. Usually uploads do not have (much)
        user defined metadata, but users provide all metadata per upload as part of
        the publish process. This will change, when we introduce editing functionality
        and metadata will be provided through different means.
        """
488
489
490
491
492
        try:
            upload_files = PublicUploadFiles(self.upload_id, is_authorized=lambda: True)
        except KeyError:
            return None
        return upload_files.user_metadata
493
494
495

    @metadata.setter
    def metadata(self, data: dict) -> None:
496
497
        upload_files = PublicUploadFiles(self.upload_id, is_authorized=lambda: True, create=True)
        upload_files.user_metadata = data
498

Markus Scheidgen's avatar
Markus Scheidgen committed
499
    @classmethod
500
    def get(cls, id: str, include_published: bool = True) -> 'Upload':
501
        return cls.get_by_id(id, 'upload_id')
Markus Scheidgen's avatar
Markus Scheidgen committed
502
503

    @classmethod
504
    def user_uploads(cls, user: datamodel.User, **kwargs) -> List['Upload']:
505
506
        """ Returns all uploads for the given user. Kwargs are passed to mongo query. """
        return cls.objects(user_id=str(user.user_id), **kwargs)
Markus Scheidgen's avatar
Markus Scheidgen committed
507

508
509
    @property
    def uploader(self):
510
        return datamodel.User.get(self.user_id)
511

Markus Scheidgen's avatar
Markus Scheidgen committed
512
513
    def get_logger(self, **kwargs):
        logger = super().get_logger()
514
515
516
517
518
        user = self.uploader
        user_name = '%s %s' % (user.first_name, user.last_name)
        logger = logger.bind(
            upload_id=self.upload_id, upload_name=self.name, user_name=user_name,
            user_id=user.user_id, **kwargs)
Markus Scheidgen's avatar
Markus Scheidgen committed
519
520
521
522
523
524
525
526
        return logger

    @classmethod
    def create(cls, **kwargs) -> 'Upload':
        """
        Creates a new upload for the given user, a user given name is optional.
        It will populate the record with a signed url and pending :class:`UploadProc`.
        The upload will be already saved to the database.
527
528

        Arguments:
529
            user: The user that created the upload.
Markus Scheidgen's avatar
Markus Scheidgen committed
530
        """
531
532
        # use kwargs to keep compatibility with super method
        user: datamodel.User = kwargs['user']
533
        del(kwargs['user'])
534

535
536
        if 'upload_id' not in kwargs:
            kwargs.update(upload_id=utils.create_uuid())
537
        kwargs.update(user_id=user.user_id)
Markus Scheidgen's avatar
Markus Scheidgen committed
538
        self = super().create(**kwargs)
539

Markus Scheidgen's avatar
Markus Scheidgen committed
540
        self._continue_with('uploading')
541

Markus Scheidgen's avatar
Markus Scheidgen committed
542
543
        return self

544
545
546
547
548
    def delete(self):
        """ Deletes this upload process state entry and its calcs. """
        Calc.objects(upload_id=self.upload_id).delete()
        super().delete()

549
    def delete_upload_local(self):
550
        """
551
        Deletes the upload, including its processing state and
552
        staging files. Local version without celery processing.
553
554
555
556
        """
        logger = self.get_logger()

        with utils.lnr(logger, 'staged upload delete failed'):
557
            with utils.timer(
558
                    logger, 'upload deleted from index', step='index',
559
                    upload_size=self.upload_files.size):
560
                search.delete_upload(self.upload_id)
561

562
            with utils.timer(
563
                    logger, 'staged upload deleted', step='files',
564
565
                    upload_size=self.upload_files.size):
                self.upload_files.delete()
566
567

            self.delete()
568

569
    @process
570
    def delete_upload(self):
571
572
573
574
        """
        Deletes of the upload, including its processing state and
        staging files. This starts the celery process of deleting the upload.
        """
575
        self.delete_upload_local()
576

577
        return True  # do not save the process status on the delete upload
578

579
    @process
580
    def publish_upload(self):
581
        """
582
583
        Moves the upload out of staging to the public area. It will
        pack the staging upload files in to public upload files.
584
        """
585
586
        assert self.processed_calcs > 0

587
        logger = self.get_logger()
588
        logger.info('started to publish')
589

590
        with utils.lnr(logger, 'publish failed'):
591
            upload_with_metadata = self.to_upload_with_metadata(self.metadata)
592
            calcs = upload_with_metadata.calcs
593

594
            with utils.timer(
595
                    logger, 'upload metadata updated', step='metadata',
596
                    upload_size=self.upload_files.size):
597
598

                def create_update(calc):
599
                    calc.published = True
600
                    calc.with_embargo = calc.with_embargo if calc.with_embargo is not None else False
601
602
603
604
605
                    return UpdateOne(
                        {'_id': calc.calc_id},
                        {'$set': {'metadata': calc.to_dict()}})

                Calc._get_collection().bulk_write([create_update(calc) for calc in calcs])
606

607
608
609
610
611
            if isinstance(self.upload_files, StagingUploadFiles):
                with utils.timer(
                        logger, 'staged upload files packed', step='pack',
                        upload_size=self.upload_files.size):
                    self.upload_files.pack(upload_with_metadata)
612
613
614
615

            with utils.timer(
                    logger, 'index updated', step='index',
                    upload_size=self.upload_files.size):
616
                search.publish(calcs)
617

618
619
620
621
622
623
            if isinstance(self.upload_files, StagingUploadFiles):
                with utils.timer(
                        logger, 'staged upload deleted', step='delete staged',
                        upload_size=self.upload_files.size):
                    self.upload_files.delete()
                    self.published = True
624
625
                    self.publish_time = datetime.utcnow()
                    self.last_update = datetime.utcnow()
626
627
                    self.save()
            else:
628
                self.last_update = datetime.utcnow()
629
                self.save()
630

631
632
633
    @process
    def re_process_upload(self):
        """
Markus Scheidgen's avatar
Markus Scheidgen committed
634
635
636
        A *process* that performs the re-processing of a earlier processed
        upload.

637
638
639
640
641
642
643
644
645
        Runs the distributed process of fully reparsing/renormalizing an existing and
        already published upload. Will renew the archive part of the upload and update
        mongo and elastic search entries.

        TODO this implementation does not do any re-matching. This will be more complex
        due to handling of new or missing matches.
        """
        assert self.published

646
647
648
        logger = self.get_logger()
        logger.info('started to re-process')

649
650
651
652
653
654
        # mock the steps of actual processing
        self._continue_with('uploading')

        # extract the published raw files into a staging upload files instance
        self._continue_with('extracting')
        public_upload_files = cast(PublicUploadFiles, self.upload_files)
655
        staging_upload_files = public_upload_files.to_staging_upload_files(create=True)
656
657

        self._continue_with('parse_all')
658
        try:
659
660
661
662
            # we use a copy of the mongo queryset; reasons are cursor timeouts and
            # changing results on modifying the calc entries
            calcs = list(Calc.objects(upload_id=self.upload_id))
            for calc in calcs:
663
664
665
666
667
668
669
670
                if calc.process_running:
                    if calc.current_process == 're_process_calc':
                        logger.warn('re_process_calc is already running', calc_id=calc.calc_id)
                    else:
                        logger.warn('a process is already running on calc', calc_id=calc.calc_id)

                    continue

671
                calc.reset(worker_hostname=self.worker_hostname)
672

673
                parser = match_parser(calc.mainfile, staging_upload_files, strict=False)
674
                if parser is None:
675
676
                    logger.error(
                        'no parser matches during re-process, use the old parser',
677
                        calc_id=calc.calc_id)
678
679
680
681
                elif calc.parser != parser.name:
                    calc.parser = parser.name
                    logger.info(
                        'different parser matches during re-process, use new parser',
682
                        calc_id=calc.calc_id, parser=parser.name)
683
684
685
                calc.re_process_calc()
        except Exception as e:
            # try to remove the staging copy in failure case
686
            if staging_upload_files is not None and staging_upload_files.exists():
687
688
689
                staging_upload_files.delete()

            raise e
690
691
692
693

        # the packing and removing of the staging upload files, will be trigged by
        # the 'cleanup' task after processing all calcs

694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
    @process
    def re_pack(self):
        """ A *process* that repacks the raw and archive data based on the current embargo data. """
        assert self.published

        # mock the steps of actual processing
        self._continue_with('uploading')
        self._continue_with('extracting')
        self._continue_with('parse_all')
        self._continue_with('cleanup')

        self.upload_files.re_pack(self.to_upload_with_metadata())
        self.joined = True
        self._complete()

Markus Scheidgen's avatar
Markus Scheidgen committed
709
    @process
710
    def process_upload(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
711
        """ A *process* that performs the initial upload processing. """
Markus Scheidgen's avatar
Markus Scheidgen committed
712
713
714
715
716
        self.extracting()
        self.parse_all()

    @task
    def uploading(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
717
        """ A no-op *task* as a stand-in for receiving upload data. """
Markus Scheidgen's avatar
Markus Scheidgen committed
718
719
        pass

720
    @property
721
722
    def upload_files(self) -> UploadFiles:
        upload_files_class = ArchiveBasedStagingUploadFiles if not self.published else PublicUploadFiles
723
        kwargs = dict(upload_path=self.upload_path) if not self.published else {}
724
725
726

        if not self._upload_files or not isinstance(self._upload_files, upload_files_class):
            self._upload_files = upload_files_class(
727
                self.upload_id, is_authorized=lambda: True, **kwargs)
728

729
        return self._upload_files
730

731
732
733
734
735
    @property
    def staging_upload_files(self) -> ArchiveBasedStagingUploadFiles:
        assert not self.published
        return cast(ArchiveBasedStagingUploadFiles, self.upload_files)

Markus Scheidgen's avatar
Markus Scheidgen committed
736
737
    @task
    def extracting(self):
738
        """
739
740
        The *task* performed before the actual parsing/normalizing: extracting
        the uploaded files.
741
        """
742
743
744
745
746
        # extract the uploaded file
        self._upload_files = ArchiveBasedStagingUploadFiles(
            upload_id=self.upload_id, is_authorized=lambda: True, create=True,
            upload_path=self.upload_path)

Markus Scheidgen's avatar
Markus Scheidgen committed
747
748
        logger = self.get_logger()
        try:
Markus Scheidgen's avatar
Markus Scheidgen committed
749
750
            with utils.timer(
                    logger, 'upload extracted', step='extracting',
751
752
                    upload_size=self.upload_files.size):
                self.upload_files.extract()
753
754
755
756

            if self.temporary:
                os.remove(self.upload_path)
                self.upload_path = None
757

758
        except KeyError:
759
            self.fail('processing requested for non existing upload', log_level=logging.ERROR)
760
761
762
            return
        except ExtractError:
            self.fail('bad .zip/.tar file', log_level=logging.INFO)
Markus Scheidgen's avatar
Markus Scheidgen committed
763
764
            return

765
766
767
768
769
    def _preprocess_files(self, path):
        """
        Some files need preprocessing. Currently we need to add a stripped POTCAR version
        and always restrict/embargo the original.
        """
770
        if os.path.basename(path).startswith('POTCAR'):
771
772
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
            # create checksum
            hash = hashlib.sha224()
            with open(self.staging_upload_files.raw_file_object(path).os_path, 'rb') as orig_f:
                for line in orig_f.readlines():
                    hash.update(line)

            checksum = hash.hexdigest()

            # created stripped POTCAR
            stripped_path = path + '.stripped'
            with open(self.staging_upload_files.raw_file_object(stripped_path).os_path, 'wt') as stripped_f:
                stripped_f.write('Stripped POTCAR file. Checksum of original file (sha224): %s\n' % checksum)
            os.system(
                '''
                    awk < %s >> %s '
                    BEGIN { dump=1 }
                    /End of Dataset/ { dump=1 }
                    dump==1 { print }
                    /END of PSCTR/ { dump=0 }'
                ''' % (
                    self.staging_upload_files.raw_file_object(path).os_path,
                    self.staging_upload_files.raw_file_object(stripped_path).os_path))

794
    def match_mainfiles(self) -> Generator[Tuple[str, object], None, None]:
795
796
797
798
799
800
801
        """
        Generator function that matches all files in the upload to all parsers to
        determine the upload's mainfiles.

        Returns:
            Tuples of mainfile, filename, and parsers
        """
802
        directories_with_match: Dict[str, str] = dict()
803
804
        upload_files = self.staging_upload_files
        for filename in upload_files.raw_file_manifest():
805
            self._preprocess_files(filename)
806
            try:
807
                parser = match_parser(filename, upload_files)
808
                if parser is not None:
809
810
                    directory = os.path.dirname(filename)
                    if directory in directories_with_match:
811
812
813
                        # TODO this might give us the chance to store directory based relationship
                        # between calcs for the future?
                        pass
814
815
                    else:
                        directories_with_match[directory] = filename
816
817

                    yield filename, parser
818
819
820
821
            except Exception as e:
                self.get_logger().error(
                    'exception while matching pot. mainfile',
                    mainfile=filename, exc_info=e)
822

Markus Scheidgen's avatar
Markus Scheidgen committed
823
824
    @task
    def parse_all(self):
825
        """
Markus Scheidgen's avatar
Markus Scheidgen committed
826
        The *task* used to identify mainfile/parser combinations among the upload's files, creates
827
828
        respective :class:`Calc` instances, and triggers their processing.
        """
829
830
        logger = self.get_logger()

Markus Scheidgen's avatar
Markus Scheidgen committed
831
832
        with utils.timer(
                logger, 'upload extracted', step='matching',
833
834
                upload_size=self.upload_files.size):
            for filename, parser in self.match_mainfiles():
835
                calc = Calc.create(
836
                    calc_id=self.upload_files.calc_id(filename),
837
                    mainfile=filename, parser=parser.name,
838
                    worker_hostname=self.worker_hostname,
839
840
                    upload_id=self.upload_id)

841
                calc.process_calc()
Markus Scheidgen's avatar
Markus Scheidgen committed
842

843
    def on_process_complete(self, process_name):
844
        if process_name == 'process_upload' or process_name == 're_process_upload':
845
846
847
            self.check_join()

    def check_join(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
848
849
850
851
852
853
854
855
        """
        Performs an evaluation of the join condition and triggers the :func:`cleanup`
        task if necessary. The join condition allows to run the ``cleanup`` after
        all calculations have been processed. The upload processing stops after all
        calculation processings have been triggered (:func:`parse_all` or
        :func:`re_process_upload`). The cleanup task is then run within the last
        calculation process (the one that triggered the join by calling this method).
        """
856
857
858
859
        total_calcs = self.total_calcs
        processed_calcs = self.processed_calcs

        self.get_logger().debug('check join', processed_calcs=processed_calcs, total_calcs=total_calcs)
860
861
        # check if process is not running anymore, i.e. not still spawining new processes to join
        # check the join condition, i.e. all calcs have been processed
862
        if not self.process_running and processed_calcs >= total_calcs:
863
            # this can easily be called multiple times, e.g. upload finished after all calcs finished
864
865
866
            modified_upload = self._get_collection().find_one_and_update(
                {'_id': self.upload_id, 'joined': {'$ne': True}},
                {'$set': {'joined': True}})
867
868
869
870
871
872
            if modified_upload is not None:
                self.get_logger().debug('join')
                self.cleanup()
            else:
                # the join was already done due to a prior call
                pass
873

874
875
876
    def reset(self):
        self.joined = False
        super().reset()
Markus Scheidgen's avatar
Markus Scheidgen committed
877

878
    def _cleanup_after_processing(self):
879
880
881
882
883
884
        # send email about process finish
        user = self.uploader
        name = '%s %s' % (user.first_name, user.last_name)
        message = '\n'.join([
            'Dear %s,' % name,
            '',
885
            'your data %suploaded at %s has completed processing.' % (
886
                '"%s" ' % self.name if self.name else '', self.upload_time.isoformat()),  # pylint: disable=no-member
887
            'You can review your data on your upload page: %s' % config.gui_url(),
888
889
890
891
            '',
            'If you encouter any issues with your upload, please let us know and replay to this email.',
            '',
            'The nomad team'
892
        ])
893
894
895
896
897
898
899
        try:
            infrastructure.send_mail(
                name=name, email=user.email, message=message, subject='Processing completed')
        except Exception as e:
            # probably due to email configuration problems
            # don't fail or present this error to clients
            self.logger.error('could not send after processing email', exc_info=e)
Markus Scheidgen's avatar
Markus Scheidgen committed
900

901
902
903
904
905
906
907
908
909
910
    def _cleanup_after_re_processing(self):
        logger = self.get_logger()
        logger.info('started to repack re-processed upload')

        staging_upload_files = self.upload_files.to_staging_upload_files()

        with utils.timer(
                logger, 'reprocessed staged upload packed', step='delete staged',
                upload_size=self.upload_files.size):

911
            staging_upload_files.pack(self.to_upload_with_metadata(), skip_raw=True)
912
913
914
915
916
917

        with utils.timer(
                logger, 'reprocessed staged upload deleted', step='delete staged',
                upload_size=self.upload_files.size):

            staging_upload_files.delete()
918
            self.last_update = datetime.utcnow()
919
920
921
922
            self.save()

    @task
    def cleanup(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
923
924
925
926
        """
        The *task* that "cleans" the processing, i.e. removed obsolete files and performs
        pending archival operations. Depends on the type of processing.
        """
927
928
929
930
931
932
933
        search.refresh()

        if self.current_process == 're_process_upload':
            self._cleanup_after_re_processing()
        else:
            self._cleanup_after_processing()

934
    def get_calc(self, calc_id) -> Calc:
Markus Scheidgen's avatar
Markus Scheidgen committed
935
        """ Returns the upload calc with the given id or ``None``. """
936
937
        return Calc.objects(upload_id=self.upload_id, calc_id=calc_id).first()

Markus Scheidgen's avatar
Markus Scheidgen committed
938
    @property
939
    def processed_calcs(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
940
941
942
943
        """
        The number of successfully or not successfully processed calculations. I.e.
        calculations that have finished processing.
        """
944
        return Calc.objects(upload_id=self.upload_id, tasks_status__in=[SUCCESS, FAILURE]).count()
945
946
947

    @property
    def total_calcs(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
948
        """ The number of all calculations. """
949
950
951
952
        return Calc.objects(upload_id=self.upload_id).count()

    @property
    def failed_calcs(self):
Markus Scheidgen's avatar
Markus Scheidgen committed
953
        """ The number of calculations with failed processing. """
954
        return Calc.objects(upload_id=self.upload_id, tasks_status=FAILURE).count()
955

956
    @property
Markus Scheidgen's avatar
Markus Scheidgen committed
957
958
    def pending_calcs(self) -> int:
        """ The number of calculations with pending processing. """
959
        return Calc.objects(upload_id=self.upload_id, tasks_status=PENDING).count()
960

961
    def all_calcs(self, start, end, order_by=None):
Markus Scheidgen's avatar
Markus Scheidgen committed
962
963
964
965
966
967
968
969
        """
        Returns all calculations, paginated and ordered.

        Arguments:
            start: the start index of the requested page
            end: the end index of the requested page
            order_by: the property to order by
        """
970
971
        query = Calc.objects(upload_id=self.upload_id)[start:end]
        return query.order_by(order_by) if order_by is not None else query
972