Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Python: Truncated output from r2.cmd #54

Open
Wenzel opened this issue Mar 14, 2018 · 14 comments
Open

Python: Truncated output from r2.cmd #54

Wenzel opened this issue Mar 14, 2018 · 14 comments

Comments

@Wenzel
Copy link

Wenzel commented Mar 14, 2018

Hi,

I am testing r2pipe in Python and i have a case where the url that open generates a lot of output.
The rest of my script attempt to run pd 10 and get the result:

r2 = r2pipe.open(url, ['-d'])
output = r2.cmd("pd 10")
logging.info(output)
r2.cmd('q!')

When logging prints the content of output, the output appears to have been truncated:

libvirt: QEMU Driver error : Domain not found: no domain with matching name 'xenwin7'
--failed to find kvm domain
LibVMI Version 0.11.0
LibVMI Driver Mode 0
--completed driver init.
--got id from name (xenwin7 --> 2)
**set image_type = xenwin7
**set allocated_ram_size = 7d04a000, max_physical_address = 0xff000000
libvirt: QEMU Driver error : Domain not found: no domain with matching name 'xenwin7'
= attach 1452 1452
= attach 1452 0
INFO:root:_reg_profile
__open
VM: xenwin7, PID: 1452
Initializing LibVMI
--failed to find kvm domain
LibVMI Version 0.11.0
LibVMI Driver Mode 0
--completed driver init.
--got id from name (xenwin7 --> 2)
**set image_type = xenwin7
**set allocated_ram_size = 7d04a000, max_physical_address = 0xff000000
**set pae = 1
**set pse = 1
**set lme = 1
**IA-32e paging
**sanity checking cr3 = 0x0000000000187000
--looking for config file at /home/tarrma/fsecure/radare2-extras/vmi/libvmi.conf
--looking for config file at /home/tarrma/etc/libvmi.conf
--looking for config file at /home/tarrma/etc/libvmi.conf
--looking for config file at /etc/libvmi.conf
**Using config file at /etc/libvmi.conf
**set os_type to Windows.
LibVMI Suggestion: set win_ntoskrnl=0x281b000 in libvmi.conf for faster startup.
LibVMI Suggestion: set win_kdbg=0x1e9070 in libvmi.conf for faster startup.
LibVMI Suggestion: set win_kdvb=0xfffff80002a04070 in libvmi.conf for faster startup.
__reg_profile
__getpid
__getpid
__select
__system command: pid 1452
__kill, sig: 0
__reg_read, type: 0, size:7168
__reg_profile
__getpid
__getpid
__select
__system command: pid 1452
__kill, sig: 0
__reg_read, type: 0, size:7168
Attaching to pid 1452...
Listening on VMI events...
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 860, CR3: 0x14cd1000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1476, CR3: 0x68eb9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1476, CR3: 0x68eb9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1476, CR3: 0x68eb9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1724, CR3: 0x505f9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 572, CR3: 0xeaaf000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 572, CR3: 0xeaaf000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1156, CR3: 0x187ff000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1476, CR3: 0x68eb9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 808, CR3: 0x15088000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 808, CR3: 0x15088000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 472, CR3: 0x20066000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
Listening on VMI events...
cb_on_cr3_load
Intercep

As you can see the last line is Intercep, and this whole output is the one from the open method.
So there is a limit somewhere in the buffer returned by r2.cmd, which prevents me from receiving the complete output of my commands.

Info

r2 -v
radare2 2.5.0-git 17625 @ linux-x86-64 git.2.4.0-103-g1b30ca2
commit: 1b30ca283c9f8a2b04add7020f7e1165ee857f8f build: 2018-03-14__13:38:18

pip3 info r2pipe
Name: r2pipe
Version: 0.9.8
Summary: Pipe interface for radare2
Home-page: http://rada.re
Author: pancake
Author-email: [email protected]
License: MIT
Location: /usr/local/lib/python3.5/dist-packages
Requires: 

Thanks !

@radare
Copy link
Collaborator

radare commented Mar 14, 2018

can you len(output) to see if thats a magic value like 4096 or so?

@radare
Copy link
Collaborator

radare commented Mar 14, 2018

are you printing any \x00 nullbyte?

