Spleeter: No output or error log for most song-length input on Ubuntu-for-Windows (WSL)

[awesomer]

Description

I have tested about 15 different songs, and only 3 of them produced any output at all. My environment is a little unusual, I'm using spleeter-cpu on WSL (Ubuntu-for-Windows).

I get the "loading audio from 0.0 to 600.0" message and then it grinds for a few minutes consuming all CPU, and then just exits. The contents of "$?" after failure is 0, indicating successful exit (or that the program doesn't properly set result codes). Sometimes only one of the models will produce any output for a given input file. Except for audio_example.mp3, which works as expected, I've yet to have the "[x]stems" model actually produce [x] output files. When there is output, I get 1 or 2 files at most, usually the vocal. I have tried FLACs, WAVs, and mp3s as input.

In response to the FAQ, I have tried chunking my input into 1, 2, and 3 minute chunks. 1 and 2 minutes work, but at 3 minutes, I only get a single vocal file and no accompaniment file.

I have 24gb of RAM on this system, and there is no dmesg log of OOMkilling, so I doubt that it's out-of-memory concerns resulting in no output. Watching the process running in Resource Manager, it uses about 5gb of RAM, and there's multiple gigs of RAM sitting unused.

The output of ulimit does not suggest that my shell is limiting available RAM.

max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
virtual memory          (kbytes, -v) unlimited

Please let me know if there is any debug mode or log that might be helpful in understanding what is happening.

Step to reproduce

1) spleeter separate -i input/track_length_input_file.mp3 -p spleeter:2stems -o audio_output/
2) notice there is no output or log

Output

None that is relevant to the issue. If the sub-process is crashing or being killed, it seems like the number one priority to avoid user confusion would be for some part of the stack to generate an error log.

Environment

| | |
| ----------------- | ------------------------------- |
| OS | Windows / Linux |
| Installation type | Conda |
| RAM available | 24gb DDR3 |
| Hardware spec | i7-2600k |

[Faylixe]

Possibly linked to #29. Meanwhile would you mind trying on another platform and not WSL ? Docker or Windows directly would be nice so we can see if the issue is WSL specific of rather associated to the track you try to separate.

[awesomer]

I've tried to increase the timeout (to 600) per #29 and noticed no difference in outcome in the WSL install.

I rebooted the same machine to Ubuntu 1804 and installed conda and associated packages in the same way as on WSL. I was unable to get spleeter-gpu working there (will file a different bug) but was able to split 100% of the time, on the same input files, with spleeter-cpu. The only meaningful difference in ulimit there is a larger amount of lockable memory, which is unlikely to be relelvant. So ultimately there must be something else about memory allocation either in windows generally or in the WSL Ubuntu environment, or some other cause of abnormal termination. Is there any log I can consult for clues?

I tried stracing the main process and it seems to just see the workers timeout. When I try to strace the worker threads, I don't see any meaningful action despite them consuming large amounts of CPU. The system, as reported by top, has gigabytes of RAM and swap available at all times up until failure. It seems to be chugging along, mostly allocating memory, until this timeout, which, if I'm reading this strace properly, then prompts it to kill its children? (edited to only refer to the parent thread pid)

[pid 1147] select(0, NULL, NULL, NULL, {tv_sec=0, tv_usec=0} [pid 1147] <... select resumed> ) = 0 (Timeout)
[pid 1147] write(7, "\0\0\0\4\200\3N.", 8) = 8
[pid 1147] wait4(1157, 0x7fffe193dc74, WNOHANG, NULL) = 0
[pid 1147] kill(1157, SIGTERM

I will do my best to try on Windows directly ASAP, to see if it affects me there as well.

[mmoussallam]

Ok so we think we have found an explanation for this and it's linked to the way we call ffmpeg. We're currently testing an alternative and we'll keep you posted.

[Faylixe]

You can already try the version from the fix-ffmpeg branch and check if it is fixing the problem (and it would be great to have your feedback regarding your configuration for this version).

You can simply perform following command from your conda environment :

git clone --branch fix-ffmpeg https://github.com/deezer/spleeter.git
cd spleeter
pip install .

Then run your separation as usual.

[awesomer]

I installed by checking out from git into a new directory, and then creating a new conda environment called "spleeter-cpu-fix" by editing the name in the conda/spleeter-cpu.yaml file. This didn't work.

I then did the above, and it said it was "Installing collected packages: future, ffmpeg-python, spleeter" and it worked. I was able to successfully process an input FLAC of the max duration (10 minutes). This suggests that the conda file might also need to reflect "future" and "ffmpeg-python"?

spleeter separate -i ../spleeter/input/my_input_file.flac -o ../spleeter/audio_output/ -p ../spleeter/configs/4stems_full/base_config.json

As an aside, I'm trying to enable debug logging, and did the following in spleeter/__main__.py :

- if arguments.verbose:
- enable_tensorflow_logging()
+ #if arguments.verbose:
+ enable_tensorflow_logging()

And it doesn't seem to enable DEBUG log level in tensorflow. Am I missing something?

Edits : positive results of further testing.

[Faylixe]

I installed by checking out from git into a new directory, and then creating a new conda environment called "spleeter-cpu-fix" by editing the name in the conda/spleeter-cpu.yaml file. This didn't work.

I then did the above, and it said it was "Installing collected packages: future, ffmpeg-python, spleeter" and it worked. I'm trying with longer test input now, but initial testing looks good. This suggests that the conda file might need to reflect "future" and "ffmpeg-python"?

Yes the current branch did not reflect in the conda environment, and should be installed manually, we will improve that as long as the fix is validated. Good to hear that the fix is working, hope it will work also at a larger scale.

As an aside, I'm trying to enable debug logging, and did the following in spleeter/main.py :

• if arguments.verbose:
• enable_tensorflow_logging()
• #if arguments.verbose:
• enable_tensorflow_logging()

And it doesn't seem to enable DEBUG log level in tensorflow. Am I missing something?

Logging is still in progress. Actually we totally disabled Tensorflow logging except for ERROR level in standard mode, and Tensorflow INFO level for the verbose mode, which can be trigger using --verbose flag when running Spleeter from command line.

[Faylixe]

The new version is uploaded on PyPi and conda environment files has been updated, please check and let us know if you face any other similar issues :)