Bug 1211694 - zypper prompt not displayed by build
Summary: zypper prompt not displayed by build
Status: CONFIRMED
Alias: None
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: libzypp (show other bugs)
Version: Current
Hardware: x86-64 openSUSE Tumbleweed
: P5 - None : Normal with 1 vote (vote)
Target Milestone: ---
Assignee: E-mail List
QA Contact: E-mail List
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-05-24 17:21 UTC by Christopher Yeleighton
Modified: 2023-05-25 06:00 UTC (History)
2 users (show)

See Also:
Found By: Community User
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---
ma: needinfo? (marco.strigl)

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Christopher Yeleighton 2023-05-24 17:21:02 UTC 
The build script invokes the following command:

{ /usr/bin/zypper --no-refresh -q --pkg-cache-dir /tmp/CH265TQIfT download -r https-download.opensuse.org-5a6700d1 rpm-4.18.0-4.2.x86_64; }

This command experienced the following problem:

2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(doCommand):479 START
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(_openLockFile):179 Open lockfile /run/zypp.pid
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(readLockFile):234 read: Lockfile /run/zypp.pid has pid 15045 (our pid: 15312) 
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(isProcessRunning):206 Checking /proc/15045{d 0555 0/0}
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp++] ZYppFactory.cc(isProcessRunning):220 Is running: /usr/libexec/packagekitd
2023-05-24 13:09:49 <2> localhost.localdomain(15312) [zypp] ZYppFactory.cc(zyppLocked):281 15045 is running and has a ZYpp lock. Sorry.
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(_closeLockFile):197 Close lockfile /run/zypp.pid
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 ZYppFactory.cc(getZYpp):415 THROW:    System management is locked by the application with pid 15045 (/usr/libexec/packagekitd).
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Close this application before trying again.
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Zypper.cc(assertZYppPtrGod):83 CAUGHT:   System management is locked by the application with pid 15045 (/usr/libexec/packagekitd).
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Close this application before trying again.
2023-05-24 17:59:42 <1> localhost.localdomain(15312) [zypper] prompt.cc(get_prompt_reply):439 reply empty, returning the default: no (1)
2023-05-24 17:59:42 <3> localhost.localdomain(15312) [zypper] Zypper.cc(assertZYppPtrGod):119 A ZYpp transaction is already in progress.
2023-05-24 17:59:42 <2> localhost.localdomain(15312) [zypper] Zypper.h(setExitCode):161 setExitCode 7


Here is the stack trace at 2023-05-24 13:09:49:

#7  std::istream::get (this=0x7ffde40e9460, __c=@0x7ffde40e8f1f: 0 '\000')
    at /usr/src/debug/gcc-13.0.1+git7231/obj-x86_64-suse-linux/x86_64-suse-linux/libstdc++-v3/include/bits/istream.tcc:306
#8  0x00007f769ffaee61 in zypp::str::receiveUpTo[abi:cxx11](std::istream&, char, bool) ()
   from /lib64/libzypp.so.1722
#9  0x00007f769ffaf05f in zypp::str::getline[abi:cxx11](std::istream&, zypp::str::Trim) ()
   from /lib64/libzypp.so.1722
#10 0x0000556ccc011698 in get_prompt_reply(Zypper&, PromptId, PromptOptions const&) ()
#11 0x0000556ccc009216 in read_bool_answer(PromptId, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool) ()
#12 0x0000556ccbef5f61 in ?? ()
#13 0x0000556ccbf53515 in Zypper::doCommand(int, char**, int) ()
#14 0x0000556ccbf2ba29 in Zypper::main(int, char**) ()
#15 0x0000556ccbf2a59e in main ()

