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?


You are receiving this mail because: