getplugins.php - 5.7s load time

[BloodyIron]

Please complete the following tasks.

• Web browser cache cleared
• Link provided to install script if applicable
• Web browser, ruTorrent, PHP and OS version provided

Tell us about your environment

Vivaldi, browser
Using: crazymax/rtorrent-rutorrent:latest

Tell us how you installed ruTorrent

crazymax/rtorrent-rutorrent:latest (k8s in yaml manifest via argoCD)

Describe the bug

When loading the webGUI getplugins.php takes 5.7 seconds to load EVERY time, and the page takes that long to load EVERY time.

Steps to reproduce

Literally load the page or refresh

Expected behavior

Load time in the realm of 5-15ms

Additional context

Original thread in other repo : crazy-max/docker-rtorrent-rutorrent#182

[stickz]

Hi @BloodyIron, this is probably specific to your configuration or hardware. What I suggest doing is installing vmtouch. It will take about 50mb of ram and hard drive space to cache the ruTorrent web client into memory.

If you're interested in steps for this solution, please provide more details about the hardware and operating system.

[BloodyIron]

Well it's a container, so that would be wiped away if it were to ever be re-initialised.

The container runs in a 3x node k8s cluster, each node in a VM on Proxmox VE (Linux KVM) with pretty good underlying hardware for the compute (one of the nodes is a Dell R720, the others are FX-8320 based).

The storage that backs the application aspect (not the torrent content) runs on a FreeNAS system with ZFS, and is striped-mirrored SSDs (4x total), and the network interconnects are multiple 1gige LACP bonds.

I do not realistically see any network, storage, CPU, or other forms of hardware contention. Multiple other websites I run on the same infra run substantially faster, and it's strictly this one php file that drags its heels.

[stickz]

@BloodyIron Any update on this issue? Did you upgrade to ruTorrent version 4.0 stable through your docker install script? Have you tried anther web browser (such as Google Chrome)? This could be a web browser problem.

There are web developer tools on chromium you can use to debug this issue. You can record the web page for 10 seconds while it loads, then get detailed information about what is causing the problem.

[BloodyIron]

@stickz well this is a new one, a developer haunting me for an update! haha! XD I love it!

Okay. so I wasn't aware that crazy-max ( https://github.com/crazy-max/docker-rtorrent-rutorrent/releases ) had released a new version (plus I've been AFK for the last 4-ish days). So I'll try that image after I send this message. Just to clarify though this isn't... "my" script or anything like that. I'm simply using the docker image in kubernetes, feeding it settings, and that's about it.

As for other browsers, I can't remember which browsers I tested it with, but I can test again with multiple browsers, and as a point of relevant interest my primary browser is Vivaldi, which is a Chromium derivative (but I can test Firefox/others too).

As for the developer console, that's how I was able to get the loading time for this file in the first place. I didn't record the waterfall load, I would just have the developer console open, then load the page, then watch and review.

I'll switch to the new image shorty and report back. By the way, seriously loving your support here! Thanks a tonne! :)

[BloodyIron]

@stickz okay so I had to explicitly use "crazymax/rtorrent-rutorrent:4.0-0.9.8-0.13.8" as I wasn't sure if "latest" was actually delivering the new ruTorrent... and now I have v4.0 running, however the problem persists. In all three tests below, I was using incognito mode, and was also ctrl+f5'ing to force any cache drop/regeneration.

Load times of getplugins.php:

• Vivaldi: 7.48s
• Firefox: 7.28s
• Chrome: 11.64s

I don't know why Chrome had a spike in load times, but yeah... here we are... And these load times were really the same after multiple refresh/reload/ctrl+f5's, so it doesn't look to be a load-once problem.

I also want to clear up that this is not an underlying hardware issue (so far as evidence shows), as I have other containers running websites (like argoCD, for example) which load substantially faster (500ms in the example of argoCD). And I do not observe any CPU, RAM, networking, or disk contention that could contribute to this (especially since the majority of this content is likely cached in RAM by the container, speculation though).

