Hey folks,
Currently, one has to run (multiple) snap commands to get the “logs” of what snapd has done on a system. This is not only annoying (because the commands one has to run are dynamic based on change IDs, so it requires scripting), but also means that normal methods of collating logging information from Ubuntu systems (whether that be grabbing files from a disk or pushing to a central logging service) fail to capture what snapd was doing to a system.
To solve this, I think it would be appropriate for snapd to log the human-readable text that snap change <id> shows you to the systemd journal.
I’ve filed a bug with the above as its description, but also wanted to draw attention to it here.
Thanks!
Dan
1 Like
INFO messages are sent to the journal already. If you turn on debug, things are a lot more chatty. If you
spot messages in DEBUG that should be INFO, let us know!
To turn on debug messages, I’ll crib from @sparkiegeek’s instructions:
$ sudo systemctl edit snapd.service
[Service]
Environment=SNAPD_DEBUG=1
$ sudo systemctl restart snapd.service
1 Like
A brief examination of the output with SNAPD_DEBUG=1 enabled suggests that I’m really asking for all the taskrunner.go:418 lines to be INFO rather than DEBUG; understanding what actions snapd is performing by examining the system log is, I think, valuable.
For reference, I filed this request when I was attempting to debug an issue with preseeded snaps (which are now present in all Ubuntu images as of cosmic, server and cloud included) and the INFO output gives no information about what is actually happening during the seeding process:
Oct 09 20:35:31 cosmic-181009-1635 systemd[1]: Starting Snappy daemon...
Oct 09 20:35:31 cosmic-181009-1635 snapd[884]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:35:32 cosmic-181009-1635 snapd[884]: helpers.go:132: error trying to compare the snap system key: system-key missing on disk
Oct 09 20:35:32 cosmic-181009-1635 snapd[884]: daemon.go:344: started snapd/2.35.4+18.10 (series 16; classic) ubuntu/18.10 (amd64) linux/4.15.0-1019
Oct 09 20:35:32 cosmic-181009-1635 systemd[1]: Started Snappy daemon.
Oct 09 20:35:38 cosmic-181009-1635 snapd[884]: backend.go:303: cannot create host snap-confine apparmor configuration: cannot synchronize snap-confi
Oct 09 20:35:38 cosmic-181009-1635 snapd[884]: daemon.go:532: gracefully waiting for running hooks
Oct 09 20:35:38 cosmic-181009-1635 snapd[884]: daemon.go:534: done waiting for running hooks
Oct 09 20:35:38 cosmic-181009-1635 systemd[1]: snapd.service: Service RestartSec=100ms expired, scheduling restart.
Oct 09 20:35:38 cosmic-181009-1635 systemd[1]: snapd.service: Scheduled restart job, restart counter is at 1.
Oct 09 20:35:38 cosmic-181009-1635 systemd[1]: Stopped Snappy daemon.
Oct 09 20:35:38 cosmic-181009-1635 systemd[1]: Starting Snappy daemon...
Oct 09 20:35:38 cosmic-181009-1635 snapd[1318]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:35:38 cosmic-181009-1635 snapd[1318]: daemon.go:344: started snapd/2.35.4+18.10 (series 16; classic) ubuntu/18.10 (amd64) linux/4.15.0-101
Oct 09 20:35:38 cosmic-181009-1635 systemd[1]: Started Snappy daemon.
Even during installation, it’s just a single line of INFO.
@Odd_Bloke Those are good points. It sounds like a good idea… let’s just try to evaluate what could go wrong if we actually do that.
This isn’t urgent, but what do we need to do to push this forward?