@Wenzel
Copy link
Author

Wenzel commented Mar 14, 2018

@radare interesting, the output is always almost a magic size:

either this:

INFO:root:output len: 4095

or this value:

INFO:root:output len: 8191

=)

@Wenzel
Copy link
Author

Wenzel commented Mar 14, 2018

@radare no, i'm not printing any buffer, just strings.
this works fine with r2.

@Wenzel
Copy link
Author

Wenzel commented Mar 14, 2018

For example, if i try to intercept the kernel process (the one which is the most frequently scheduled),
the script is working and i have pd 10 output:

len(output) here is 3457

libvirt: QEMU Driver error : Domain not found: no domain with matching name 'xenwin7'
--failed to find kvm domain
LibVMI Version 0.11.0
LibVMI Driver Mode 0
--completed driver init.
--got id from name (xenwin7 --> 2)
**set image_type = xenwin7
**set allocated_ram_size = 7d04a000, max_physical_address = 0xff000000
libvirt: QEMU Driver error : Domain not found: no domain with matching name 'xenwin7'
= attach 4 4
= attach 4 0
read 0xfffffffffffffe88: vmi_failure
read 0x28: vmi_failure
read (nil): vmi_failure
read (nil): vmi_failure
read 0x4: vmi_failure
read 0x165: vmi_failure
INFO:root:output len: 3457
INFO:root:__reg_profile
__open
VM: xenwin7, PID: 4
Initializing LibVMI
--failed to find kvm domain
LibVMI Version 0.11.0
LibVMI Driver Mode 0
--completed driver init.
--got id from name (xenwin7 --> 2)
**set image_type = xenwin7
**set allocated_ram_size = 7d04a000, max_physical_address = 0xff000000
**set pae = 1
**set pse = 1
**set lme = 1
**IA-32e paging
**sanity checking cr3 = 0x0000000000187000
--looking for config file at /home/tarrma/fsecure/radare2-extras/vmi/libvmi.conf
--looking for config file at /home/tarrma/etc/libvmi.conf
--looking for config file at /home/tarrma/etc/libvmi.conf
--looking for config file at /etc/libvmi.conf
**Using config file at /etc/libvmi.conf
**set os_type to Windows.
LibVMI Suggestion: set win_ntoskrnl=0x281b000 in libvmi.conf for faster startup.
LibVMI Suggestion: set win_kdbg=0x1e9070 in libvmi.conf for faster startup.
LibVMI Suggestion: set win_kdvb=0xfffff80002a04070 in libvmi.conf for faster startup.
__reg_profile
__getpid
__getpid
__select
__system command: pid 4
__kill, sig: 0
__reg_read, type: 0, size:7168
__reg_profile
__getpid
__getpid
__select
__system command: pid 4
__kill, sig: 0
__reg_read, type: 0, size:7168
Attaching to pid 4...
Listening on VMI events...
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 380, CR3: 0x20c66000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 1476, CR3: 0x68eb9000
Listening on VMI events...
cb_on_cr3_load
Intercepted PID: 4, CR3: 0x187000
__select
__system command: pid 4
__kill, sig: 0
__reg_read, type: 0, size:7168
__select
__system command: pid 4
__kill, sig: 0
__reg_read, type: 0, size:7168
__system command: pid 4
__kill, sig: 0
__reg_read, type: 0, size:7168
__kill, sig: 0
__reg_read, type: 0, size:7168
__reg_read, type: 1, size:7168
__reg_read, type: 2, size:7168
__reg_read, type: 3, size:7168
__reg_read, type: 4, size:7168
__reg_read, type: 5, size:7168
__reg_read, type: 6, size:7168
__read, offset: fffff800028931a9
__read, offset: fffff800028931a9
__kill, sig: 0
__reg_read, type: 0, size:7168
            ;-- rip:
            0xfffff800028931a9      4c8bbb88feff.  mov r15, qword [rbx - 0x178]
            0xfffff800028931b0      488b6e28       mov rbp, qword [rsi + 0x28]
            0xfffff800028931b4      49896f04       mov qword [r15 + 4], rbp
            0xfffff800028931b8      48896b28       mov qword [rbx + 0x28], rbp
            0xfffff800028931bc      f7057e741800.  test dword [0xfffff80002a1a644], 4
        ,=< 0xfffff800028931c6      0f850b010000   jne 0xfffff800028932d7
        |   0xfffff800028931cc      c6474900       mov byte [rdi + 0x49], 0
        |   0xfffff800028931d0      0fbe86650100.  movsx eax, byte [rsi + 0x165]
        |   0xfffff800028931d7      84c0           test al, al
       ,==< 0xfffff800028931d9      0f8489000000   je 0xfffff80002893268

