turbinia icon indicating copy to clipboard operation
turbinia copied to clipboard

StringsJob occasionally fails with permission denied error

Open wajihyassine opened this issue 2 years ago • 2 comments

Seeing a couple of StringJobs fail occasionally during high load tests.

Example error:

Execution of [strings -a -t d -e l /dev/loop8 > /mnt/turbiniavolume/output/d9d5cd4e1c6947c1bc0ecfc612000956/1675275488-fc35e981640f4dc9bab06bff7d538a04-StringsUnicodeTask/loop8.uni] failed with status 1

Reviewing stderr of failed Task:

strings: /dev/loop8: Permission denied

Originally posted by @wajihyassine in https://github.com/google/turbinia/issues/1249#issuecomment-1412631476

wajihyassine avatar Feb 01 '23 19:02 wajihyassine

Sample logs around error:

2023-02-01 18:32:51,660:INFO:Starting preprocessor for evidence test-disk-20gb-80:/p2
2023-02-01 18:32:51,660:DEBUG:Evidence test-disk-20gb-80:/p2 is not resource tracked. Running preprocess.
2023-02-01 18:32:51,660:DEBUG:Scanning test-disk-20gb-80 for partition at location /p2
2023-02-01 18:32:52,261:DEBUG:Found path_spec {'parent': {'parent': {'location': '/dev/disk/by-id/google-test-disk-20gb-80'}, 'location': '/p2'}, 'location': '/'} for parent evidence test-disk-20gb-80
2023-02-01 18:32:52,263:INFO:Running command sudo losetup --show --find -r -o 210763776 --sizelimit 21263024128 /dev/disk/by-id/google-test-disk-20gb-80
2023-02-01 18:32:52,317:INFO:Loop device /dev/loop8 created for evidence /dev/disk/by-id/google-test-disk-20gb-80
2023-02-01 18:32:52,318:INFO:Preprocessing evidence test-disk-20gb-80:/p2 is complete, and evidence is in state [MOUNTED: False, ATTACHED: True, DECOMPRESSED: False, CONTAINER_MOUNTED: False]
2023-02-01 18:32:52,319:INFO:Updating task StringsUnicodeTask in Redis
2023-02-01 18:32:52,321:INFO:Running strings as [strings -a -t d -e l /dev/loop8 > /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/loop8.uni]
2023-02-01 18:32:52,338:DEBUG:Writing stderr to /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/stderr-05k6is_7.txt
2023-02-01 18:32:52,343:INFO:Output log file found at /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/stderr-05k6is_7.txt
2023-02-01 18:32:52,344:DEBUG:Not copying source file /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/stderr-05k6is_7.txt already in output dir /mnt/turbiniavolume/output/04c923
c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask
2023-02-01 18:32:52,344:INFO:Execution of [strings -a -t d -e l /dev/loop8 > /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/loop8.uni] failed with status 1
2023-02-01 18:32:52,344:INFO:Execution of [strings -a -t d -e l /dev/loop8 > /mnt/turbiniavolume/output/04c923c25c3a4df9bd179153ceae2f18/1675276360-c363d893fef642a1807963288887b61c-StringsUnicodeTask/loop8.uni] failed with status 1
2023-02-01 18:32:52,345:INFO:Starting postprocessor for evidence test-disk-20gb-80:/p2
2023-02-01 18:32:52,345:DEBUG:Evidence state: [MOUNTED: False, ATTACHED: True, DECOMPRESSED: False, CONTAINER_MOUNTED: False]
2023-02-01 18:32:52,345:DEBUG:Evidence test-disk-20gb-80:/p2 is not resource tracked. Running postprocess.
2023-02-01 18:32:52,346:INFO:Running: sudo losetup -d /dev/loop8
2023-02-01 18:32:52,433:DEBUG:losetup retry check 0/10 for device /dev/loop8
2023-02-01 18:32:53,453:INFO:losetup device [/dev/loop8] deleted.
2023-02-01 18:32:53,453:DEBUG:Evidence test-disk-20gb-80:/p2 has parent_evidence. Running postprocess for parent evidence test-disk-20gb-80.
2023-02-01 18:32:53,455:INFO:Starting postprocessor for evidence test-disk-20gb-80
2023-02-01 18:32:53,455:DEBUG:Evidence state: [MOUNTED: False, ATTACHED: True, DECOMPRESSED: False, CONTAINER_MOUNTED: False]
2023-02-01 18:32:53,457:DEBUG:Evidence: test-disk-20gb-80 is resource tracked. Acquiring filelock for postprocessing.
2023-02-01 18:32:53,457:DEBUG:Removing task c363d893fef642a1807963288887b61c with associated resource test-disk-20gb-80 from the resource state file.
2023-02-01 18:32:53,458:INFO:The resource state file has been successfully updated.

wajihyassine avatar Feb 01 '23 19:02 wajihyassine

Should we just add a sudo to the execution?

aarontp avatar Apr 21 '23 00:04 aarontp