Start/restart stacks once. Skip failed pulls. Final summary notification.

[vorezal]

Attempting to address issues #249 and #260. Additionally, I skipped running docker compose up against stacks that it had already been performed for. Open to thoughts on that last bit, since no one actually asked for it but me.

I've tested a fair amount, but I don't think I hit every case. I wasn't able to "successfully" cause a docker pull to error or even think of how to force it to do so as a test. I'll keep testing more myself, but I wanted to get this up for review/thoughts before I went too far with a particular approach that someone else may know of a better way to handle.

[mag37]

Great work again @vorezal ! As I mentioned in the other PR, I'm a bit tight on time currently. I'll try to review this and get back to you asap, looks good at first glance! Though a compose.yaml might have snuck in from the other PR?

Maybe the pull error can be forced by hardcoding wrong $ContImage for a specific container during a test or something. I'll try to look at it when I find some time.

[yoyoma2]

Has the sourcing policy of v1 and v2 changed? Looks like v2 is now first and v1 is second. If v1 isn't there will v2 be sourced again?

I like that the summary notification is off by default.

The actions being logged are quite limited so introducing bugs as in my comment somewhere else aren't an issue.

The maintenance part however is still a concern. From the beginning notifications were considered outside the scope of dockcheck and deliberately separate. Now a new dockcheck feature needs to consider adding actions. Adding actions to the summary involves dockcheck version change instead of only a notify_v2 version change. This is a notable architectural change.

[vorezal]

No worries on the timing. Happy to keep this in the pipe as long as necessary for it to be properly reviewed. Thanks for the notice on the compose.yaml as well. I forgot that I made the .gitignore changes on the other branch and that made it through. I'll have to force push to remove it. No reason people need to see my compose.yaml.

I agree on the maintenance concern, though I'm also not too sure what to do about it. It could potentially be minimized by wrapping actions within another function that combines execution, error reporting, and storing the action, but no matter what tracking new actions would always require a version bump since we'd be modifying dockcheck.sh. It would be equivalent to adding new cli log output I suppose.

[mag37]

The maintenance part however is still a concern. From the beginning notifications were considered outside the scope of dockcheck and deliberately separate. Now a new dockcheck feature needs to consider adding actions.

Valid points to consider @yoyoma2 , thank you for raising them.
I've not reviewed the code properly yet so can't go into detail or alternatives, but I think - as @vorezal mention - to avoid touching dockcheck.sh we'd probably create a lot of extra hoops to jump through and messy dependencies/connections.

Hopefully the touching of dockcheck.sh won't be too often, and we could just decide to "lock" the scope to what we decide is complete with this feature change. Or decide to only push notification-changes within larger releases or something.

[mag37]

Line 690-699 is a bit hard to read and just from reading I can't say surely if the logic is sound, I'd need to dumb it down and create a test case for it to see that it does what intended.

        # Check if the whole stack should be restarted
        if [[ "$ContRestartStack" == true ]] || [[ "$ForceRestartStacks" == true ]]; then
          [[ "${RestartedStacks[@]}" != *"$ContPath"* ]] && { ${DockerBin} ${CompleteConfs} stop; ${DockerBin} ${CompleteConfs} ${ContEnvs} up -d && Actions+=("Recreate $i;Success;Full stack restart") || { printf "\n%bFailed to recreate $i, skipping.%b\n" "$c_red" "$c_reset" ; Actions+=("Recreate $i;Error;Failed to start stack") ; } }
	  RestartedStacks+=("$ContPath")
        else
          { [[ "${RestartedStacks[@]}" != *"$ContPath"* ]] || [[ -n "${SpecificContainer:-}" ]] } && { ${DockerBin} ${CompleteConfs} ${ContEnvs} up -d ${SpecificContainer} && Actions+=("Recreate $i;Success;${SpecificContainer:-Stack}") || { printf "\n%bFailed to recreate $i, skipping.%b\n" "$c_red" "$c_reset" ; Actions+=("Recreate $i;Error;Failed to start ${SpecificContainer:-Stack}") ; } }
	  if [[ -z "${SpecificContainer:-}" ]]; then
            RestartedStacks+=("$ContPath")
	  fi
        fi

Also looks like there's some indentation errors in the Recreate phase in general.

[vorezal]

Agreed. My first pass at that was pretty rough. I'll try to clean up the logic. My IDE also kept auto-indenting in a way that I didn't intend to and I didn't put in the effort to fix it at the time. I'll clean that up too.

[yoyoma2]

When the first notifications were introduced it was considered outside the scope of dockcheck. It turns out to have become a popular feature so the strict separation may not be a big deal any more. Recently someone fixed notify_v2 for unraid and I thought it was super cool that I got a notification for a new v2 but not for dockcheck.

Brainstorming:
What if logging calls were added to dockcheck with the usual verbosity levels like NOTICE, WARNING, ERROR and stored into a file and/or sent as a notification. Then the new logging system is sprinkled throughout dockcheck instead of the notification system sprinkled throughout dockcheck.

Again why the new sourcing of notify_v2 in line 163? Looks like it will get sourced again right after if you don't have a v1.

[vorezal]

That's a good thought. Building a logging system once within dockcheck and then having notification logic to parse through for log message types or verbosity levels would be more work, but it would be more segregated and potentially more maintainable. Let me think about how this could be done.

Apologies, I forgot to address that source change. At one point I was troubleshooting an error causing the source to fail. That was meant as a troubleshooting line and forgetting to remove it was a miss on my part. I'll make sure to get it out of there.

[yoyoma2]

After the v2 revamp stuff you've set the bar high. Curious to see your ideas.

Figures that sourcing thing was just forgotten troubleshooting code. Everything else made perfect sense.

[mag37]

What if logging calls were added to dockcheck with the usual verbosity levels like NOTICE, WARNING, ERROR and stored into a file and/or sent as a notification. Then the new logging system is sprinkled throughout dockcheck instead of the notification system sprinkled throughout dockcheck.

@yoyoma2 this is a good idea and I've got "add some logging" in my TODO, though quite some work to implement. And depending on how things are implemented I'm not against having notification - logic sprinkled through dockcheck-main, but you're right that it can become messy.

That's a good thought. Building a logging system once within dockcheck and then having notification logic to parse through for log message types or verbosity levels would be more work, but it would be more segregated and potentially more maintainable. Let me think about how this could be done.

@vorezal That's quite the project to undertake, rewriting and adding logging - I don't want you to feel obligated to do the work. I agree that it could be very nice but it takes some consideration and thoughts on structure, plus a lot of work.

I'm glad you both are discussing and coming up with ideas and arguments! I currently have minimal time to spare (in the middle of a house move and new job) but I'll try to put some thinking into this at least!

If we'd rewrite, we could probably create a print-function and a log-function and everywhere we'd like to state a message we could call either of those. Though if the log-function is writing to memory we'd need to catch errors and dump it to file when things break. (just thinking loud).

Thank you both!

[vorezal]

I have some ideas on this and have actually already been working on it off and on. I should have something ready to show in a little bit. Some of the basic features I'm considering and would be happy to have some initial feedback on:

• A log-and-print function that writes to the screen, stores the message in a memory buffer, and (optionally) logs to file.
• A log only function that just stores in a memory buffer and logs to file
• Log levels based on the OpenTelemetry log data-model severities: link to docs
• A function that writes a stored buffer out to the screen and/or triggers a notification. This would end up here and there throughout the dockcheck.sh code (really just one place to start) but I can't really think of a way around that. One way or another we need something in the main script to trigger an alert.
• Wrapper for function execution that can control stdout output while maintaining return code
• Quiet mode flag -q to prevent output to stdout
• Config option for log level output
• Config option to enable file based logs
• Config option for log file retention

I think those are the main points. If that sounds reasonable I'll get the functions finished.

[mag37]

Sounds very reasonable! Though also sound like you need to put a lot of work into it, I don't want you to feel obligated or pushed, there's no stress! (I wont be able to review/test/contribute properly until earliest next week).

And also, I don't mean to be disrespectful or doubt your effort - but it needs to be said (generally, not to you personally): if AI-tools are being used for a big PR I'd like to know and be assured it's properly vetted/reviewed by a human.

[vorezal]

No worries! I got invested and am already decently far along. Once I have the functions and structure in maybe we can tag team converting the existing output to the new logger though.