I would like to add, however, that there are rendering issues in Vivaldi. I do not know why they happen. I will not be posting a screenshot (as well... there's sensitive information), so I'm going to describe it as best I can. This rendering issue does not seem to happen in Firefox or Chrome so yeah...:

1. In the "State" section, the icons are repeated for the full width (and beyond) of that sub-section
2. The "bubbles" showing # of torrents, plus size per label/tracker, is dark-ish grey text, on a light-ish grey background, extra hard to read (this appears to be limited to the left bar, but is present in State, Labels, Search, and Trackers).

I'm going to roll back to the pre-v4.0 image as I want to be able to read this text, but should you want me to test more, then I gladly will :)

[stickz]

@BloodyIron

1. If you would like to do more testing, I would recommend using the web developer tools on Chrome. You can record a page refresh. I would like to see a screenshot of the network waterfall in the performance tab. I'm specially interested in getplugins.php You can use the snipping tool to only capture the web developer tools. You will be able to preview the image before posting it and only capture a specific section of your screen (so sensitive information is not exposed).

2. Setting $do_diagnostic to false in /conf/conf.php will improve your loading time, at the expense of less debugging information. It's safe to change this value, once your ruTorrent installation is working properly.

3. We never recommend using version 3 anymore because it's full of bugs and performance issues. If you're not able to provide screenshots to help us improve support for Vivaldi, I would recommend using Firefox or Chrome instead. It's worth it to change web browsers for version 4. It's significantly more polished and will result in a much smoother experience.

[BloodyIron]

Hi @stickz

Oddly enough, switching back to crazymax/rtorrent-rutorrent:4.0-0.9.8-0.13.8 the previously mentioned graphical issues in Vivaldi don't exist... and it's confusing lol. Let's just ignore that for now and if it happens again I'll try to provide something actually useful around that (for now I'll keep crazymax/rtorrent-rutorrent:4.0-0.9.8-0.13.8 as my daily driver).

As for your screenshot requests... here's the one you asked for:

Here are two additional ones that are not what you asked for but may be helpful anyways... :

As for the conf.php file, that file doesn't exist in the docker image except under folders for different plugins, so I'm unsure the "proper" way to do that with this particular container... What kind of performance timing difference are we talking about here for disabling $do_diagnostic ? Is that an environment variable I can pass to it perhaps?

[stickz]

The file does exist, it's right here. ruTorrent will not function without it. $do_diagnostic = false; could have a major impact.
https://github.com/Novik/ruTorrent/blob/master/conf/config.php

Also, while you're in there, ensure $phpUseGzip = false; is set. Enabling PHP gzip could cause this problem to happen.

[BloodyIron]

Okay I found the config.php file, I somehow missed it first time I looked and it wasn't quite where I anticipated it in the container (despite searching the whole root/recursive file structure). Anyways...

phpUseGzip is set to false, do_diagnostic is set to false, and getplugins.php is still averaging about 5.7s load time

I have explicitly confirmed those variables are set to false in the running config.php

[n1ce-0ne]

sorry to butt in, im just reading along / following / happy to help if i can, im just wondering BloodyIron,
as per this comment here: #1878 (comment)

have you tried disabling plugins or 'moved' plugins like they call it, to try narrow down which if any are causing it?

i ask because they seem to have identified which plugin is actually causing it 'extsearch' in there case.

if that could be possible in your case maybe it could help?

ignore me if not, just enjoy this sorta stuff :)

[BloodyIron]

@n1ce-0ne yeah I had seen that particular one suggested as disabling, so these are the ones that I've had disabled this whole time:

diskspace,extsearch,feeds,filedrop,geopip2,ipad,rss,rssurlrewrite,unpack

[liaralabs]

I'm currently facing a similar issue on a multi-tenant box.

ruTorrent is hosted on an SSD drive, rTorrent is hosted on individual drives.

For several users, ruTorrent getplugins.php loads sub 1 second, with every plugin loaded. However, two users sharing the same drive are facing ~6 second script times for the getplugins.php script.

Underlying drive has almost zero activity, so it doesn't seem to be directly related to disk activity on the underlying rTorrent (xmlrpc) device.

If I disable the FileManager plugin, load times go to 3 seconds (still high). Other users on the server are able to have 1 second load times even with FileManager enabled.

That said, a slow trace is largely indicating that the stack time is getting spent caught in the xmlrpc calls:

[27-Jan-2023 21:49:34]  [pool user] pid xxxxxxx
script_filename = /srv/rutorrent/php/getplugins.php
[0x00007f360a2147f0] fread() /srv/rutorrent/php/xmlrpc.php:110
[0x00007f360a2146a0] send() /srv/rutorrent/php/xmlrpc.php:184
[0x00007f360a2145c0] run() /srv/rutorrent/php/getplugins.php:176
[0x00007f360a2144c0] findRemoteEXE() /srv/rutorrent/plugins/filemanager/init.php:28
[0x00007f360a214390] [INCLUDE_OR_EVAL]() /srv/rutorrent/php/getplugins.php:495

Disabling FM still gets caught in xmlrpc time

[27-Jan-2023 22:16:42]  [pool user] pid xxxxxxx
script_filename = /srv/rutorrent/php/getplugins.php
[0x00007f14bb614870] fread() /srv/rutorrent/php/xmlrpc.php:110
[0x00007f14bb614720] send() /srv/rutorrent/php/xmlrpc.php:184
[0x00007f14bb614640] run() /srv/rutorrent/php/getplugins.php:176
[0x00007f14bb614390] findRemoteEXE() /srv/rutorrent/php/getplugins.php:403

ruTorrent version is v4.0-beta3 for all users.

Honestly, can't explain anything beyond potentially some weird intra-drive differences in the ability to make xmlrpc calls to the rTorrent interface, even though the drive itself is mostly idle.

[stickz]

@liaralabs @BloodyIron Please give aeb9f62 a try and set $localHostedMode to true in the config.php file.

[liaralabs]

I just cherry-picked the commit to the install in question and it seems to have made some improvement. 2.5 seconds with filemanager and 1.4 or so with it disabled.

Still some time spent in the unpack plugin (same with filemanager).

Took a peek at findRemoteEXE() /srv/rutorrent/plugins/unpack/init.php:11 and realized that was because do_diagnostic. With do_diagnostic false and localhostedmode true, I get 500ms load times on the page now with filemanager disabled. Nice work!

[n1ce-0ne]

progress, great to see :)

