This updates our logging framework from legacy freetext strings using
the `log` package to structured log entries using `log/slog`. I have
updated all INFO or higher level entries, but not yet DEBUG (😓)... So,
at a high level:
There is a slight change in log levels, effectively adding a new warning
level:
- DEBUG is still debug (ideally not for users but developers, though
this is something we need to work on)
- INFO is still info, though I've added more data here, effectively
making Syncthing more verbose by default (more on this below)
- WARNING is a new log level that is different from the _old_ WARNING
(more below)
- ERROR is what was WARNING before -- problems that must be dealt with,
and also bubbled as a popup in the GUI.
A new feature is that the logging level can be set per package to
something other than just debug or info, and hence I feel that we can
add a bit more things into INFO while moving some (in fact, most)
current INFO level warnings into WARNING. For example, I think it's
justified to get a log of synced files in INFO and sync failures in
WARNING. These are things that have historically been tricky to debug
properly, and having more information by default will be useful to many,
while still making it possible get close to told level of inscrutability
by setting the log level to WARNING. I'd like to get to a stage where
DEBUG is never necessary to just figure out what's going on, as opposed
to trying to narrow down a likely bug.
Code wise:
- Our logging object, generally known as `l` in each package, is now a
new adapter object that provides the old API on top of the newer one.
(This should go away once all old log entries are migrated.) This is
only for `l.Debugln` and `l.Debugf`.
- There is a new level tracker that keeps the log level for each
package.
- There is a nested setup of handlers, since the structure mandated by
`log/slog` is slightly convoluted (imho). We do this because we need to
do formatting at a "medium" level internally so we can buffer log lines
in text format but with separate timestamp and log level for the API/GUI
to consume.
- The `debug` API call becomes a `loglevels` API call, which can set the
log level to `DEBUG`, `INFO`, `WARNING` or `ERROR` per package. The GUI
is updated to handle this.
- Our custom `sync` package provided some debugging of mutexes quite
strongly integrated into the old logging framework, only turned on when
`STTRACE` was set to certain values at startup, etc. It's been a long
time since this has been useful; I removed it.
- The `STTRACE` env var remains and can be used the same way as before,
while additionally permitting specific log levels to be specified,
`STTRACE=model:WARN,scanner:DEBUG`.
- There is a new command line option `--log-level=INFO` to set the
default log level.
- The command line options `--log-flags` and `--verbose` go away, but
are currently retained as hidden & ignored options since we set them by
default in some of our startup examples and Syncthing would otherwise
fail to start.
Sample format messages:
```
2009-02-13 23:31:30 INF A basic info line (attr1="val with spaces" attr2=2 attr3="val\"quote" a=a log.pkg=slogutil)
2009-02-13 23:31:30 INF An info line with grouped values (attr1=val1 foo.attr2=2 foo.bar.attr3=3 a=a log.pkg=slogutil)
2009-02-13 23:31:30 INF An info line with grouped values via logger (foo.attr1=val1 foo.attr2=2 a=a log.pkg=slogutil)
2009-02-13 23:31:30 INF An info line with nested grouped values via logger (bar.foo.attr1=val1 bar.foo.attr2=2 a=a log.pkg=slogutil)
2009-02-13 23:31:30 WRN A warning entry (a=a log.pkg=slogutil)
2009-02-13 23:31:30 ERR An error (a=a log.pkg=slogutil)
```
---------
Co-authored-by: Ross Smith II <ross@smithii.com>
### Purpose
The `fs.Filesystem` interface contains two parts that cannot be
implemented externally because they are private:
* `filesystemWrapperType`: this PR changes `unwrapFilesystem` to
downcast to a specific concrete type
* `underlying`: this PR simply moves it to an unexported interface
### Testing
Regular tests pass.
This adds a header with the operating system version, verbatim in
whatever format the operating system reports it, to the upgrade check.
The intention is that the upgrade server can use this information to
filter out (or maybe just mark) potentially unsupported upgrades.
With this change, error messages include the offending characters or
name parts. Examples:
nul.txt: name is invalid, contains Windows reserved name: "nul"
foo>bar.txt: name is invalid, contains Windows reserved character: ">"
foo \bar.txt: name is invalid, must not end in space or period on Windows
all: Add package runtimeos for runtime.GOOS comparisons
I grew tired of hand written string comparisons. This adds generated
constants for the GOOS values, and predefined Is$OS constants that can
be iffed on. In a couple of places I rewrote trivial switch:es to if:s,
and added Illumos where we checked for Solaris (because they are
effectively the same, and if we're going to target one of them that
would be Illumos...).
This adds support for syncing ownership on Unixes and on Windows. The
scanner always picks up ownership information, but it is not applied
unless the new folder option "Sync Ownership" is set.
Ownership data is stored in a new FileInfo field called "platform data". This
is intended to hold further platform-specific data in the future
(specifically, extended attributes), which is why the whole design is a
bit overkill for just ownership.
Add specific errors for the failures, resulting in this rather than just
the generic "invalid filename":
[MRIW7] 08:50:50 INFO: Puller (folder default, item "NUL"): syncing: filename is invalid: name is reserved
[MRIW7] 08:50:50 INFO: Puller (folder default, item "fail."): syncing: filename is invalid: name ends with space or period
[MRIW7] 08:50:50 INFO: Puller (folder default, item "sup:yo"): syncing: filename is invalid: name contains reserved character
[MRIW7] 08:50:50 INFO: default: Failed to sync 3 items
* lib/fs, lib/model: Add error channel to Watch to avoid panics (fixes#5697)
* forgot unsupported watch
* and more non(-standard)-unixy fixes
* and windows test
* review
This adds a folder option "CopyOwnershipFromParent" which, when set,
makes Syncthing attempt to retain the owner/group information when
syncing files. Specifically, at the finisher stage we look at the parent
dir to get owner/group and then attempt a Lchown call on the temp file.
For this to succeed Syncthing must be running with the appropriate
permissions. On Linux this is CAP_FOWNER, which can be granted by the
service manager on startup or set on the binary in the filesystem. Other
operating systems do other things, but often it's not required to run as
full "root". On Windows this patch does nothing - ownership works
differently there and is generally less of a deal, as permissions are
inherited as ACLs anyway.
There are unit tests on the Lchown functionality, which requires the
above permissions to run. There is also a unit test on the folder which
uses the fake filesystem and hence does not need special permissions.
It turns out that ZFS doesn't do any normalization when storing files,
but does do normalization "as part of any comparison process".
In practice, this seems to mean that if you LStat a normalized filename,
ZFS will return the FileInfo for the un-normalized version of that
filename.
This meant that our test to see whether a separate file with a
normalized version of the filename already exists was failing, as we
were detecting the same file.
The fix is to use os.SameFile, to see whether we're getting the same
FileInfo from the normalized and un-normalized versions of the same
filename.
One complication is that ZFS also seems to apply its magic to os.Rename,
meaning that we can't use it to rename an un-normalized file to its
normalized filename. Instead we have to move via a temporary object. If
the move to the temporary object fails, that's OK, we can skip it and
move on. If the move from the temporary object fails however, I'm not
sure of the best approach: the current one is to leave the temporary
file name as-is, and get Syncthing to syncronize it, so at least we
don't lose the file. I'm not sure if there are any implications of this
however.
As part of reworking normalizePath, I spotted that it appeared to be
returning the wrong thing: the doc and the surrounding code expecting it
to return the normalized filename, but it was returning the
un-normalized one. I fixed this, but it seems suspicious that, if the
previous behaviour was incorrect, noone ever ran afoul of it. Maybe all
filesystems will do some searching and give you a normalized filename if
you request an unnormalized one.
As part of this, I found that TestNormalization was broken: it was
passing, when in fact one of the files it should have verified was
present was missing. Maybe this was related to the above issue with
normalizePath's return value, I'm not sure. Fixed en route.
Kindly tested by @khinsen on the forum, and it appears to work.
GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4646
These files always have the symlink bit set, because they are reparse
points. Nonetheless they are not symlinks, and Lstat reports a size for
them. We use this fact to disambiguate, and hope fervently that nothing
else matches this description so it comes back to bite us...
GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4622
The folder already knew how to stop properly, but the fs.Walk() didn't
and can potentially take a very long time. This adds context support to
Walk and the underlying scanning stuff, and passes in an appropriate
context from above. The stop channel in model.folder is replaced with a
context for this purpose.
To test I added an infiniteFS that represents a large amount of data
(not actually infinite, but close) and verify that walking it is
properly stopped. For that to be implemented smoothly I moved out the
Walk function to it's own type, as typically the implementer of a new
filesystem type might not need or want to reimplement Walk.
It's somewhat tricky to test that this actually works properly on the
actual sendReceiveFolder and so on, as those are started from inside the
model and the filesystem isn't easily pluggable etc. Instead I've tested
that part manually by adding a huge folder and verifying that pause,
resume and reconfig do the right things by looking at debug output.
GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4117
One more step on the path of the great refactoring. Touches rwfolder a
little bit since it uses the Lstat from fs as well, but mostly this is
just on the scanner as rwfolder is scheduled for a later refactor.
There are a couple of usages of fs.DefaultFilesystem that will in the
end become a filesystem injected from the top, but that comes later.
GitHub-Pull-Request: https://github.com/syncthing/syncthing/pull/4070
LGTM: AudriusButkevicius, imsodin