As for the AI bit, totally understandable it would be something to address. I can't say I don't use it at all, but it's usually pretty minimal and not something I would copy verbatim without both understanding it and testing. In this case, so far I've asked Gemini (just via a Google search) to generate a bash function the takes an existing printf command and wraps it up with a date stamp and log level parameter while respecting the format string and an arbitrary number of substitution parameters. It came back with something pretty straightforward and I took some ideas from it, but customized it heavily myself as well. Beyond that kind of thing I mostly look up Bash syntax that the AI summary can bring back a quick answer for, but it's wrong enough that I often have to search through posts and documentation myself anyway. So yeah. That's about it. Fully tested and human vetted in the end though for sure.

[vorezal]

Alright folks. Long comment (and PR). Sorry for that.

I've added several functions to support standardized logging. It requires more additional characters in code than I might like. I'd love for it to be as simple as calling a function with a message and have that be it, but to support buffers and log levels I don't see a way to avoid requiring at least those as parameters. I suppose separate functions for each log level and with/without buffer storage could work now that I think about it, but could be too much. Open to thoughts there however. Anyway, I also changed a couple of lines to use the new log functions as examples, but left most unchanged for now. I expect functionality be as follows:

log_print buffername INFO "Some message\n" <- Prints the message to the screen, stores it in the buffer buffername, and may write out to file if configured in the settings
log buffername INFO "Some other message\n" <- Stores the log in mainbuf and may write out to file if configured, as above. Does not print to stdout.
print_buffer buffername [notify/notifyonly] [label] <- Prints the buffer. Parameters 2 and 3 are optional, with the default being to print to stdout only. If 'notify' is passed, it will also send a buffer notification. If 'notifyonly' is passed, it will only send the notification without printing to stdout. If notify or notifyonly are passed and parameter 3 is sent, its value will be used in place of the buffer name as the label for the notification. This will need to be added to dockcheck.sh wherever/whenever we want a new buffer printed out or a new buffer notification (if we ever make another).
log_severity string <- Takes a string and converts it to a numerical representation of the log severity. If a number is passed between 0 and 24, uses it directly. If anything else is passed, defaults to 0. Just a helper function.
log_cleanup <- Removes log files older than LogDaysToKeep days.

exec_command command and arguments <- Takes a normal bash command as arguments, runs it, stores the output in a variable, and returns the response code. If Quiet is not set, also allows printing to stdout via a duplicated file descriptor
LatestOutput <- Variable used to store the output from the last executed command sent through exec_command. We can use this to dynamically push the response to a buffer and/or log it to file.

A few points about logging and my assumptions:

• I assume we handle newlines in stdout manually. No newlines are added automatically to screen output.
• I think we should only log single lines to file. I took the easy way out for now and replace every newline with a literal '\n' and add a single newline to the end. We could alternatively log in json or something, but this seemed the least complicated. We could even decide to support multi-line log events, but that's not generally considered best practice these days.
• Logs are kept in the /log directory within the main project folder and is created if it does not exist.
• A new log file is created for each exeution.
• I expect strings in buffers we notify on to have ; characters separating up to three fields. The action or event name, optional status of the action or event (success, error, skipped, whatever is appropriate for that event), and an optional detailed message or description. Only the first field is required, but the ; separator, when provided, does make file logs look a little weird. I haven't decided what, if anything, to do about that for now.

New parameters:
-q : Quiet

New configuration options:
LogToFile: true/false
LogDaysToKeep: integer
LOG_LEVEL: INFO/WARN/etc
ENABLE_SUMMARY_NOTIFICATION: true/false

README changes: TBD once this is reviewed and more finalized, but for the most part we won't need to document the internal log changes. Just the new parameter and configuration options.

I expect a lot of testing to be needed here. Even more so when we start migrating log messages over. I'm almost positive we will find interesting formatting cases I hadn't accounted for that makes things come through differently or unexpectedly and we will have to adjust. Some of this may well be... over engineered at best.

Finally, I rewrote the logic to check if a stack has already been restarted. It's more verbose with full multi-line if statements, but it should hopefully be easier to follow. Still might need additional comments for clarity though.

Phew. That was a bunch. Let's split this out and test each feature change one by one.

[yoyoma2]