[stickz]

Took a peek at findRemoteEXE() /srv/rutorrent/plugins/unpack/init.php:11 and realized that was because do_diagnostic. With do_diagnostic false and localhostedmode true

Thanks for the feedback. We can add $localHostedMode support to the unpack plugin.

I get 500ms load times on the page now with filemanager disabled. Nice work!

You should be able to get similar loading times with $do_diagnostic set to true, once this is completed. Changing $do_diagnostic to false is a developer's worse nightmare. It will make bugs harder to find and report for everyone.

I will also separate bin diagnostics, so these can be disabled. This will allow faster look-ups of binaries by caching shell results. An install script should not require bin diagnostics. It can delete which.dat file every time it upgrades instead for the same impact.

[BloodyIron]

@stickz I switched to "crazymax/rtorrent-rutorrent:4.0.1-0.9.8-0.13.8" which, according to your discussion with CrAzY mAx here ( crazy-max/docker-rtorrent-rutorrent#215 ) should already have what you propose in it.

Results????:

un-cached (ctrl+F5) getplugins.php : 6.9s
-total load : 7.87s-11.49s
cached (regular F5 after first load) getplugins.php : 1-2ms (MILLISECONDS not seconds)
-total load: 1.61s-2.29s

Now, the uhhh... weird... thing is... I don't seem to have the plugin "filemanager" loaded, enabled... or even disabled...

These are the plugins I have disabled (copy paste from YAML): "diskspace,extsearch,feeds,filedrop,geopip2,ipad,rss,rssurlrewrite,unpack"

So not sure what to make of the filemanager plugin thing...

But yeah, SUBSTANTIALLY IMPROVED! At this point "action.php" seems the slowest with load times of ~950ms (or similar) at a few points. (maybe last area for speed improvement? but this is very usable now!)

Thanks to @crazy-max and @stickz plus anyone else that was involved! \o/

[BloodyIron]

Oh, and I still have RU_DO_DIAGNOSTIC (env variable equivalent) set to false. Should I set it to true now? Or... wait for something?

[BloodyIron]

@stickz oh also, the version in the help GUI for ruTorrent still says 4.0, not 4.0.1, maybe poke that with a stick sometime ;)

[liaralabs]

@BloodyIron file manager is a third party add-on. It's fairly popular, but it seems plausible your container author hasn't included it in the image.

I wouldn't worry too much about it -- after all, this wouldn't be the correct place to complain about issues in 3rd party plugins. Mostly brought it up as a point of comparison (since the plug-in runs its own check for remoteEXEs and the function is built in to ruTorrent)

[BloodyIron]

@stickz okay so I want to add that if I don't go to my ruTorrent set up for a while (hours) the initial load is still in the realm of like 5-8s. Naturally I didn't get an actual number since I didn't hit F12 before loading the page.

So this story may not be over just yet.

@liaralabs roger that! Thanks for the explanation :)

[liaralabs]

@stickz I'm giving the changes a more thorough testing today and I've bumped into the following issue. Not sure if it's unintended behavior or just a quirk of the change that is the way it is.

I'm working on adding localhostedmode = true to swizzin, but I've also swapped to loading the paths required in conf/config.php directly from the php environment (env[PATH]). I've basically realized that ruTorrent is non-functional after first setup now without hardcoding the php path in the config.php or setting localhostedmode = false. I'm assuming this is because we've just completely bypassed the check for EXEs?

Once the which.dat is generated for the user in question, the problem disappears and can no longer be reproduced so I'm guessing the which.dat is an important fallback which hasn't yet been generated for users in question on the first load.

[stickz]

@liaralabs this should be fixed in 0dbc009. I believe the problem was caused by setting $do_diagnostic to false. I would recommend waiting for version 4.0.2 hot fix. I will add unpack support for $localhostedmode for $do_diagnostic = true.

There is one more issue with file permissions I'm going to resolve. The $localhostedmode feature will not be used unless the executable has 755 or greater file permissions. This will ensure the optimization always works in all scenarios.

I will rush the release of version 4.0.2 today for you. It's highly recommended to set $do_diagnostic = true to detect problems. We are adding support to address the concerns in this issue report, to improve the loading time for users.

[liaralabs]

$do_diagnostic is left true already as per your previous recommendations. I toggled them off during debugging but the original error occurred with it already enabled

Also, please don't rush a release on account of me. The changes are just queued up in develop. No rush, and please enjoy your Sunday 😄

[stickz]

@liaralabs version 4.0.2 is live. https://github.com/Novik/ruTorrent/releases/tag/v4.0.2
If $cachedPluginLoading is left at false, it's not required to hard code paths. Changing $do_diagnostic is bug free now.

@BloodyIron in v4.0.2 $cachedPluginLoading=true will reduce loading time to 50ms. But it may be required to clear web browser cache every time you upgrade versions or install a new plugin. If you forget, it will be automatically cleared every day.

[blueberryapple]

@BloodyIron in v4.0.2 $cachedPluginLoading=true will reduce loading time to 50ms. But it may be required to clear web browser cache every time you upgrade versions or install a new plugin. If you forget, it will be automatically cleared every day.

@stickz is it recommended to set $cachedPluginLoading=true? I noticed it was hardcoded to false on the crazy max docker image. I am noticing a speed regression between 4.0.1 and 4.0.2

[BloodyIron]

@stickz I've set cachedPluginLoading=true (I assume the dollarsign is not needed?), and loaded the latest @crazy-max image with tag "latest". Multiple testing, incognito/not, including plenty ctrl+f5's, and I'm still getting 7s-8s loading times for getplugins.php.

I went to the shell for the running container, and verified the variable is set to true in the running environment.

I may be doing this "wrong" somehow, but... ?? also, do_diagnostic is currently set to "false",... I'm going to retest with it as "true" now....

[BloodyIron]

