Log file is abnormally huge (21GB+)

[nPrevail]

Bug Description

I was using my Traktor S2 MK1 controller in Mixxx, and everything operationally worked fine. After closing Mixxx, I noticed an incredibly large mixxx.log file had been created, as big as 21GB+

I ran tail and produced two .txt files showing the first 3800 lines and the last 2000 lines of code.

I run NixOS stable, and unfortunately it only supports up to Mixxx 2.4.0.

mixxx.extract (first 3800+).txt
mixxx.extract (last 2000).txt

Version

2.4.0

OS

NixOS 24.05

[JoergAtGithub]

It looks like you've no access rights to this device - neither read nor write.

Could you check that the udev rules are properly set: https://github.com/mixxxdj/mixxx/blob/main/res/linux/mixxx-usb-uaccess.rules

[nPrevail]

That's interesting...

The only udev rule I've written for my NixOS config is services.udev.packages = [pkgs.mixxx]; Yet, my USB devices seem to work fine.

I'm gonna see if adding services.udev.enable = true; fixes it

[JoergAtGithub]

Also the Traktor Kontrol S2 is working fine?

[nPrevail]

Yes! I haven't had any issues using the S2, or any other controller.

[nPrevail]

@JoergAtGithub Actually, there's one minor thing with the S2 Mk1, and this might be a separate issue for me to file: the Effects buttons on both Effects banks (left and right of the deck) don't light up when engaged. Not sure if this is related to the "Device disconnected" message I'm getting in both logs.

[JoergAtGithub]

According to the logs posted above, the problem affects both Input and Output:

 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to send data to device : "No such device"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to send data to device : "No such device"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"
 [HidIoThread Traktor Kontrol S2 9E2E_3] Unable to read buffered HID InputReports from "Traktor Kontrol S2 9E2E_3" : "hid_read_timeout: unexpected poll error (device disconnected)"

[JoergAtGithub]

I can't imagine how this mapping can work, as the hidapi function hid_read_timeout does an early return after storing this message:
https://github.com/libusb/hidapi/blob/master/linux/hid.c#L1142-L1149

Could you run mixxx --controller-debug and attach the output.

[nPrevail]

Could you run mixxx --controller-debug and attach the output.

Do I need to have the Traktor S2 Mk1 controller connected to my laptop? If so, I'll try to upload the output later this evening.

[nPrevail]

Mixxx & Traktor S2 MK1 09.18.24.txt

Done

[JoergAtGithub]

Mixxx.Traktor.S2.MK1.09.18.24.txt

This looks normal

[nPrevail]

What's interesting is that the LED lights on the effects banks are still not working on my S2 MK1, but after using it for 30+ minutes, the lights start to work... Not sure what's causing that issue.

I've had no issues like that on Windows, but on Linux, not even the mixxx --controller-debug command can detect it.

But regarding the abnormal log file size, I'm not sure why the S2 Mk1 caused that flood of messages...

[ronso0]

Unrelated to this specific issue:
as a safety net, can we install a file watcher that triggers something when a log file grows larger than 1 GB? This can be a real killer on low-tech devices with little space like RPi.
something could be eg. stop flushing the log to disk (if that's possible).

[JoergAtGithub]

I've had no issues like that on Windows, but on Linux,

Does the Windows logfile also contain such error messages?

[JoergAtGithub]

Did you build the Nix version of Mixxx yourself? Which version of hidapi is used?

[JoergAtGithub]

What's interesting is that the LED lights on the effects banks are still not working on my S2 MK1, but after using it for 30+ minutes, the lights start to work... Not sure what's causing that issue.

Is it possible that something else is running on your system, which access the controller too?
e.g. a Windows VM with the Native Instruments drivers installed?

[nPrevail]

I've had no issues like that on Windows, but on Linux,

Does the Windows logfile also contain such error messages?

Not sure. I haven't used Windows in some years now, but when I used to use the S2 MK1 on it, I had no connectivity issues.

[nPrevail]

Did you build the Nix version of Mixxx yourself? Which version of hidapi is used?

I didn't build it from the ground up; I've only added the Nix pkg from the repo.

My hidapi version is hidapi 0.14.0. It's what's included in Mixxx 2.4.0.

[JoergAtGithub]

Not sure. I haven't used Windows in some years now, but when I used to use the S2 MK1 on it, I had no connectivity issues.

Could you test with the same Mixxx version on systems other than Nix?

[daschuer]

Unrelated to this specific issue: as a safety net, ....

Yes, this has two aspects, the priority inversion when writing the file that may effect the Mixxx performance badly and the disk full condition, that may effects the stability of the whole OS. Both can be party stopper without a quick band aid for non techy users.

I think we should fix both, independent from the rout cause.

I will take a look.

[daschuer]

The mixx.log limit is here: #13684

[nPrevail]

I can test it on Flatpak. Would that suffice?

…

On Sun, Sep 22, 2024 at 12:57 AM JoergAtGithub ***@***.***> wrote: Not sure. I haven't used Windows in some years now, but when I used to use the S2 MK1 on it, I had no connectivity issues. Could you test with the same Mixxx version on systems other than Nix? — Reply to this email directly, view it on GitHub <#13660 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ANYETW556UY5C6EPDVRJAH3ZXZ2AFAVCNFSM6AAAAABOMOCNMCVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDGNRVHA4DONRUGU> . You are receiving this because you authored the thread.Message ID: ***@***.***>

-- Nelson "nPrevail" Nailat (224) 36N-PREV (224) 366-7738 www.nprevail.bandcamp.com www.mixcloud.com/hasi_la_pheeque "You got to have vision."

[JoergAtGithub]

That would help - if it's suffice depends on the result.

[daschuer]

The error message indicates that the "device device is disconnected"

The error message is generated here

mixxx/src/controllers/hid/hidiothread.cpp

Line 102 in 64a4248

qCWarning(m_logOutput) << "Unable to read buffered HID InputReports from"

https://github.com/libusb/hidapi/blob/ba28d382cbe4e5d44ad52d395479c41392b43c87/linux/hid.c#L1143
It has been introduced in hidapi-0.13.0, our vendored version is hidapi-0.11.2
(Btw: We can drop the vendored hidapi in main since Ubuntu Jammy is on 0.11.2)

So the "Log file is abnormally huge (21GB+)" issue is a kind of regression of since hidapi-0.13.0.

One of this happens:
POLLERR Error condition, write or read end closed.
POLLHUP peer closed its end of the channel.
POLLNVAL Invalid request: fd not open

Details: https://man7.org/linux/man-pages/man2/poll.2.html#RETURN_VALUE

Unfortunatly the implementation hides these detals for us. We only receive -1 either for timout or disconnected.

However our code does not consider the disconnected state at all.
Is that a problem? What happen if we disconnect and reconnect the controller?

Can one test that on Linux? I don't have a working HID device.

[JoergAtGithub]

There is no disconnect state in hidapi. There is a hot-plugging development branch, but this is not released. For now, if a device looses connection before closing the device, we must shutdown our application and restart it to get access to this device again.

There seems something wrong with this file handles on this particular NIX system and we need to find out what.

There are many errors, that hidapi can report, but this is done by the message string, not by the return value. Most error messages are just relayed from the particular operating system and not generated by hidapi itself - there is not such a concept like error codes in hidapi.
A timeout of hid_read_timeout is not an error. But we don't use the timeout functionality anyway.

[daschuer]

This #13692
Avoids to repeat the same error over and over again.

[Swiftb0y]

At least the log size issues has been fixed by #13692, right?