It looks like zypper was waiting for my reply on standard input and that it thinks it has displayed a prompt to me so that I should know what to do.  But there was no prompt issued on the build terminal.
Comment 1 Andreas Stieger 2023-05-24 18:58:39 UTC 
Looks like zypper is blocked by packagekit. Odd, you pass -q, run zypper non-interactively and expect output? Also what looks like a subshell? I think you want -n.
Comment 2 Christopher Yeleighton 2023-05-24 19:07:54 UTC 
(In reply to Andreas Stieger from comment #1)
> Looks like zypper is blocked by packagekit. Odd, you pass -q, run zypper
> non-interactively and expect output? Also what looks like a subshell? I
> think you want -n.

I did not invoke zypper, build did.
Comment 3 Michael Andres 2023-05-24 19:12:22 UTC 
@Christopher, please provide the full zypper.log.
Comment 4 Christopher Yeleighton 2023-05-24 19:23:17 UTC 
(In reply to Michael Andres from comment #3)
> @Christopher, please provide the full zypper.log.

2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] main.cc(main):125 ===== Hi, me zypper 1.14.60
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] main.cc(main):126 ===== '/usr/bin/zypper' '--no-refresh' '-q' '--pkg-cache-dir' '/tmp/CH265TQIfT' 'download' '-r' 'https-download.opensuse.org-5a6700d1' 'rpm-4.18.0-4.2.x86_64' =====
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(_autodetectSystemArchitecture):146 Uname architecture is 'x86_64'
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(_autodetectTextLocale):308 Default text locale is 'en'
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(Impl):511 libzypp: 17.31.11
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp-core] iniparser.cc(parse):86 Start parsing /etc/zypp/zypp.conf[g___]
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [Progress++] progressdata.cc(report):75 {#1|/etc/zypp/zypp.conf} START
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp-core] iniparser.cc(parse):140 Done parsing /etc/zypp/zypp.conf[_eF_]
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [Progress++] progressdata.cc(report):94 {#1|/etc/zypp/zypp.conf} END
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(Impl):720 ZConfig singleton created.
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(ZConfig):936 libzypp: 17.31.11
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(ZConfig):936 libsolv: 0.7.24
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(ZConfig):936 zypp.conf: '/etc/zypp/zypp.conf'
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(ZConfig):936 TextLocale: 'en' (en)
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zconfig] ZConfig.cc(ZConfig):936 SystemArchitecture: 'x86_64' (x86_64)
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp-core] PathInfo.cc(assert_dir):353 mkdir /var/tmp/zypp.oUCCQa/zypper 00755
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(Zypper):189 Zypper instance created.
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] media.h(MediaCallbacks):200 Set media callbacks..
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(processGlobalOptions):293 START
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [Measure] Measure.cc(log):178 START MEASURE(ReadConfig)
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Augeas.cc(Augeas):537 Going to read zypper config using Augeas...
2023-05-24 13:09:49 <2> localhost.localdomain(15312) [zypper] Augeas.cc(Augeas):605 MISS config file: /root/.zypper.conf
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Augeas.cc(Augeas):599 READ config file: /etc/zypp/zypper.conf
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [Measure] Measure.cc(log):178 ELAPSED(ReadConfig) 0 (u 0.01 s 0.00 c 0.00)
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [Measure] Measure.cc(log):178 MEASURE(ReadConfig) 0 (u 0.01 s 0.00 c 0.00) [0 (u 0.00 s 0.00 c 0.00)]
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Config.cc(operator()):592 Autorefresh disabled.
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):303 Verbosity 0
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):304 Output type 1
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):342 repos.d dir = /etc/zypp/repos.d
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):343 cache dir = /var/cache/zypp
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):344 raw cache dir = /var/cache/zypp/raw
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):345 solv cache dir = /var/cache/zypp/solv
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper++] Zypper.cc(processGlobalOptions):346 package cache dir = /tmp/CH265TQIfT
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(processGlobalOptions):350 Repositories enabled
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(processGlobalOptions):353 DONE
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypper] Zypper.cc(doCommand):479 START
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(_openLockFile):179 Open lockfile /run/zypp.pid
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(readLockFile):234 read: Lockfile /run/zypp.pid has pid 15045 (our pid: 15312) 
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(isProcessRunning):206 Checking /proc/15045{d 0555 0/0}
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp++] ZYppFactory.cc(isProcessRunning):220 Is running: /usr/libexec/packagekitd
2023-05-24 13:09:49 <2> localhost.localdomain(15312) [zypp] ZYppFactory.cc(zyppLocked):281 15045 is running and has a ZYpp lock. Sorry.
2023-05-24 13:09:49 <1> localhost.localdomain(15312) [zypp] ZYppFactory.cc(_closeLockFile):197 Close lockfile /run/zypp.pid
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 ZYppFactory.cc(getZYpp):415 THROW:    System management is locked by the application with pid 15045 (/usr/libexec/packagekitd).
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Close this application before trying again.
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Zypper.cc(assertZYppPtrGod):83 CAUGHT:   System management is locked by the application with pid 15045 (/usr/libexec/packagekitd).
2023-05-24 13:09:49 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Close this application before trying again.
2023-05-24 17:59:42 <1> localhost.localdomain(15312) [zypper] prompt.cc(get_prompt_reply):439 reply empty, returning the default: no (1)
2023-05-24 17:59:42 <3> localhost.localdomain(15312) [zypper] Zypper.cc(assertZYppPtrGod):119 A ZYpp transaction is already in progress.
2023-05-24 17:59:42 <2> localhost.localdomain(15312) [zypper] Zypper.h(setExitCode):161 setExitCode 7
2023-05-24 17:59:42 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Zypper.cc(assertZYppPtrGod):123 THROW:    ZYpp locked
2023-05-24 17:59:42 <5> localhost.localdomain(15312) [zypp-core] Exception.cc(log):186 Zypper.cc(doCommand):694 CAUGHT:   ZYpp locked
2023-05-24 17:59:42 <2> localhost.localdomain(15312) [zypper] Zypper.cc(doCommand):695 Caught exit request: exitCode 7
2023-05-24 17:59:42 <1> localhost.localdomain(15312) [zypper] Zypper.cc(cleanup):729 START
2023-05-24 17:59:42 <1> localhost.localdomain(15312) [zypper] main.cc(~Bye):98 ===== Exiting main(7) =====
Comment 5 Michael Andres 2023-05-24 19:37:43 UTC 
Thanks.

I don't know exactly what the build script does, but AFAICS `zypper` asks:
> PackageKit is blocking zypper. ...
> ...
> Ask PackageKit to quit? [yes/no] (no):

`zypper -q (quiet) asks just:
> Ask PackageKit to quit? [yes/no] (no):
Which is IMO ok.

`zypper >/dev/null` however fails to detect that it's not running on a terminal, displays nothing but waits for input. This is definitely a bug.
Comment 6 Christopher Yeleighton 2023-05-24 19:54:49 UTC 
(In reply to Michael Andres from comment #5)
> `zypper -q (quiet) asks just:
> > Ask PackageKit to quit? [yes/no] (no):
> Which is IMO ok.

It is not OK because these questions are passed through a line-buffered fork tier to the build log and thus invisible until answered, which is paradoxical.
Comment 7 Michael Andres 2023-05-24 20:19:06 UTC 
The question is what zypper can detect. 

In the first place it's an issue of 'build' because they should use --non-interactive or no line-bufering. Let's ask Marco as bugowner of build.

zypper itself could just fallback to --non-interactive if there is no tty to prompt. This would mitigate the impact on scripts forgetting to use -n.
Comment 8 Christopher Yeleighton 2023-05-24 20:36:33 UTC 
(In reply to Michael Andres from comment #7)
> In the first place it's an issue of 'build' because they should use
> --non-interactive or no line-bufering. Let's ask Marco as bugowner of build.

I also think that libzypp is not the right component for this bug.  If it can be fixed in the zypper executable, zypper is part of Basesystem.
Comment 9 Michael Andres 2023-05-25 05:58:24 UTC 
(In reply to Christopher Yeleighton from comment #8)
> I also think that libzypp is not the right component for this bug.  If it
> can be fixed in the zypper executable, zypper is part of Basesystem.

It is. libzypp and zypper are both maintained by us (zypp-maintainers). Some products offer component a 'libzypp', some a component 'zypper'. But they always serve both.