Not much time at the moment to test but seems very good. The detailed comment on the changes is appreciated too. 👍

[mag37]

This case could probably be condensed the same way the getops - case is, so each case except *) is just a single line.
Like:

TRACE) levelnum=1 ;;
DEBUG) levelnum=5 ;; 

Or if it's more readable (I'm not sure) with two lines:

TRACE)
    levelnum=1 ;;
DEBUG)
    levelnum=5 ;; 

[vorezal]

Ah good call. Happy to condense. For whatever reason I've gotten into the habit of doing it long form but I'm not sure why.

[mag37]

That's a lot of work @vorezal - I'm sorry I've not had time to review it properly nor test it.
I've barely got my network up in the new house (servers first ofc, rest is secondary!) but I glanced through it now.

And thank you for the very thorough commentary to show what's done.

• I assume we handle newlines in stdout manually. No newlines are added automatically to screen output.

As I've used printf in most places (except the helper function, easy to rewrite though) that required manual newlines.

• I think we should only log single lines to file. I took the easy way out for now and replace every newline with a literal '\n' and add a single newline to the end. We could alternatively log in json or something, but this seemed the least complicated. We could even decide to support multi-line log events, but that's not generally considered best practice these days.

I agree that multi-line log events is not preferred, I think we're fine as is - single line. Maybe a look at json format in the future could be worth it, probably not.

• Logs are kept in the /log directory within the main project folder and is created if it does not exist.
• A new log file is created for each exeution.

Good decisions! Agree.

• I expect strings in buffers we notify on to have ; characters separating up to three fields. The action or event name, optional status of the action or event (success, error, skipped, whatever is appropriate for that event), and an optional detailed message or description. Only the first field is required, but the ; separator, when provided, does make file logs look a little weird. I haven't decided what, if anything, to do about that for now.

I'll have to look at this when I first test it out to see the formatting and readability - but sounds like it should be okay.

There's quite a lot to grasp and things to test/read through. But I'll try to find time soon to dive a bit deeper and actually test it out to come back with some feedback and aid with any further work needed.

[mag37]

Hmm, when I tested it now it spams the output quite a lot during the updates. It probably prints a new line with every change instead of refreshing. The pretty output from docker is missing.

Comparison:

Current - one line per layer that shows progress during download and refreshes each line dynamically.

Now updating (1/1): metube
Using default tag: latest
latest: Pulling from alexta69/metube
0c8d55a45c0d: Pull complete 
03af238a5946: Pull complete 
686599c79c87: Pull complete 
f1cadbd7abd2: Pull complete 
5440da0719f6: Pull complete 
89e03b9c5229: Pull complete 
804d33ddcf40: Pull complete 
87e3e7a09860: Pull complete 
5ffd71f61b11: Pull complete 
6fdc376c7541: Pull complete 
bd163ec93542: Pull complete 
Digest: sha256:eddc5430c1e3299f2df3a3c413af7b50fdbcbb12c7065fe32d29b4bc83557aac
Status: Downloaded newer image for alexta69/metube:latest
docker.io/alexta69/metube:latest

This PR:

Now updating (1/1): metube
Using default tag: latest
latest: Pulling from alexta69/metube
0c8d55a45c0d: Pulling fs layer
03af238a5946: Pulling fs layer
686599c79c87: Pulling fs layer
f1cadbd7abd2: Pulling fs layer
5440da0719f6: Pulling fs layer
89e03b9c5229: Pulling fs layer
804d33ddcf40: Pulling fs layer
87e3e7a09860: Pulling fs layer
5ffd71f61b11: Pulling fs layer
6fdc376c7541: Pulling fs layer
bd163ec93542: Pulling fs layer
f1cadbd7abd2: Waiting
5440da0719f6: Waiting
89e03b9c5229: Waiting
804d33ddcf40: Waiting
87e3e7a09860: Waiting
5ffd71f61b11: Waiting
6fdc376c7541: Waiting
bd163ec93542: Waiting
03af238a5946: Verifying Checksum
03af238a5946: Download complete
f1cadbd7abd2: Verifying Checksum
f1cadbd7abd2: Download complete
5440da0719f6: Verifying Checksum
5440da0719f6: Download complete
686599c79c87: Verifying Checksum
686599c79c87: Download complete
89e03b9c5229: Verifying Checksum
89e03b9c5229: Download complete
0c8d55a45c0d: Verifying Checksum
0c8d55a45c0d: Download complete
0c8d55a45c0d: Pull complete
03af238a5946: Pull complete
5ffd71f61b11: Verifying Checksum
5ffd71f61b11: Download complete
87e3e7a09860: Verifying Checksum
87e3e7a09860: Download complete
686599c79c87: Pull complete
f1cadbd7abd2: Pull complete
5440da0719f6: Pull complete
6fdc376c7541: Verifying Checksum
6fdc376c7541: Download complete
89e03b9c5229: Pull complete
bd163ec93542: Download complete
804d33ddcf40: Verifying Checksum
804d33ddcf40: Download complete
804d33ddcf40: Pull complete
87e3e7a09860: Pull complete
5ffd71f61b11: Pull complete
6fdc376c7541: Pull complete
bd163ec93542: Pull complete
Digest: sha256:eddc5430c1e3299f2df3a3c413af7b50fdbcbb12c7065fe32d29b4bc83557aac
Status: Downloaded newer image for alexta69/metube:latest
docker.io/alexta69/metube:latest

[vorezal]

Well shoot. I thought I had that handled with the stdout file descriptor duplication. More testing on my end is in order then.

[mag37]

Well shoot. I thought I had that handled with the stdout file descriptor duplication. More testing on my end is in order then.

I'm not entirely sure we really need all the output being logged - though maybe that was the easier way to grab the messages needed for logging.

I guess what people wanted was just an output of fail/success and what containers got updated etc. Not a complete copy of the stdout. But as I said - maybe this was the easier way to accomplish that :)

[vorezal]

Yeah this was a combination of things. One was to allow the capturing of the output at all (sending it to a buffer if needed). The other though was to handle the quiet flag easily, but that could be done other ways if docker CLI output is troublesome. The main issue seems to be that when you do anything to the Docker CLI output I think it detects it isn't part of an interactive shell and defaults to text only output, line by line. I think I might have a way of adjusting for that, but if not we may need to handle Docker output, or any other output that relies on a TTY, separately without having a logger for it.

[mag37]

Are we certain its worth all that effort just to allow a quiet flag?
Considering the main use cases - either fully unattended and scheduled (with or without notifications) or interactive with manual choices.

And then focus on logging the process in other ways than using the stdout.
As I think the reasoning was just to get the execution logged / summarized to know what happened when and if things failed.

[vorezal]

Yeah I think you're right here. I may have gone overboard on this one unnecessarily, and there are probably a few too many edge cases and issues to handle them all properly with my attempt at an execute_command wrapper function. We'll likely need to capture stdout and handle logging/printing to screen separately in each case. I think it should still be very reasonably possible to handle the quiet flag anyway, but I was concerned about the dynamic progress output interfering. I think we can manage that by adopting the Docker practice (if we want to) of sending progress bars and the like to stderr instead of stdout though.

[mag37]

I'm considering if we should re-think this a bit before you plow down too much time to rewrite anything :)
Maybe break things down a bit and even split it to different things.

I'm not writing this to control or force anything, I'm just afraid things snowball to be a much larger scope and perhaps harder to maintain than it needs to be. And @vorezal crushing themselves with work!
So read it with a tone of good faith.

---

• Do we need the quiet-flag?

A manual (and blunt) way is to just append &>/dev/null to have it completely quiet. What's the use case we're aiming for here? If this implementation is what causes the most rewrites or issues maybe the worth should be reconsidered.

• What is necessary to fulfill the logging scope?

What's suggested and asked for was the ability to get a full summary of what's successfully updated to be used within notifications. I was also looking at keeping a logfile with the digests as a transaction log, but not completed it yet (see branch: log_digests) as suggested in #244.

• Another issue was #260 - to continue the run even if an update fail.

We should handle the fails gracefully and keep track of succeeded//failed updates to be able to skip recreation and maybe include easier in notifications.

• Skip running docker compose up against stacks that had already been recreated.

This is very sensible and would make things smoother in general, so I think this is very much worth it.

[vorezal]

I think very reasonable in this case considering how different the features are. I'll work on pulling them into separate branches and we can evaluate them individually.