Core: Log filled with error messages : [websocket] error from callback [...] on_message() missing 1 required positional argument: 'message'

[nicolasvila]

Home Assistant release with the issue:

Home Assistant 0.91.4

Last working Home Assistant release (if known):

No problem found on HomeAssistant v0.91.1 (and maybe 0.91.2)
Problem occured since v0.91.3+

Operating environment (Hass.io/Docker/Windows/etc.):

ArchLinuxARM
Kernel: armv7l Linux 5.0.7-1-ARCH
Board Odroid-U3 (armv7)
HassIO installation (using odroid-xu official docker image: armv7)

Component/platform:

Concerns both Home Assistant (standalone, or HASSIO installation)

Description of problem:

The log is filled by error messages related to WebSocket: missing 1 required positional argument: 'message'
Check the log below.
Maybe related to issue https://github.com/home-assistant/home-assistant/issues/17532

Traceback (if applicable):

[...]
2019-04-17 13:06:08 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-04-17 13:06:38 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-04-17 13:07:08 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-04-17 13:07:38 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-04-17 13:08:08 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'

[ccorderod]

Hi Nicolas. Did you fix this error?
I have a similar issue:

2019-05-05 20:37:16 ERROR (Thread-11) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-12, initial daemon)>>: on_message() missing 1 required positional argument: 'message'

Txs.

[nicolasvila]

No I still have this error, even with latest update:

2019-05-06 08:41:13 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'

[rytilahti]

It is really hard to say without knowing what integration causes this, but it's likely dyson (https://github.com/home-assistant/home-assistant/search?q=on_message&unscoped_q=on_message) -- could you please confirm?

[ccorderod]

Nope. No Dyson integration in my setup. Still have the problem after the upgrade to 0.93.1.

[nicolasvila]

Same for me still have the issue with the latest version: 0.93.1

2019-05-18 14:07:21 ERROR (Thread-3) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-4, initial daemon)>>: on_message() missing 1 required positional argument: 'message'

[nicolasvila]

is there any way to have a more "verbose" log? I suppose it's related to one sensor or component. It could help to enable the full stack trace when an error message occurs.

[rafaalbelda]

I have the same error since some months ago (don´t know exactly).

websocket-client version is 0.37.0
Homeassistant version is 0.93.1
one error every 30 seconds
No dyson configured

2019-05-19 12:42:00 ERROR (Thread-26) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-27, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-05-19 12:42:30 ERROR (Thread-26) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-27, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-05-19 12:43:00 ERROR (Thread-26) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-27, initial daemon)>>: on_message() missing 1 required positional argument: 'message'
2019-05-19 12:43:30 ERROR (Thread-26) [websocket] error from callback <bound method Listener.on_message of <Listener(Thread-27, initial daemon)>>: on_message() missing 1 required positional argument: 'message'

[rytilahti]

Ah, okay, so it is probably then coming from some dependency. I cannot think any other way than going to the directory where the dependencies are installed, and do grep -R on_message * or ag on_message (if ag is installed) to try to locate the source for it.

[nicolasvila]

I found the log in the main HomeAssistant docker instance. I don't think this bug is related to an addon. I'm wondering if this could be related to ddwrt or nmap device tracker (there are plenty of traces when no MAC address is returned)
Anybody on this thread using those trackers?

