mixxxdj / mixxx

Mixxx is Free DJ software that gives you everything you need to perform live mixes.
http://mixxx.org
Other
4.54k stars 1.28k forks source link

Log file is abnormally huge (21GB+) #13660

Closed nPrevail closed 1 day ago

nPrevail commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

Also the Traktor Kontrol S2 is working fine?

nPrevail commented 2 months ago

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

nPrevail commented 2 months ago

@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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

Mixxx & Traktor S2 MK1 09.18.24.txt

Done

JoergAtGithub commented 2 months ago

Mixxx.Traktor.S2.MK1.09.18.24.txt

This looks normal

nPrevail commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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

Does the Windows logfile also contain such error messages?

JoergAtGithub commented 2 months ago

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

JoergAtGithub commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

The mixx.log limit is here: https://github.com/mixxxdj/mixxx/pull/13684

nPrevail commented 2 months ago

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 https://github.com/mixxxdj/mixxx/issues/13660#issuecomment-2365887645, 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 commented 2 months ago

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

daschuer commented 2 months ago

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

The error message is generated here https://github.com/mixxxdj/mixxx/blob/64a42484a8aa78effba56ab50c4e4f528a7369ce/src/controllers/hid/hidiothread.cpp#L102 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 commented 2 months ago

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 commented 2 months ago

This https://github.com/mixxxdj/mixxx/pull/13692 Avoids to repeat the same error over and over again.

Swiftb0y commented 2 weeks ago

At least the log size issues has been fixed by https://github.com/mixxxdj/mixxx/pull/13692, right?