[BUG] bettercap.py dying

[aluminum-ice]

[BUG] bettercap.py dying

[kennyHH]

I made a quick workaround by creating services that look for those errors in 'pwnagotchi.log' and restart both pwnagtochi and bettercap. It's quicker than looking at the logs and restarting them manually. Hopefully it will get fixed in the future :)

I took my pwnagotchi for a walk and looks like it's working properly. If not let me know.

Here is a quick guide :

https://wax-stitch-c28.notion.site/Pwny-restart-scripts-to-recover-from-bettercap-crashes-dffece81076d4884b9d851390611705c

[captclearleft]

Im getting this too:
[WARNING] connection to the bettercap endpoint failed...

A reboot seems to help. But eventually - this keeps happening.

On another note (maybe related). I have found that when using the Web Ui from a Bluetoothed phone - If you navigate to the plugins page and toggle anything - this loads all the default settings that are not already in the config.toml file. (ie so the config.toml has just what was initialy loaded (the basics) - then if you toggle gps on or off- then all the settings that were not there before all get loaded.) then after a reboot - The OS wont load. It just restarts then freezes. A new config.toml file in the boot section of the sd card does not help. The system restarts before looking for the config.toml file aparently. I am trying to figure out which setting is causing the issue. But there are a lot of settings.

[captclearleft]