[...]
{"log":"2019-05-17 17:26:43 INFO (SyncWorker_19) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.100\n","stream":"stderr","time":"2019-05-17T15:26:43.517948802Z"}
{"log":"2019-05-17 17:26:46 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12\n","stream":"stderr","time":"2019-05-17T15:26:46.004748
96Z"}
{"log":"2019-05-17 17:26:46 INFO (SyncWorker_6) [homeassistant.components.ddwrt.device_tracker] Checking ARP\n","stream":"stderr","time":"2019-05-17T15:26:46.0161106Z"}
{"log":"2019-05-17 17:26:48 INFO (SyncWorker_13) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.10.100\n","stream":"stderr","time":"2019-05-17T15:26:48.181308081Z"}
{"log":"2019-05-17 17:26:48 INFO (SyncWorker_13) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.10.127\n","stream":"stderr","time":"2019-05-17T15:26:48.257888015Z"}
{"log":"2019-05-17 17:26:51 ERROR (Thread-3) [websocket] error from callback \u003cbound method Listener.on_message of \u003cListener(Thread-4, initial daemon)\u003e\u003e: on_message() missing 1 required positional argument: 'message'\n"
,"stream":"stderr","time":"2019-05-17T15:26:51.775266651Z"}
{"log":"2019-05-17 17:26:56 INFO (SyncWorker_1) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.1\n","stream":"stderr","time":"2019-05-17T15:26:56.382328342Z"}
{"log":"2019-05-17 17:26:56 INFO (SyncWorker_1) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.23\n","stream":"stderr","time":"2019-05-17T15:26:56.40643704Z"}
{"log":"2019-05-17 17:26:56 INFO (SyncWorker_1) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.100\n","stream":"stderr","time":"2019-05-17T15:26:56.430751822Z"}
{"log":"2019-05-17 17:26:59 INFO (SyncWorker_12) [homeassistant.components.ddwrt.device_tracker] Checking ARP\n","stream":"stderr","time":"2019-05-17T15:26:59.021807397Z"}
{"log":"2019-05-17 17:27:09 INFO (SyncWorker_7) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.1\n","stream":"stderr","time":"2019-05-17T15:27:09.427496519Z"}
{"log":"2019-05-17 17:27:09 INFO (SyncWorker_7) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.23\n","stream":"stderr","time":"2019-05-17T15:27:09.451933842Z"}
{"log":"2019-05-17 17:27:12 WARNING (MainThread) [homeassistant.components.device_tracker] Updating device list from nmap_tracker took longer than the scheduled scan interval 0:00:12\n","stream":"stderr","time":"2019-05-17T15:27:12.004531
855Z"}
{"log":"2019-05-17 17:27:12 INFO (SyncWorker_17) [homeassistant.components.ddwrt.device_tracker] Checking ARP\n","stream":"stderr","time":"2019-05-17T15:27:12.008146401Z"}
{"log":"2019-05-17 17:27:14 INFO (SyncWorker_11) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.10.100\n","stream":"stderr","time":"2019-05-17T15:27:14.526794159Z"}
{"log":"2019-05-17 17:27:14 INFO (SyncWorker_11) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.10.127\n","stream":"stderr","time":"2019-05-17T15:27:14.550657482Z"}
{"log":"2019-05-17 17:27:21 ERROR (Thread-3) [websocket] error from callback \u003cbound method Listener.on_message of \u003cListener(Thread-4, initial daemon)\u003e\u003e: on_message() missing 1 required positional argument: 'message'\n"
,"stream":"stderr","time":"2019-05-17T15:27:21.775402101Z"}
{"log":"2019-05-17 17:27:22 INFO (SyncWorker_4) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.1\n","stream":"stderr","time":"2019-05-17T15:27:22.169667158Z"}
{"log":"2019-05-17 17:27:22 INFO (SyncWorker_4) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.23\n","stream":"stderr","time":"2019-05-17T15:27:22.194119189Z"}
{"log":"2019-05-17 17:27:22 INFO (SyncWorker_4) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.100\n","stream":"stderr","time":"2019-05-17T15:27:22.218608763Z"}
{"log":"2019-05-17 17:27:25 INFO (SyncWorker_7) [homeassistant.components.ddwrt.device_tracker] Checking ARP\n","stream":"stderr","time":"2019-05-17T15:27:25.022975218Z"}
{"log":"2019-05-17 17:27:35 INFO (SyncWorker_2) [homeassistant.components.nmap_tracker.device_tracker] No MAC address found for 192.168.1.1\n","stream":"stderr","time":"2019-05-17T15:27:35.459523413Z"}
[...]

[ccorderod]

@nicolasvila I am using nmap for device tracking in my setup. no ddwrt. no errors from nmap in my log.

[ctrl50]

just want to pop in and say i got this same error this morning after installing PushBullet and enabling it.

currently trying to figure out how to fix..

[nicolasvila]

Not using PushBullet but Telegram. Still haven't found how to enable debug
messages

Le sam. 1 juin 2019 à 08:04, ctrl50 [e-mail] a écrit :

just want to pop in and say i got this same error this morning after
installing PushBullet and enabling it.

currently trying to figure out how to fix..

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/home-assistant/home-assistant/issues/23161?email_source=notifications&email_token=AABEBTU4YVZ6ENK2F5KQEX3PYIGPRA5CNFSM4HGTHNZKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODWWZV6A#issuecomment-497916664,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AABEBTSYTHRDAPE2IITUBC3PYIGPRANCNFSM4HGTHNZA
.

[ctrl50]

https://www.home-assistant.io/components/logger/

?

[ccorderod]

Thank you @ctrl50. I have disabled Pushbullet notifications platform and those pesky msgs went away.

[ctrl50]

Your welcome.

[ctrl50]

alright well.

I fixed my issue, _app.py line 339 to 351 change to:

    def _callback(self, callback, *args):
        if callback:
            try:
                callback(self, *args)
            except Exception as e:
                _logging.error("error from callback {}: {}".format(callback, e))
                if _logging.isEnabledForDebug():
                    _, _, tb = sys.exc_info()
                    traceback.print_tb(tb)

This code is from an older version that i kept seeing referenced with this issue.. its working fine for me now, your results may vary, Enjoy.

source: https://github.com/websocket-client/websocket-client/blob/v0.48.0/websocket/_app.py

[ctrl50]

Not using PushBullet but Telegram. Still haven't found how to enable debug messages Le sam. 1 juin 2019 à 08:04, ctrl50 [e-mail] a écrit :

seems its an issue with websockets. _app.py compare your version at line 339 with the info i posted. may fix it.

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[nicolasvila]

The issue is still present on the latest version and I would like to have some insight in order to dig further the problem, and try to debug. Problem is I don't know where to start. I don't have the full stacktrace and I don't know the name of the faulty component (I just have the thread reference.

[ctrl50]

Nicola. I posted the fix in this comment.

https://github.com/home-assistant/home-assistant/issues/23161#issuecomment-498007144

Open the websockets component folder. Find. _app.py and change the coding as referenced in that post.
Done deal. Hasnt been an issue since then.

[nicolasvila]

Thanks for the tip. No more garbage in my log file ;-)

[stale[bot]]

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.
Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍
This issue now has been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

[TRusselo]

still getting this error with pushbullet enabled in configuration.yaml

[rv-kip]

The error flood went away when I disabled the Pushbullet integration