Handle signals #337

b0urb0n · 2020-07-27T15:48:46Z

Every once in a while, FLOSS takes forever to process a sample and becomes unresponsive to all signals including SIGINT (from Ctrl-C) and SIGKILL (from kill -9 <pid>). SIGKILL has a tendency to turn the FLOSS process into a zombie until it eventually exits (sometimes days later).

Here's an example of a run-away FLOSS process:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root       192 99.7 39.2 105612524 103645076 ? R    14:34  56:24 /usr/local/bin/floss --quiet --minimum-length 4 --output-json /tmp/tmp722lnot0 /tmp/tmpz75s5fhb

Note the process run-time of 14.5 minutes, pegged CPU, and over 100GB of RAM in use.

Here's another that ran for over an hour:

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root        47 97.9 41.8 112215364 110384012 ? R    18:32  78:22 /usr/local/bin/floss --quiet --minimum-length 4 --output-json /tmp/tmpxme6e3rh /tmp/tmpddot57ml

Here are some zombies from days ago:

root        27  0.0  0.0      0     0 ?        Z    Jul24   2:36 [floss] <defunct>
root        31  0.0  0.0      0     0 ?        Z    Jul24   2:21 [floss] <defunct>
root        47  1.8  0.0      0     0 ?        Z    Jul24  78:30 [floss] <defunct>

(These are executed as root because docker instances)

For what it's worth, these are kicked off with the subprocess Python library with subprocess.check_output.

I'm going to track down exactly which samples cause this behavior and try and get permission to release them for testing if you're interested.

In the meantime, has any effort been put into better supporting IPC in order to cleanly exit? My guess is that most of this effort would be in Vivisect but I'm not sure right now.

The text was updated successfully, but these errors were encountered:

mr-tz · 2020-07-31T10:30:39Z

If you could provide (a) sample(s) for testing that would be best. I've seen rare instances where vivisect spins forever, but it could also be that the FLOSS core goes off the rails somehow.

As a workaround, maybe specifying a timeout with subprocess can help?!

b0urb0n · 2020-08-05T18:47:38Z

We've been using a timeout with our call to subprocess.check_output. The Python application seems to never unblock from this call presumably due to the .wait() call in subprocess.run() that doesn't have a timeout value

    ...
    with Popen(*popenargs, **kwargs) as process:
        try:
            stdout, stderr = process.communicate(input, timeout=timeout)
        except TimeoutExpired as exc:
            process.kill()
            if _mswindows:
                ...
            else:
                # POSIX _communicate already populated the output so
                # far into the TimeoutExpired exception.
                process.wait()
            raise
    ...

I'll have a try at re-implementing this feature in our application with Popen.communicate or asyncio.create_subprocess_exec and explicitly cleaning up the child (and grandchild) processes.

As for the samples causing the problems, my organization is okay with sharing them as long as you use them only for testing and do not share them. If that is acceptable, please let me know how I can send them to you.

FWIW, we're also seeing the same behavior with capa (CPU pegged, runaway memory consumption) which is initially why I believe the problem to be Vivisect's.

mr-tz · 2020-08-06T11:07:27Z

Great, thank you. I'll only use the samples to test this issue.

mr-tz · 2020-09-30T09:14:37Z

I've taken a look at the samples @b0urb0n provided via email. vivisect encounters some errors when loading as shown below and then continuously throws Exception: Address (0x...) not in maps! exceptions. If you can share a sample publicly I could open a vivisect issue.

2020-09-30 02:35:20,359:ERROR:vivisect.base: Traceback (most recent call last):
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 570, in _fireEvent
    self.ehand[event](einfo)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 394, in _handleADDMMAP
    self.locmap.initMapLookup(va, blen)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/envi/pagelookup.py", line 52, in initMapLookup
    marray = [obj] * size