Yeah setting do_diagnostic to "true" does not appear to improve the situation, getting generally the same load times for getplugins.php :( I'm going to set that back to "false" now. Tidy IaC for me!

[Jolly-Pirate]

@BloodyIron the dollar sign is needed, it prepends all variables in PHP.

[BloodyIron]

@Jolly-Pirate well... uhhh... I'll try with the dollarsign then... HMB 🍺

[BloodyIron]

Yeah so "$" characters are invalid for kubernetes environment variables to be passed... so... not-workable, but pretty sure the variable is being applied... (I think?)

[Jolly-Pirate]

Why are you passing them as environment variables (I'm not familiar with kubernetes)? Edit them directly in the config.php of ruTorrent.

[BloodyIron]

@Jolly-Pirate because I'm running the container from @crazy-max and container storage is ephemeral. Environment variables are how things like this are configured (in this case). Editing config.php would be wiped next time it re-initialised. The do_diagnostics variable (as well as a whole bunch of others) was passed as an environment variable as part of how it is configured via IaC (Infrastructure as Code) in the YAML Manifest.

You might actually like containers ;) Worth learning IMO!

[blueberryapple]

@BloodyIron the config setting for the crazy max docker image is currently hard coded and not yet customizable. Refer to my comment above

[Jolly-Pirate]

I know what containers are, and I use docker a lot (never used kubernetes though). So in our case, I'm using https://github.com/romancin/rutorrent-docker. It has all plugins added and works nicely. The configuration files are mapped to a host folder, so I can edit them as I please. If you want to try it, the master branch is still on v3.10, so check out the develop branch that is up to date with 4.0.2. I made a pull request with several improvements and fixes as well romancin/rutorrent-docker#104

[liaralabs]

@BloodyIron you can't just pass arbitrary environment variables and expect that the container will know what to do with them. Env variables need to be mapped by the container somehow, or explicitly mapped in PHP to use xyz variable from the environment with a default fall back if undefined.

In the case of the container you're using, the environment variables are mapped to their proper locations on container initialization with a script: https://github.com/crazy-max/docker-rtorrent-rutorrent/blob/master/rootfs/etc/cont-init.d/03-config.sh

The only variables supported would be items which have actions in the init script above

ruT config starts here: https://github.com/crazy-max/docker-rtorrent-rutorrent/blob/master/rootfs/etc/cont-init.d/03-config.sh#L199

Notice the hard coded values which you can't override with the environment (which blueberryapple has already pointed out)

[stickz]

@BloodyIron in v4.0.2 $cachedPluginLoading=true will reduce loading time to 50ms. But it may be required to clear web browser cache every time you upgrade versions or install a new plugin. If you forget, it will be automatically cleared every day.

@stickz is it recommended to set $cachedPluginLoading=true? I noticed it was hardcoded to false on the crazy max docker image. I am noticing a speed regression between 4.0.1 and 4.0.2

This value should be set to false by default. The speed regression is due to the patched caching issues. Also, your very first load will be slower, as it's required to regenerate the binary path caches. Afterwards, they are saved to which.dat.

If users would like to customize this variable, there should be a configuration value added to the @crazy-max docker image. However, there should be an implied warning that it may cause caching issues when upgrading versions.

[BloodyIron]

okay so... I'm still having the slow performance, am I waiting to test more changes upcoming or something? I'm not sure if there's something specifically for me to do at this time.

And yeah, I see what the above comments are saying about this variable not being handled in the same way, in my case.

[stickz]

@BloodyIron Consider trying the latest version of docker-ruTorrent. Change the environment variable RU_CACHED_PLUGIN_LOADING to true. https://github.com/crazy-max/docker-rtorrent-rutorrent

Optionally, you can change RU_PLUGIN_JS_CACHE_EXPIRE to a higher value like 30*60*24 for 30 day caching. However, it will almost definitely be required to clear the web browser cache when upgrading versions.

Other users have reported loading times between 300ms to 500ms on the 2nd load. If this resolves your problem, I'm going to close off the issue report. The caching issue is still present in rare scenarios, but we have taken significant steps to mitigate it.

[BloodyIron]

@stickz switched to the latest image, serving v4.0.4. Added the RU_CACHED_PLUGIN_LOADING = true environment variable.

Forcefully cleared cache, first load very slow, as to be expected.

Subsequent load times are in the realm of 1.9 seconds. Substantial improvement over 7 seconds.

When I analyse the debug, network load waterfall, it seems "action.php" in two parts is the "slow" part of the load. Not sure if I was having it slow before, or if this is new/regression.

This is, for sure, a substantial improvement. Do you want us to proceed to explore the action.php aspect, have me open a new issue/ticket, or what?

I do really appreciate your hard work, and the work of others on this matter! This does help me plenty :) So, as you may have already noticed, I do try to help out where I can in my own way.

Anyways, please let me know your thoughts. Thanks again! :)

[stickz]

@BloodyIron Thanks for your help testing. I'm going to go ahead and close this issue report, since the problem with getplugins.php has been resolved. I don't want to confuse this issue report with a different problem.

Please feel free to open a new issue report with fresh information about the action.php issue.

[BloodyIron]

@stickz actually, I just observed an issue again with getplugins.php so maybe let's discuss that a touch more.

So, my computer just rebooted for $reasons, and I went to my ruTorrent webGUI. Surprise surprise, getplugins.php took 6.42 seconds to load.

Now, I haven't refreshed any cache in my browser (for the ruTorrent webGUI website), the docker container has not restarted, or anything like that. So as far as I can tell, this should have been the earlier observed 1.9 seconds of load time (or in that realm). And yes, same browser that I use to access it.

I have not changed any configuration, or other stuff, about the environment, since I did the previous change to v4.0.4.

Um... unsure how to reliably reproduce this, but... what are your thoughts on this? :s

I can create another issue/ticket once this is sorted/figured out or whatever, for action.php, but I'm going to hold off considering this new result sample.

[BloodyIron]

Yeah, okay so additional information.

Same browser session, I open a new tab, go to google.com, hit F12 to open console so I can watch network load, go to ruTorrent webGUI again... and yeah, getplugins.php took 5 seconds to load.

I did not close the window, refresh cache or anything like that, just new tab, steps described above.

Something still seems not quite right.

[stickz]

@BloodyIron The default cache duration is 3 hours.

Optionally, you can change RU_PLUGIN_JS_CACHE_EXPIRE to a higher value like 30*60*24 for 30 day caching. However, it will almost definitely be required to clear the web browser cache when upgrading versions.

[BloodyIron]

@stickz aha! I'll try that and report back if any issues crop up related to getplugins.php ;) I had not realised the cache, by default, was as low as 3hr!

I'll also open a new issue for the action.php matter

Again, thanks for your help and work on all this! Yay! :D