IDA7.6，ERROR:[sync] idb is disabled

[havocykp]

Hi, I'm here again. I configured RET sync for IDA 7.6, but it also made an error

3.

What is causing this problem and how do we solve it?

[bootleg]

Hi @havocykp

seeing sys.stdout.puts in the backtrace. Could you check this instance of ret-sync is up-to-date? It should not be there anymore. See the last commit:

ret-sync/ext_ida/retsync/broker.py

Line 65 in bc897bb

self.stdout.write(rs_encode(msg + '\n'))

Cheers,

[havocykp]

2021-08-08 10:18:02,513 [ERROR] server.loop
Traceback (most recent call last):
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 479, in error_reporting
yield
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 494, in
server.loop()
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 149, in loop
self.handle(s)
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 154, in handle
self.parse_exec(s, req)
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 212, in parse_exec
req_handler(s, hash)
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 381, in req_kill
self.client_quit(s)
File "D:\IDA Pro 7.6\plugins\retsync\dispatcher.py", line 316, in client_quit
self.opened_socks.remove(idbc.client_sock)
ValueError: list.remove(x): x not in list

[bootleg]

Hi @havocykp

sorry for the delay,I was absent.

Could you tell me what happens if you simply try to run python dispatcher.py directly from a shell ?

This weird network related error plus you plugin failing to initialize may indicate a failure to bind server port on 9100.

[adrian-rt]

hi @bootleg , I have the same issue:

[sync] sync enabled
[sync] init_broker
[sync] cmdline: "C:\Python27-x64\python.exe" -u "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\broker.py" --idb "Acrobat.exe"
[sync] module base 0xb50000
[sync] hexrays #7.2.0.181105 found
[sync] broker new state: Starting
[sync] broker new state: Running
[sync] broker started
[sync] hexrays sync enabled

[sync] << broker << dispatcher not found, trying to run it
[sync] << broker << dispatcher now runs with pid: 1592
[sync] << broker << connected to dispatcher
[sync] << broker << binding on port 49914
[sync] << broker << beacon not received (this may be dispatcher error, tip: please check that the port 9100 is available )
[sync] << broker << received kill notice
[sync] broker new state: Not running
[sync]     check tmp file retsync.<broker|dispatcher>.err if you think this is an error
[sync] broker finished
[sync] idb is disabled

If I run python dispatcher.py from the console it seems that a server is started on port 9100.

[bootleg]

@adrian-rt

Is a retsync.<broker|dispatcher>.err generated?
Is the port 9100 already bound before launching retsync?

[adrian-rt]

@bootleg

port is not bound before launching retsync.

the dispatcher log file is same as above:

2021-09-01 09:12:12,005 [ERROR] server.loop
Traceback (most recent call last):
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 479, in error_reporting
    yield
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 494, in <module>
    server.loop()
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 149, in loop
    self.handle(s)
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 153, in handle
    for req in self.recvall(client):
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 182, in recvall
    self.client_quit(client.srv_sock)
  File "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\dispatcher.py", line 316, in client_quit
    self.opened_socks.remove(idbc.client_sock)
ValueError: list.remove(x): x not in list

[bootleg]

@adrian-rt

please see commit 2f2c39e

There was a logic issue in the handling of the socks; the same sock would be consider as both a client and server sock. It is fixed now however I feel I don't really get the root cause of your issue. My guess is that the broker is dying for whatever reason thus the sock.error and finally the ValueError: list.remove(x): x not in list.

[adrian-rt]

@bootleg
I downloaded the latest version, but I still get the same error:

`sync] sync enabled
[sync] cmdline: "C:\Python27-x64\python.exe" -u "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\broker.py" --idb "Acrobat.exe"
[sync] module base 0xb50000
[sync] hexrays #7.2.0.181105 found
[sync] broker started
[sync] restarting broker
[sync] broker finished
[sync] sync disabled

[sync] sync enabled
[sync] cmdline: "C:\Python27-x64\python.exe" -u "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\broker.py" --idb "Acrobat.exe"
[sync] module base 0xb50000
[sync] hexrays #7.2.0.181105 found
[sync] broker started
[sync] << broker << dispatcher not found, trying to run it
[sync] << broker << dispatcher now runs with pid: 10500
[sync] << broker << connected to dispatcher
[sync] << broker << beacon not received (this may be dispatcher error, tip: please check that the port 9100 is available )
[sync] << broker << received kill notice
[sync] broker finished
[sync] idb is disabled
[sync] restarting broker
[sync] sync enabled
[sync] cmdline: "C:\Python27-x64\python.exe" -u "C:\Users\adria\AppData\Roaming\Hex-Rays\IDA Pro\plugins\retsync\broker.py" --idb "Acrobat.exe"
[sync] module base 0xb50000
[sync] hexrays #7.2.0.181105 found
[sync] broker started
[sync] << broker << dispatcher not found, trying to run it
[sync] << broker << dispatcher now runs with pid: 4988
[sync] << broker << connected to dispatcher
[sync] << broker << beacon not received (this may be dispatcher error, tip: please check that the port 9100 is available )
[sync] << broker << received kill notice
[sync] broker finished
[sync] idb is disabled`

[bootleg]

That was my guess indeed :/

However right now there is now more retsync.<broker|dispatcher>.err generated?

[adrian-rt]

nothing new in those log files ...

[bootleg]

Is there still ValueError: list.remove(x): x not in list in them ?

[adrian-rt]

no, nothing is logged now.

[bootleg]

Silly question but this instance of Python is authorized to bind a port right (ie. not firewalled) right (9100 or other) ?

import socket

host = '127.0.0.1'
port = 9100
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.bind((host, port))

Also if I can ask you to insert the rslog line in dispatcher.py (line 281) as below:

    # a new idb client connects to the dispatcher via its broker
    def req_new_client(self, srv_sock, hash):
        port, name = hash['port'], hash['idb']
        try:
            client_sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
            client_sock.settimeout(2)
            client_sock.connect(('localhost', port))
            self.opened_socks.append(client_sock)
        except socket.error:
            rs_log.exception("req_new_client socket.error", exc_info=True)
            self.opened_socks.remove(srv_sock)
            srv_sock.close()
            return

[adrian-rt]

indeed looks like there is an issue with python, it can't bind

` sock.bind((host, port))
Traceback (most recent call last):
File "", line 1, in
File "C:\Python27-x64\lib\socket.py", line 228, in meth
return getattr(self._sock,name)(*args)
socket.error: [Errno 10013] An attempt was made to access a socket in a way forbidden by its access permissions

sock.bind((host, port))
sock.bind((host, port))
Traceback (most recent call last):
File "", line 1, in
File "C:\Python27-x64\lib\socket.py", line 228, in meth
return getattr(self._sock,name)(*args)
socket.error: [Errno 10022] An invalid argument was supplied`

not seen this one before.....

I made that change in dispatcher.py but nothing gets logged.

[bootleg]

Intersting,

does the snippet below succeed?

import socket

host = 'localhost'
port = 9100
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.bind((host, port))

ie. using localhost instead of 127.0.0.1

Based on the previous traces, it seems that the broker successfully binds on a random port. Broker code would be:

import socket

host = 'localhost'
port = 0
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.bind((host, port))