race condition in AspireUpdate\Debug::log

[chuckadams]

Roughly here:
https://github.com/aspirepress/AspireUpdate/blob/e855143dea6e744d6d2c04ff9c55031971c46670/includes/class-debug.php#L154

Reading the whole log, appending a line, and writing the whole thing back is not only extremely inefficient, it has an inherent race condition between the read and the write. File I/O being what it is, the window of that race condition may be a lot bigger than you think. The WP filesystem API doesn't have any way to open a file for appending, so it's probably to best just not use that API for log files.

[namithj]

Looks like we are going to have to extend WP-Filesystem class. We can also submit to core but they probably won't accept since this is an obvious use case which haven't yet been added in.

[costdev]

The Filesystem API didn't have much in the way of maintainers over the years. I took over its maintenance a while back, but resolving issues took precedence over new features, and resolving issues in such an old, mission-critical API is a doozy with the BC promise and X number of server configurations.

If we're not planning to support FTP-based or SSH-based filesystems, consider just using native PHP functions. Otherwise, extending the API will need variations for FTPext, ftpsockets, and SSH

[namithj]

I guess We will have to do both fopen and file_put_contents to cover most of our use cases. What about inheriting the Filesystem API class and adding functions for these two paths.
Or ignore the class and do it all custom?

[costdev]

For now, I'd say we should probably go with the native PHP functions rather than extending the API, as this will need investigation and testing for supporting FTP/SSH systems.

[chuckadams]

I'm not sure maintaining a local debug log over ftp/ssh is a great idea anyway. I mean there's stuff like sshfs we can't do anything about, but filesystems like that are what exacerbate race conditions in the first place.

[afragen]

Is there some reason we need a separate debug.log? If it's to designate AU errors we could prefix the errors like [AspireUpdate].

[costdev]

It would mean loading a full debug.log and parsing for [AspireUpdate], which would load a larger file into memory.

Additional note about our current save location: If an installation has wp-content locked down for changes, then this could run into an issue. Usually, plugins would store created files into wp-content/uploads, which is usually kept open. This came up during the new fonts/ directory location discussions for Core's Fonts API.

It might not be an issue here, but thought I'd raise it anyway while we're discussing the log file.

[chuckadams]

It would mean loading a full debug.log and parsing for [AspireUpdate], which would load a larger file into memory.

The file can be streamed. But why load the log in the first place or have a separate UI for viewing only AU's part of the log? People who enable and actually use debug.log generally know how to grep it. Using a separate log virtually guarantees that AU's debug log won't be picked up by log collectors by default, which any big deployment will be using.

[namithj]

What's the opinion about logging in the DB?

[chuckadams]

I like the idea of logging in the db, but it seems to be kind of foreign to the WP ecosystem, might not be palatable to some. error_log() sucks as a logging API, but it seems WP already gets by using only that. what do the big plugins like yoast or woo do for logging?

Might want to distinguish between "useful to know" debug logging from the official record of actions taken: I could get behind creating a new db table for the latter and using that, but not throwing every bit of logging chatter into it.

[namithj]

We can throw our log into a non public custom post type. It won't be amount my first 10 choices but it's still better than going direct file access way. error_log doesn't have a non hacky way to specify the error log file during each write, else it would have done the job.

We have limited to view log to 1000 items, may be we only save the latest 1000 items.

[costdev]

What do the big plugins like yoast or woo do for logging?

WooCommerce has two options:

File system stores to wp-content/uploads/wc-logs/

By default, logging is handled by WC_Logger. The default handler is LogHandlerFileV2 and the controller is FileController.

Not sure what, if anything, Yoast does.

[namithj]

We should check what approach woocommerce is using to write to the file log. I am going to dig into that code, my gut says we will end at fopen down the rabbit hole.

[costdev]

• Reading: Uses fopen(), gets the stream here and outputs here
• Writing: Uses fopen( '', 'ab' ) and fwrite()

[namithj]

So we can just go with that. If woo with as many sites doesn't have compatibility issues, it won't be a big issue for us too.

[costdev]

Yeah, and also a reminder of the location Woo uses: wp-content/uploads/wc-logs/. We should do the same for AspireUpdate and use our own directory/file in wp-content/uploads/.

[namithj]

Do you have bandwidth to take this over?

[costdev]

Not at the moment. I'm away all weekend and not sure what bandwidth I have during next week yet.

[namithj]

I will leave it unassigned. Will change the assignment only if I starts on it.