psqworker fails and can't be killed if GCS_MOUNT_DIR points to a non existing directory in a non writable parent

[rgayon]

[INFO] Starting PSQ listener on queue turbinia-psq
[INFO] Running Turbinia PSQ Worker.                                                                   
[INFO] Starting Task StatTask c45b770ca70b4c518a6970a67df6d2b8                                        
[INFO] Creating new directory /mnt/turbinia/output/1534207046-c45b770ca70b4c518a6970a67df6d2b8-StatTask
[ERROR] StatTask Task failed with exception: [Permission error ([Errno 13] Permission denied: '/mnt/turbinia')]
[ERROR] Traceback (most recent call last):                                                                     
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 399, in run_wrapper
    self.result = self.setup(evidence)                                             
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 318, in setup
    self.output_manager.setup(self)                                                                               
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 156, in setup
    self._output_writers = self.get_output_writers(task)
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 64, in get_output_writers        unique_dir=unique_dir)]                    
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 221, in __init__
    super(LocalOutputWriter, self).__init__(*args, **kwargs)
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 177, in __init__
    self.create_output_dir()
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 235, in create_output_dir
    raise TurbiniaException(msg)
TurbiniaException: Permission error ([Errno 13] **Permission denied: '/mnt/turbinia')**
[ERROR] No TurbiniaTaskResult object found after task execution.                                                
[DEBUG] Checking TurbiniaTaskResult for serializability 
[INFO] Result check: Successful                                                                            
[ERROR] Task 1693f13511f24a9c93ce72788fe1f2c7 failed.                                                              
Traceback (most recent call last):                                                                                 
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 90, 
in execute                                                                                                         
    result = self.call_func()                            
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 104, in call_func                                     
    return self.f(*self.args, **self.kwargs)                                                          
  File "/home/romaing/src/turbinia/turbinia/task_manager.py", line 73, in task_runner
    return obj.run_wrapper(*args, **kwargs)                                                            
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 450, in run_wrapper    
    if original_result_id != self.result.id:                                                                   
AttributeError: 'NoneType' object has no attribute 'id'                                                    
[ERROR] Task 1693f13511f24a9c93ce72788fe1f2c7 failed.
[ERROR] Task 1693f13511f24a9c93ce72788fe1f2c7 failed.                                                      [38/188]
Traceback (most recent call last):                                                                   
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 90,
in execute                                                                                         
    result = self.call_func()                           
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 104, in call_func                                                                                                          return self.f(*self.args, **self.kwargs)                                                                         File "/home/romaing/src/turbinia/turbinia/task_manager.py", line 73, in task_runner
    return obj.run_wrapper(*args, **kwargs)
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 450, in run_wrapper
    if original_result_id != self.result.id:
AttributeError: 'NoneType' object has no attribute 'id'
[INFO] Starting Task PlasoTask e160edc505bf47d893c4d9e9cb93f0d5
[INFO] Creating new directory /mnt/turbinia/output/1534207047-e160edc505bf47d893c4d9e9cb93f0d5-PlasoTask
[ERROR] PlasoTask Task failed with exception: [Permission error ([Errno 13] Permission denied: '/mnt/turbinia')]
[ERROR] Traceback (most recent call last):
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 399, in run_wrapper
    self.result = self.setup(evidence)
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 318, in setup
    self.output_manager.setup(self)
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 156, in setup
    self._output_writers = self.get_output_writers(task)
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 64, in get_output_writers
    unique_dir=unique_dir)]
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 221, in __init__
    super(LocalOutputWriter, self).__init__(*args, **kwargs)
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 177, in __init__
    self.create_output_dir()
  File "/home/romaing/src/turbinia/turbinia/output_manager.py", line 235, in create_output_dir
    raise TurbiniaException(msg)
TurbiniaException: Permission error ([Errno 13] Permission denied: '/mnt/turbinia')[ERROR] No TurbiniaTaskResult object found after task execution.                                                   
[DEBUG] Checking TurbiniaTaskResult for serializability                                                            
[INFO] Result check: Successful                                                                                    
[ERROR] Task 06d539c4cfac49c5a0ccf58addb3bc1d failed.                                                              
Traceback (most recent call last):
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 90,
in execute
    result = self.call_func()
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 104$
 in call_func
    return self.f(*self.args, **self.kwargs)
  File "/home/romaing/src/turbinia/turbinia/task_manager.py", line 73, in task_runner
    return obj.run_wrapper(*args, **kwargs)
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 450, in run_wrapper
    if original_result_id != self.result.id:
AttributeError: 'NoneType' object has no attribute 'id'
[ERROR] Task 06d539c4cfac49c5a0ccf58addb3bc1d failed.
Traceback (most recent call last):
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 90,
in execute
    result = self.call_func()
  File "/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/psq/task.py", line 104$
 in call_func
    return self.f(*self.args, **self.kwargs)
  File "/home/romaing/src/turbinia/turbinia/task_manager.py", line 73, in task_runner
    return obj.run_wrapper(*args, **kwargs)
  File "/home/romaing/src/turbinia/turbinia/workers/__init__.py", line 450, in run_wrapper
    if original_result_id != self.result.id:
AttributeError: 'NoneType' object has no attribute 'id'
^[[5~^C^C^C^C^C^C^C^C^C^C

$ turbiniactl server
[DEBUG] Recieved pubsub message: {"recipe": {}, "request_id": "877b2ac92f664b918921520726b5d396", "type": "Turbinia
Request", "context": {}, "evidence": [{"processed_by": [], "description": null, "tags": {}, "local_path": "/var/log
/dmesg", "copyable": false, "source": null, "saved_path": null, "cloud_only": false, "request_id": null, "config": 
{}, "type": "Directory", "saved_path_type": null, "name": "/var/log/dmesg"}]}                                      
[INFO] Processing PubSub message 166629104334310                                                                   
[INFO] Received evidence [Directory:/var/log/dmesg:/var/log/dmesg] from PubSub message.                            
[INFO] Adding new evidence: Directory:/var/log/dmesg:/var/log/dmesg                                                
[INFO] Adding StatJob job to process /var/log/dmesg                                                                
[INFO] Writing new task StatTask into Datastore                                                                    
[INFO] Adding PSQ task StatTask with evidence /var/log/dmesg to queue                                              
[INFO] Adding PlasoJob job to process /var/log/dmesg                                                               
[INFO] Writing new task PlasoTask into Datastore                                                                   
[INFO] Adding PSQ task PlasoTask with evidence /var/log/dmesg to queue                                             
[DEBUG] Task 1693f13511f24a9c93ce72788fe1f2c7 not yet created                                                      
[DEBUG] Task 06d539c4cfac49c5a0ccf58addb3bc1d not yet created
[INFO] 2 Tasks still outstanding.
[DEBUG] Updating Task StatTask in Datastore
[DEBUG] Updating Task PlasoTask in Datastore
[WARNING] Task 1693f13511f24a9c93ce72788fe1f2c7 failed.
[WARNING] Task 06d539c4cfac49c5a0ccf58addb3bc1d failed.
[INFO] 0 Tasks still outstanding.
[DEBUG] Updating Task StatTask in Datastore
[DEBUG] Updating Task PlasoTask in Datastore


$ turbiniactl -w -a -p 10 directory -l /var/log/dmesg                  
/home/romaing/venvs/turbinia-dev/local/lib/python2.7/site-packages/google/auth/_default.py:66: Use
rWarning: Your application has authenticated using end user credentials from Google Cloud SDK. We recommend that mo
st server applications use service accounts instead. If your application continues to use end user credentials from
 Cloud SDK, you might receive a "quota exceeded" or "API not enabled" error. For more information about service ac$