MemoryError
[base.py:_fireEvent:589:MainThread]
2020-09-30 02:35:24,037:WARNING:vivisect.parsers.pe: Error Loading Section ( size:850 rva:00006174 offset: 33024): [pe.py:loadPeIntoWorkspace:314:MainThread]
2020-09-30 02:35:27,667:WARNING:vivisect.parsers.pe: Error Loading Section ( size:1764 rva:00000063 offset: 99): [pe.py:loadPeIntoWorkspace:314:MainThread]
2020-09-30 02:35:28,763:WARNING:vivisect.parsers.pe: Error Loading Section ( size:12 rva:0000636f offset: 33531): [pe.py:loadPeIntoWorkspace:314:MainThread]
2020-09-30 02:35:28,885:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.generic.entrypoints[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:28,892:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.pe[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,280:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.generic.relocations[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,282:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.ms.vftables[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,282:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.generic.emucode[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,283:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.i386.importcalls[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,284:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.i386.golang[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,284:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.generic.codeblocks[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,285:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.generic.impapi[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,286:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.ms.hotpatch[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,291:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.ms.msvc[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,291:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.i386.instrhook[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,292:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.i386.calling[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,292:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.ms.localhints[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,292:DEBUG:vivisect: Adding Function Analysis Module: vivisect.analysis.generic.thunks[__init__.py:addFuncAnalysisModule:492:MainThread]
2020-09-30 02:35:29,293:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.generic.funcentries[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,293:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.ms.msvcfunc[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,295:DEBUG:vivisect: Adding Analysis Module: vivisect.analysis.generic.strconst[__init__.py:addAnalysisModule:465:MainThread]
2020-09-30 02:35:29,295:INFO:vivisect.analysis: Vivisect Analysis Setup Hooks Complete[__init__.py:addAnalysisModules:203:MainThread]
2020-09-30 02:35:29,295:INFO:vivisect: Loaded (19.5809 sec) <sample>[vivbin.py:main:103:MainThread]
2020-09-30 02:35:29,298:INFO:vivisect: Beginning analysis...[__init__.py:vprint:186:MainThread]
2020-09-30 02:35:29,298:INFO:vivisect: Extended Analysis: vivisect.analysis.generic.entrypoints[__init__.py:vprint:186:MainThread]
2020-09-30 02:35:29,299:ERROR:vivisect.base: Traceback (most recent call last):
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 570, in _fireEvent
    self.ehand[event](einfo)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 212, in _handleADDLOCATION
    self.locmap.setMapLookup(lva, lsize, loc)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/envi/pagelookup.py", line 62, in setMapLookup
    raise Exception('Address (0x%.8x) not in maps!' % va)
Exception: Address (0x004789fe) not in maps!
[base.py:_fireEvent:589:MainThread]
2020-09-30 02:35:29,300:ERROR:vivisect.base: Traceback (most recent call last):
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 570, in _fireEvent
    self.ehand[event](einfo)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/vivisect/base.py", line 212, in _handleADDLOCATION
    self.locmap.setMapLookup(lva, lsize, loc)
  File "/tmp/flare-floss/local/lib/python2.7/site-packages/envi/pagelookup.py", line 62, in setMapLookup
    raise Exception('Address (0x%.8x) not in maps!' % va)
Exception: Address (0x00478a00) not in maps!
...

b0urb0n · 2020-10-05T15:43:46Z

Sorry for the delay. Unfortunately, the organization is not willing to release the samples publicly at this time. Perhaps similar samples could be found by leveraging ssdeep/TLSH?

b0urb0n · 2020-12-09T21:15:59Z

@mr-tz, here's a similar sample

mr-tz · 2020-12-11T10:44:17Z

Great, thank you! I'll take a look and open a vivisect issue upstream.

mr-tz · 2020-12-11T10:55:53Z

For me vivisect and FLOSS both quickly process 9e7ff34f05442d26457fd8066f52d9dad9b2a7b2ef57e02b944959ce046330fd.
What error are you encountering?

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Handle signals #337

Handle signals #337

b0urb0n commented Jul 27, 2020 •

edited

Loading

mr-tz commented Jul 31, 2020

b0urb0n commented Aug 5, 2020 •

edited

Loading

mr-tz commented Aug 6, 2020 •

edited

Loading

mr-tz commented Sep 30, 2020

b0urb0n commented Oct 5, 2020

b0urb0n commented Dec 9, 2020 •

edited

Loading

mr-tz commented Dec 11, 2020

mr-tz commented Dec 11, 2020

Handle signals #337

Handle signals #337

Comments

b0urb0n commented Jul 27, 2020 • edited Loading

mr-tz commented Jul 31, 2020

b0urb0n commented Aug 5, 2020 • edited Loading

mr-tz commented Aug 6, 2020 • edited Loading

mr-tz commented Sep 30, 2020

b0urb0n commented Oct 5, 2020

b0urb0n commented Dec 9, 2020 • edited Loading

mr-tz commented Dec 11, 2020

mr-tz commented Dec 11, 2020

b0urb0n commented Jul 27, 2020 •

edited

Loading

b0urb0n commented Aug 5, 2020 •

edited

Loading

mr-tz commented Aug 6, 2020 •

edited

Loading

b0urb0n commented Dec 9, 2020 •

edited

Loading