Validation error when accepting DukeDS transfer

[johnbradley]

The following error occurred when a user was accepting a transfer:

ERROR:django.request:Internal Server Error: /ownership/process/
Traceback (most recent call last):
  File "/app/ownership/views.py", line 169, in process_accept
    self.warning_message = self.delivery_type.transfer_delivery(delivery, request.user)
  File "/app/switchboard/dds_util.py", line 514, in transfer_delivery
    delivery_util.accept_project_transfer()
  File "/app/switchboard/dds_util.py", line 422, in accept_project_transfer
    self.dds_util.accept_project_transfer(self.delivery.transfer_id)
  File "/app/switchboard/dds_util.py", line 75, in accept_project_transfer
    return self.remote_store.data_service.accept_project_transfer(transfer_id).json()
  File "/usr/local/lib/python3.6/site-packages/ddsc/core/ddsapi.py", line 805, in accept_project_transfer
    return self._process_project_transfer('accept', transfer_id, status_comment)
  File "/usr/local/lib/python3.6/site-packages/ddsc/core/ddsapi.py", line 778, in _process_project_transfer
    return self._put(path, data, content_type=ContentType.form)
  File "/usr/local/lib/python3.6/site-packages/ddsc/core/ddsapi.py", line 41, in retry_function
    result = func(*args, **kwds)
  File "/usr/local/lib/python3.6/site-packages/ddsc/core/ddsapi.py", line 266, in _put
    return self._check_err(resp, url_suffix, data, allow_pagination=False)
  File "/usr/local/lib/python3.6/site-packages/ddsc/core/ddsapi.py", line 353, in _check_err
    raise DataServiceError(resp, url_suffix, data)
ddsc.core.ddsapi.DataServiceError: Error 400 on /project_transfers/0815f0b7-9f41-4f9e-9fb9-5c781a2afc77/accept
Reason:validation failed
Suggestion:Fix the following invalid fields and resubmit

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/exception.py", line 41, in inner
    response = get_response(request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 249, in _legacy_get_response
    response = self._get_response(request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 187, in _get_response
    response = self.process_exception_by_middleware(e, request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 185, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/contrib/auth/decorators.py", line 23, in _wrapped_view
    return view_func(request, *args, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/views/decorators/cache.py", line 57, in _wrapped_view_func
    response = view_func(request, *args, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 68, in view
    return self.dispatch(request, *args, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 88, in dispatch
    return handler(request, *args, **kwargs)
  File "/app/ownership/views.py", line 141, in post
    return self._action(request, self.handle_post)
  File "/app/ownership/views.py", line 133, in _action
    handle_method()
  File "/app/ownership/views.py", line 187, in handle_post
    self.process_accept()  # May override response type with an error
  File "/app/ownership/views.py", line 173, in process_accept
    self.set_error_details(500, 'Unable to transfer ownership: {}'.format(e.message))
AttributeError: 'DataServiceError' object has no attribute 'message'

It appears this transfer eventually worked and the user was able to accept the transfer.

I am not sure why the /project_transfers/0815f0b7-9f41-4f9e-9fb9-5c781a2afc77/accept would fail with a 400. We don't pass the optional message field. I am wondering if this problem is on the DukeDS side.

We can however fix the AttributeError that occurs when building a message for the user.

[johnbradley]

I heard back from the DukeDS team that this 400 error was because the transfer was already accepted. I think this might be due to the state of the project not being updated in the D4S2 database.

[johnbradley]

In the logs I also saw this error before the 400 error on project accept.

[2020-03-16 16:00:19 -0400] [16] [CRITICAL] WORKER TIMEOUT (pid:21)
[2020-03-16 20:00:19 +0000] [21] [INFO] Worker exiting (pid: 21)
[2020-03-16 16:00:19 -0400] [23] [INFO] Booting worker with pid: 23

[johnbradley]

I think this timeout occurred when sending emails. In the following code the sender_message email was sent but not the recipient_message and mark_accepted was not called.

https://github.com/Duke-GCB/D4S2/blob/536cd68261f41b79ad8f50e4b51fd4d7d199b190/switchboard/dds_util.py#L518-L527

We send emails with the django.core.mail.backends.smtp.EmailBackend. The default timeout is None for the EmailBackend is no timeout. In the short term we should set this timeout to a reasonable value to allow the user to properly accept a delivery even if SMTP is slow. Long term the email should be sent in a background thread/process.

[johnbradley]

This was fixed by #226