ounts, see https://cloud.google.com/docs/authentication/.                                                            warnings.warn(_CLOUD_SDK_CREDENTIALS_WARNING)                                                                    
[DEBUG] Setting up PSQ Task Manager requirements on project romaing-turbinia-dev                                   
[DEBUG] Trying to create pubsub topic projects/romaing-turbinia-dev/topics/turbinia-dev                            [DEBUG] PubSub topic projects/romaing-turbinia-dev/topics/turbinia-dev already exists.                             
[DEBUG] Setup PubSub publisher at projects/romaing-turbinia-dev/topics/turbinia-dev                                
[INFO] Creating request 877b2ac92f664b918921520726b5d396 with evidence /var/log/dmesg                              [INFO] Published message 166629104334310 to topic turbinia-dev                                                     
[INFO] Waiting for request 877b2ac92f664b918921520726b5d396 to complete                                            
[DEBUG] Calling Cloud Function [gettasks] with args [{u'instance': u'turbinia-dev', u'kind': u'TurbiniaTask', u're$uest_id': '877b2ac92f664b918921520726b5d396'}]                                                                     
[INFO] 0 Tasks found, 0 completed. Waiting 10 seconds.                                                             
[DEBUG] Calling Cloud Function [gettasks] with args [{u'instance': u'turbinia-dev', u'kind': u'TurbiniaTask', u'request_id': '877b2ac92f664b918921520726b5d
<repeats forever>

[rgayon]

Same "Unkillable" issue if Plaso is broken:

Traceback (most recent call last):
  File "/usr/bin/log2timeline.py", line 12, in <module>
    from plaso.cli import log2timeline_tool
  File "/usr/lib/python2.7/dist-packages/plaso/cli/log2timeline_tool.py", line 19, in <module>
    from plaso.cli import extraction_tool
  File "/usr/lib/python2.7/dist-packages/plaso/cli/extraction_tool.py", line 12, in <module>
    from plaso import parsers  # pylint: disable=unused-import
  File "/usr/lib/python2.7/dist-packages/plaso/parsers/__init__.py", line 9, in <module>
    from plaso.parsers import bsm
  File "/usr/lib/python2.7/dist-packages/plaso/parsers/bsm.py", line 74, in <module>
    class BSMParser(interface.FileObjectParser):
  File "/usr/lib/python2.7/dist-packages/plaso/parsers/bsm.py", line 90, in BSMParser
    IPV4_STRUCT = construct.UBInt32('ipv4')
AttributeError: 'module' object has no attribute 'UBInt32'
[INFO] Execution failed with status 1
[INFO] Execution failed with status 1
[WARNING] New file path [/mnt/turbinia/output/1534208316-acba9089469a431dbde6a57b3598906e-PlasoTask/worker-log.txt] already exists.
[INFO] Writing /mnt/turbinia/output/1534208316-acba9089469a431dbde6a57b3598906e-PlasoTask/worker-log.txt to GCS path output/1534208316-acba9089469a431dbde6a57b3598906e-PlasoTask/worker-log.txt
[DEBUG] Result close successful. Status is [Execution failed with status 1]
[DEBUG] Checking TurbiniaTaskResult for serializability
[INFO] Result check: Successful
[DEBUG] Returning original result object 6b364a20787e43c4946437f9a3732539 after task execution
^C^C^C^C^C^C

[aarontp]

There are a few different things going on here:

• An error that could potentially be caught early on, but isn't checked for. This is what I'll keep this bug open to fix.
• The error then causes Turbinia worker to behave badly (the error should be caught and returned instead of causing a stack trace). I have another PR in progress to fix this.
• PSQ being uninterruptible: This is a known issue with PSQ, and unfortunately is the case whether or not there is a problem in the worker. I can't seem to find the issue now, but I'll see if I can dig it up. I added a note about this in the developer doc.

[aarontp]

So for the third bullet point above, I ended up filing this bug: GoogleCloudPlatform/psq#41

I think the previous issue I was thinking about was this one, but it's been closed since then:
GoogleCloudPlatform/psq#17

[aarontp]

FYI: For point 2 above, I have PR #235

[aarontp]

I'm going to close this issue out now. Issue 1 was fixed in #230, Issue 2 was fixed in #235, and issue 3 is tracked in GoogleCloudPlatform/psq#41.