@radare
Copy link
Collaborator

radare commented Mar 14, 2018 via email

@quim0
Copy link

quim0 commented Mar 16, 2018

Here:

r2 = r2pipe.open(url, ['-d'])

What url are you using? Can't reproduce using process.

@Wenzel
Copy link
Author

Wenzel commented Mar 16, 2018

@quim0 i'm developing a debugger plugin based on virtual machine introspection:
Here: https://github.com/Wenzel/radare2-extras/blob/python/vmi/r2vmi.py#L47

Ask me if you want to test a script or a behavior :)

@quim0
Copy link

quim0 commented Mar 16, 2018

Are you sure you're not printing any nullbytes?
Because I still can't reproduce. I've not used your plugin with qemu yet, but I'm able to print >15K characters with it without any problem, so idk if this is related to r2pipe.

>> import r2pipe
>> r = r2pipe.open('vmi://foo:1234')
>> print len(r.cmd('px 0x10000'))
16383

@Wenzel
Copy link
Author

Wenzel commented Mar 16, 2018

hmm, if you would print a nullbyte, the buffer length would not be a magic number like 4095 in my opinion.

Thank you for investigating.
I will take a look next week if i can

@radare
Copy link
Collaborator

radare commented Mar 16, 2018 via email

@radare
Copy link
Collaborator

radare commented Mar 18, 2018

ping

@Wenzel
Copy link
Author

Wenzel commented Mar 18, 2018

Hello, you know it's the week-end don't you :)

but anyway:
OS: Ubuntu 16.04 stable
Python 3.5.2

I made a video to demonstrate how it happens:
https://drive.google.com/file/d/1D8Zj2MB35y3lq7MxcpVgC4CJmvDSxkdH/view?usp=sharing

Also note that i'm opening the url with the -d flag, to enable the debugging mode.

@Wenzel
Copy link
Author

Wenzel commented Sep 9, 2018

@radare i made some progress on this bug, it's still here, and i have a Dockerfile for you to reproduce:

FROM radare/radare2

USER root
RUN apt-get update && apt-get install -y build-essential git libtool \
        libvirt-dev autoconf pkg-config flex bison libglib2.0-dev libxen-dev libjson-c-dev \
        python3-pip python3-docopt
USER r2

# install libvmi
RUN git clone https://github.com/libvmi/libvmi
USER root
RUN cd libvmi && ./autogen.sh && ./configure --prefix=/usr && make && make install
USER r2

# vmi plugin
RUN git clone https://github.com/Wenzel/r2vmi -b debug_r2pipe
ENV PKG_CONFIG_PATH /usr/lib/pkgconfig
RUN cd r2vmi && make install

# r2pipe
USER root
RUN pip3 install r2pipe
USER r2

ENTRYPOINT python3 r2vmi/examples/debug_r2pipe.py vm explorer

output:

...
Print line 888...
Print line 889...
Print line 890...
Print line 891...
Print line 892...
Print line 893...
Print line 894...
Print line 895...
Print line 896...
Print line 897...
Print line 898...
Print line 899...
Print line 900...
Print line 901...
Print line 902...
Print line 903...
Print line 904...
Print line 905...
Print line 906...
Print line 907...
Print line 908...
Print line 909...
Print line 910...
Print lin__read, offset: 0
read (nil): vmi_failure

__reg_read, type: 0, size:7168
INFO:root:size of output: 16383

We should have seen a pd 10 output being printed.

r2pipe script i'm using

    r2_url = "vmi://{}:{}".format(vm_name,target)
    r2 = r2pipe.open(r2_url, ["-d"])
    output = r2.cmd('pd 10')
    logging.info(output)
    logging.info("size of output: %s", len(output))

Thanks guys !

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants