Bug ID | 1099494 |
---|---|
Summary | zypper calls snapper, snapshot creation failed while snapper already running, still stalling system |
Classification | openSUSE |
Product | openSUSE Tumbleweed |
Version | Current |
Hardware | Other |
OS | Other |
Status | NEW |
Severity | Major |
Priority | P5 - None |
Component | Other |
Assignee | bnc-team-screening@forge.provo.novell.com |
Reporter | okurz@suse.com |
QA Contact | qa-bugs@suse.de |
Found By | --- |
Blocker | --- |
Created attachment 775554 [details]
y2logs, snapper.log, system journal, snapper cleanup journal, zypper.log
## Observation
On an openSUSE Tumbleweed installation on a HDD disk (btrfs, encrypted, i.e.
slow performance) calling zypper dup proposed to install around 3000 packages -
as expected for openSUSE Tumbleweed upgrades. During that process it seems
snapper cleanup was triggered in parallel but zypper also tried to create a
snapshot but failed to do so effectively stalling the system for a very long
time. Logfiles show quite some errors.
E.g. from zypper.log:
```
018-06-28 10:54:26 <2> linux-9akz(17693) [PLUGIN]
PluginScript.cc(~PluginDumpStderr):75 ! INFO:root:creating post snapshot
2018-06-28 10:54:26 <5> linux-9akz(17693) [zypp] Exception.cc(log):166
PluginExecutor.cc(doSend):133 CAUGHT: Not ready to read within timeout.
2018-06-28 10:54:26 <2> linux-9akz(17693) [zypp::plugin]
PluginExecutor.cc(doSend):134 Not ready to read within timeout.
2018-06-28 10:54:26 <2> linux-9akz(17693) [zypp::plugin]
PluginExecutor.cc(doSend):140 Bad plugin response from PluginScript[4691]
/usr/lib/zypp/plugins/commit/snapper.py: PluginF
rame[](0){0}
2018-06-28 10:54:26 <2> linux-9akz(17693) [zypp::plugin]
PluginExecutor.cc(doSend):141 (Expected ACK or _ENOMETHOD)
2018-06-28 10:54:26 <1> linux-9akz(17693) [zypp::plugin++]
PluginScript.cc(close):229 Close:PluginScript[4691]
/usr/lib/zypp/plugins/commit/snapper.py
2018-06-28 10:54:26 <1> linux-9akz(17693) [zypp::plugin++]
PluginScript.cc(send):272 PluginScript[4691]
/usr/lib/zypp/plugins/commit/snapper.py ->send PluginFrame[_DISCONNECT](0){0}
2018-06-28 10:54:30 <2> linux-9akz(17693) [PLUGIN]
PluginScript.cc(~PluginDumpStderr):75 ! ERROR:root:creating snapshot failed:
2018-06-28 10:54:30 <2> linux-9akz(17693) [PLUGIN]
PluginScript.cc(~PluginDumpStderr):75 ! ERROR:root:
org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes
include: the remote application did not send a reply, the message bus security
policy blocked the reply, the reply timeout expired, or the network connection
was broken.
```
whereas snapper-cleanup reports
```
2018-06-28 10:54:03 MIL libsnapper(4747) Snapper.cc(Snapper):91 - Snapper
constructor
2018-06-28 10:54:03 MIL libsnapper(4747) Snapper.cc(Snapper):92 - libsnapper
version 0.5.4
2018-06-28 10:54:03 MIL libsnapper(4747) Snapper.cc(Snapper):93 -
config_name:root disable_filters:false
2018-06-28 10:54:03 MIL libsnapper(4747) AsciiFile.cc(reload):114 - loading
file /etc/snapper/configs/root
2018-06-28 10:54:03 MIL libsnapper(4747) AsciiFile.cc(getValue):235 -
key:SUBVOLUME value:/
2018-06-28 10:54:03 MIL libsnapper(4747) AsciiFile.cc(getValue):235 -
key:FSTYPE value:btrfs
2018-06-28 10:54:03 MIL libsnapper(4747) AsciiFile.cc(getValue):235 -
key:QGROUP value:1/0
2018-06-28 10:54:03 MIL libsnapper(4747) AsciiFile.cc(getValue):235 -
key:SYNC_ACL value:no
2018-06-28 10:54:03 MIL libsnapper(4747) Snapper.cc(Snapper):125 - subvolume:/
filesystem:btrfs
2018-06-28 10:54:03 MIL libsnapper(4747) Snapper.cc(loadIgnorePatterns):174 -
number of ignore patterns:8
2018-06-28 10:54:03 MIL libsnapper(4747) Snapshot.cc(read):245 - found 16
snapshots
2018-06-28 10:54:03 MIL libsnapper(4747) SystemCmd.cc(SystemCmd):46 -
constructor SystemCmd:"/usr/lib/snapper/plugins/grub --refresh"
2018-06-28 10:54:03 MIL libsnapper(4747) SystemCmd.cc(execute):82 - SystemCmd
Executing:"/usr/lib/snapper/plugins/grub --refresh"
2018-06-28 10:54:05 MIL libsnapper(4747) SystemCmd.cc(doExecute):267 -
stopwatch 1.439245s for "/usr/lib/snapper/plugins/grub --refresh"
2018-06-28 10:54:05 MIL libsnapper(4747) SystemCmd.cc(doExecute):287 - system()
Returns:0
2018-06-28 10:54:05 WAR libsnapper(4747) FileUtils.cc(SDir):88 - THROW: open
failed path://.snapshots errno:2 (No such file or directory)
2018-06-28 10:55:01 MIL libsnapper(4747) SystemCmd.cc(SystemCmd):46 -
constructor SystemCmd:"/usr/lib/snapper/plugins/grub --refresh"
2018-06-28 10:55:01 MIL libsnapper(4747) SystemCmd.cc(execute):82 - SystemCmd
Executing:"/usr/lib/snapper/plugins/grub --refresh"
2018-06-28 10:55:03 MIL libsnapper(4747) SystemCmd.cc(doExecute):267 -
stopwatch 1.765667s for "/usr/lib/snapper/plugins/grub --refresh"
```
so it looks like snapper was starting up just in before, coincidence?