(EDITED to add more log error info that occurs after the
connection to the bettercap endpoint failed...
Here is what the log shows. disregard ########## (00:00:00:00:00) just masking the actual ssid and mac.

[2023-09-25 16:37:29,563] [INFO] sending association frame to ########## (00:00:00:00:00 ) on channel 11 [0 clients], -89 dBm...
[2023-09-25 16:37:29,614] [INFO] waiting for 59s on channel 11 ...
[2023-09-25 16:38:14,843] [WARNING] ping error - retrying connection in 1.3340479788812716 sec
[2023-09-25 16:38:16,189] [INFO] creating new websocket...
[2023-09-25 16:38:16,194] [WARNING] connection to the bettercap endpoint failed...
[2023-09-25 16:38:16,195] [WARNING] retrying connection in 1.1220782125029423 sec
[2023-09-25 16:38:17,320] [INFO] creating new websocket...
[2023-09-25 16:38:17,325] [WARNING] connection to the bettercap endpoint failed...

This is from another day. with more detail
[2023-09-30 10:45:48,387] [WARNING] connection to the bettercap endpoint failed...
[2023-09-30 10:45:48,388] [WARNING] retrying connection in 4.094671831103489 sec
[2023-09-30 10:45:51,545] [WARNING] can't run my request... connection to the bettercap endpoint failed...
[2023-09-30 10:45:51,546] [WARNING] retrying run in 2.888625456879751 sec
[2023-09-30 10:45:51,627] [ERROR] Error while getting acces points (HTTPConnectionPool(host='localhost', port=8081): Max retries exceeded with url: /api/session (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x42c5dd30>: Failed to establish a new connection: [Errno 111] Connection refused')))
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/urllib3/connection.py", line 175, in _new_conn
(self._dns_host, self.port), self.timeout, **extra_kw
File "/usr/local/lib/python3.7/dist-packages/urllib3/util/connection.py", line 95, in create_connection
raise err
File "/usr/local/lib/python3.7/dist-packages/urllib3/util/connection.py", line 85, in create_connection
sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/urllib3/connectionpool.py", line 710, in urlopen
chunked=chunked,
File "/usr/local/lib/python3.7/dist-packages/urllib3/connectionpool.py", line 398, in _make_request
conn.request(method, url, **httplib_request_kw)
File "/usr/local/lib/python3.7/dist-packages/urllib3/connection.py", line 239, in request
super(HTTPConnection, self).request(method, url, body=body, headers=headers)
File "/usr/lib/python3.7/http/client.py", line 1264, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1310, in _send_request
self.endheaders(body, encode_chunked=encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1259, in endheaders
self._send_output(message_body, encode_chunked=encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1034, in _send_output
self.send(msg)
File "/usr/lib/python3.7/http/client.py", line 974, in send
self.connect()
File "/usr/local/lib/python3.7/dist-packages/urllib3/connection.py", line 205, in connect
conn = self._new_conn()
File "/usr/local/lib/python3.7/dist-packages/urllib3/connection.py", line 187, in _new_conn
self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x42c5dd30>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/requests/adapters.py", line 499, in send
timeout=timeout,
File "/usr/local/lib/python3.7/dist-packages/urllib3/connectionpool.py", line 788, in urlopen
method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
File "/usr/local/lib/python3.7/dist-packages/urllib3/util/retry.py", line 592, in increment
raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='localhost', port=8081): Max retries exceeded with url: /api/session (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x42c5dd30>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/pwnagotchi/agent.py", line 182, in get_access_points
s = self.session()
File "/usr/local/lib/python3.7/dist-packages/pwnagotchi/bettercap.py", line 46, in session
r = requests.get("%s/session" % self.url, auth=self.auth)
File "/usr/local/lib/python3.7/dist-packages/requests/api.py", line 73, in get
return request("get", url, params=params, **kwargs)
File "/usr/local/lib/python3.7/dist-packages/requests/api.py", line 59, in request
return session.request(method=method, url=url, **kwargs)
File "/usr/local/lib/python3.7/dist-packages/requests/sessions.py", line 587, in request
resp = self.send(prep, **send_kwargs)
File "/usr/local/lib/python3.7/dist-packages/requests/sessions.py", line 701, in send
r = adapter.send(request, **kwargs)
File "/usr/local/lib/python3.7/dist-packages/requests/adapters.py", line 565, in send
raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='localhost', port=8081): Max retries exceeded with url: /api/session (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x42c5dd30>: Failed to establish a new connection: [Errno 111] Connection refused'))
[2023-09-30 10:45:51,753] [INFO] [epoch 3] duration=00:00:50 slept_for=00:00:30 blind=1 sad=0 bored=0 inactive=1 active=0 peers=0 tot_bond=0.00 avg_bond=0.00 hops=0 missed=0 deauths=0 assocs=0 handshakes=0 cpu=5% mem=70% temperature=55C reward=-0.125
[2023-09-30 10:45:52,485] [INFO] creating new websocket...
[2023-09-30 10:45:52,490] [WARNING] connection to the bettercap endpoint failed...

[captclearleft]

Note: I just noticed that IF my phone DOES connect to Bluetooth successfully - I do NOT get these errors (at least in the first test.)
I will try a few more times to see what happens when I make sure that the phone is connected.

I know the last few times where I get these errors in the logs - I know that my phone is not connected (BT-NF). And I see that the UP Time does not get updated and the pwnagotchi just sits there and takes naps, looks around, and zzzzzz... When I see this happening, I note the time - do a reboot vie GPIO Button, and know that when I check the log it will be filled with the
connection to the bettercap endpoint failed...

[captclearleft]

@kennyHH
This is great stuff! Thanks. I am still doing testing and trying to figure out what is causing it.
Other theories right now:

-- I have my handshakes folder in the /home directrory, not root like the default. I do not understand why its originally in root?
-- The error almost always follows
[INFO] [ai] ! channels: [1, 2, 4, 5, 6, 7, 11] -> [1, 2, 3, 5, 7, 8, 11]
[WARNING] ping error - retrying connection in 2.1915870428889512 sec

This is with DEBUG --(pwanagotchi seems to be constantly polling pwngrid-peer for peers even though I have that disabled...)

[DEBUG] client < Frame(fin=True, opcode=1, data=b'{"tag":"wifi.ap.new","time":"2023-09-27T14:29:17.535516444-06:00","data":{"ipv4":"0.0.0.0","ipv6":"","mac":"82:d2:94:ba:8e:1a","hostname":"\\u003chidden\\u003e","alias":"","vendor":"","first_seen":"2023-09-27T14:29:17.534793944-06:00","last_seen":"2023-09-27T14:29:17.534793944-06:00","meta":{"values":{}},"frequency":2422,"channel":3,"rssi":-90,"sent":0,"received":0,"encryption":"WPA2","cipher":"CCMP","authentication":"PSK","wps":{},"clients":[],"handshake":false}}', rsv1=False, rsv2=False, rsv3=False)
[2023-09-27 14:29:17,594] [DEBUG] client - event = data_received(<225 bytes>)
[2023-09-27 14:29:17,596] [DEBUG] client < Frame(fin=True, opcode=1, data=b'{"tag":"gps.new","time":"2023-09-27T14:29:17.590390975-06:00","data":{"Updated":"2023-09-27T14:29:17.590380923-06:00","Latitude":0,"Longitude":0,"FixQuality":"0","NumSatellites":3,"HDOP":6.56,"Altitude":0,"Separation":0}}', rsv1=False, rsv2=False, rsv3=False)
[2023-09-27 14:29:17,643] [DEBUG] e-Paper busy
[2023-09-27 14:29:17,645] [DEBUG] e-Paper busy release
[2023-09-27 14:29:17,646] [DEBUG] e-Paper busy
[2023-09-27 14:29:17,743] [DEBUG] e-Paper busy release
[2023-09-27 14:29:17,957] [DEBUG] e-Paper busy
[2023-09-27 14:29:18,165] [DEBUG] client - event = eof_received()
[2023-09-27 14:29:18,167] [DEBUG] client ! failing OPEN WebSocket connection with code 1006
[2023-09-27 14:29:18,167] [DEBUG] client - event = connection_lost(None)
[2023-09-27 14:29:18,167] [DEBUG] client - state = CLOSED
[2023-09-27 14:29:18,168] [DEBUG] client x code = 1006, reason = [no reason]
[2023-09-27 14:29:18,180] [WARNING] ping error - retrying connection in 3.8435677219429745 sec
[2023-09-27 14:29:18,583] [DEBUG] e-Paper busy release
[2023-09-27 14:29:21,041] [DEBUG] polling pwngrid-peer for peers ...
[2023-09-27 14:29:22,035] [INFO] creating new websocket...
[2023-09-27 14:29:22,113] [WARNING] connection to the bettercap endpoint failed...

[captclearleft]

@kennyHH
I added the recommended

main.mon_max_blind_epochs = 5

main.no_restart = false

to the config.toml file and got some new log data. It appears that the Connection was reestablished. The log does not indicate a restart or reboot - but I am guessing that is what happened.

I would like to create a plugin that looks for the connection error and then checks to see if mon0 is up. Is this possible with your script.... Is it possible to use your script to instead of restarting the bettercap and pwnagotchi - - check if mon0 is down... If it is bring it back up.... I am not sure about this though... need to do some more testing and investigating.
This all could be a chip issue as aluminum-ice mentions that the new pi zero 2 w (which is what I do not have ) has a better chip BCM4343... I have not been able to get one of these.

https://pastebin.com/7qWaDpQS

[captclearleft]

More research into this: I have looked into the syslog file and found some correlation to the error.
It appears that maybe the GPS could be causing an issue, but more likely is just the nexmon drivers mon0 failing... Will continue to test without GPS...
Here is where the error starts in the pwnagotchi.log (09:35:10)

[2023-10-05 09:35:10,386] [DEBUG] client - event = data_received(<226 bytes>)
[2023-10-05 09:35:10,387] [DEBUG] client < Frame(fin=True, opcode=1, data=b'{"tag":"gps.new","time":"2023-10-05T09:35:10.385335869-06:00","data":{"Updated":"2023-10-05T09:35:10.385330657-06:00","Latitude":0,"Longitude":0,"FixQuality":"0","NumSatellites":0,"HDOP":99.99,"Altitude":0,"Separation":0}}', rsv1=False, rsv2=False, rsv3=False)
[2023-10-05 09:35:10,684] [DEBUG] client - event = data_received(<639 bytes>)
[2023-10-05 09:35:10,685] [DEBUG] client < Frame(fin=True, opcode=1, data=b'{"tag":"wifi.client.probe","time":"2023-10-05T09:35:10.671141363-06:00","data":{"mac":"f2:6d:3e:10:82:e1","vendor":"","alias":"","essid":"TMobileWingman","rssi":-86}}', rsv1=False, rsv2=False, rsv3=False)
[2023-10-05 09:35:10,686] [DEBUG] client < Frame(fin=True, opcode=1, data=b'{"tag":"wifi.ap.new","time":"2023-10-05T09:35:10.67293562-06:00","data":{"ipv4":"0.0.0.0","ipv6":"","mac":"xx:xx:xx:xx","hostname":"############","alias":"","vendor":"","first_seen":"2023-10-05T09:35:10.672371882-06:00","last_seen":"2023-10-05T09:35:10.672371882-06:00","meta":{"values":{}},"frequency":2437,"channel":6,"rssi":-85,"sent":0,"received":0,"encryption":"WPA2","cipher":"CCMP","authentication":"PSK","wps":{},"clients":[],"handshake":false}}', rsv1=False, rsv2=False, rsv3=False)
[2023-10-05 09:35:10,810] [DEBUG] client - event = eof_received()
[2023-10-05 09:35:10,811] [DEBUG] client ! failing OPEN WebSocket connection with code 1006
[2023-10-05 09:35:10,812] [DEBUG] client - event = connection_lost(None)
[2023-10-05 09:35:10,813] [DEBUG] client - state = CLOSED
[2023-10-05 09:35:10,813] [DEBUG] client x code = 1006, reason = [no reason]
[2023-10-05 09:35:10,822] [WARNING] ping error - retrying connection in 4.153930391318868 sec
[2023-10-05 09:35:10,910] [DEBUG] e-Paper busy release
[2023-10-05 09:35:10,921] [DEBUG] e-Paper busy

From there we continue to get:

[2023-10-05 09:35:14,990] [WARNING] connection to the bettercap endpoint failed...
[2023-10-05 09:35:14,990] [WARNING] retrying connection in 2.2730925871741783 sec

Until reboot...

Now in the syslog file at the same time I get this:

Oct  5 09:35:09 imatorchi24 bettercap-launcher[459]: [09:35:09] [gps.new] latitude:0.000000 longitude:0.000000 quality:0 satellites:0 altitude:0.000000
Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: [09:35:10] [gps.new] latitude:0.000000 longitude:0.000000 quality:0 satellites:0 altitude:0.000000
Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: fatal error: concurrent map iteration and map write
Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: goroutine 318 [running]:

Then down below this:

Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: #011/root/go/src/github.com/gorilla/mux/mux.go:212 +0x1dc
Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: net/http.serverHandler.ServeHTTP({0x35823c0}, {0x11ce404, 0x385c000}, 0x39fe000)
Oct  5 09:35:10 imatorchi24 kernel: [  697.872434] device mon0 left promiscuous mode
Oct  5 09:35:10 imatorchi24 bettercap-launcher[459]: #011/usr/local/go/src/net/http/server.go:2936 +0x304

Then:
O```
ct 5 09:35:10 imatorchi24 bettercap-launcher[459]: #11/usr/local/go/src/os/exec/exec.go:716 +0x8f4
Oct 5 09:35:11 imatorchi24 systemd[1]: bettercap.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Oct 5 09:35:11 imatorchi24 systemd[1]: bettercap.service: Failed with result 'exit-code'.
Oct 5 09:35:41 imatorchi24 systemd[1]: bettercap.service: Service RestartSec=30s expired, scheduling restart.
Oct 5 09:35:41 imatorchi24 systemd[1]: bettercap.service: Scheduled restart job, restart counter is at 1.
Oct 5 09:35:41 imatorchi24 systemd[1]: Stopped bettercap api.rest service..
Oct 5 09:35:41 imatorchi24 systemd[1]: Started bettercap api.rest service..
Oct 5 09:35:41 imatorchi24 rfkill: unblock set for all
Oct 5 09:35:41 imatorchi24 kernel: [ 728.699329] brcmfmac: brcmf_cfg80211_set_power_mgmt: Forcing power management
Oct 5 09:35:41 imatorchi24 kernel: [ 728.699348] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Oct 5 09:35:41 imatorchi24 bettercap-launcher[1725]: command failed: Operation not supported (-95)
Oct 5 09:35:41 imatorchi24 kernel: [ 728.837096] brcmfmac: brcmf_vif_add_validate: Attempt to add a MONITOR interface...
Oct 5 09:35:41 imatorchi24 kernel: [ 728.837116] brcmfmac: brcmf_vif_add_validate: ... there is already a monitor interface, returning EOPNOTSUPP
Oct 5 09:35:41 imatorchi24 kernel: [ 728.837134] ieee80211 phy0: brcmf_cfg80211_add_iface: iface validation failed: err=-95
Oct 5 09:35:42 imatorchi24 bettercap-launcher[1725]: grep: /sys/class/net/eth0/operstate: No such file or directory
Oct 5 09:35:43 imatorchi24 bettercap-launcher[1725]: WARNING: Terminal colors have been disabled, view will be very limited.
Oct 5 09:35:43 imatorchi24 bettercap-launcher[1725]: bettercap v2.32.0 (built for linux arm with go1.20.6) [type 'help' for a list of commands]
Oct 5 09:35:43 imatorchi24 bettercap-launcher[1725]: Are you sure you want to quit this session? y/n [09:35:43] [sys.log] [inf] api.rest api server starting on http://127.0.0.1:8081
Oct 5 09:37:51 imatorchi24 systemd[1]: Stopped target Timers.

[aluminum-ice]

It's nexmon dying. Setting the parameter to reboot the machine when it's blind will fix the problem. The error logs are showing you that my changes to bettercap.py are catching the exception versus simply crashing the code. This makes it more likely it will auto reboot as it should when it notices it's blind.