Bug 154352

Summary: [zypp] Source re-init does not start from cache in 2nd stage installation
Product: [openSUSE] SUSE Linux 10.1 Reporter: Klaus Kämpf <kkaempf>
Component: libzyppAssignee: Stanislav Visnovsky <visnov>
Status: RESOLVED FIXED QA Contact: Klaus Kämpf <kkaempf>
Severity: Blocker    
Priority: P5 - None CC: aj, dmacvicar
Version: Beta 6   
Target Milestone: ---   
Hardware: Other   
OS: Other   
Whiteboard:
Found By: Other Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: logs for 2nd stage only (shortened)
zypp.tgz
log when CD2 is skipped in 2nd stage

Description Klaus Kämpf 2006-03-01 13:24:19 UTC
see $summary
Comment 1 Klaus Kämpf 2006-03-01 13:24:52 UTC
It looks like /var/lib/YaST2/remaining isn't properly read in this case (no media in drive)
Comment 2 Klaus Kämpf 2006-03-01 13:25:15 UTC
This would also explain why all CDs are skipped
Comment 3 Klaus Kämpf 2006-03-01 13:27:00 UTC
Hmm, the file is read correctly but its content not evaluated.
Comment 4 Klaus Kämpf 2006-03-01 13:46:52 UTC
Pkg::PkgInstall is called but the logs don't show the return code.

So here's the suspicion I have:

The source is recreated from cache but this fails (logs show physical media being initialized or accessed).
Since source creation failed, no packages are known.
PkgInstall passes the remaining package to the backend which doesn't find a match.
The call to TargetImpl::commit shows zero package to install.
Comment 5 Duncan Mac-Vicar 2006-03-01 13:53:40 UTC
Can I see /var/zypp dir content?
Comment 6 Klaus Kämpf 2006-03-01 13:55:49 UTC
Created attachment 70795 [details]
logs for 2nd stage only (shortened)
Comment 7 Klaus Kämpf 2006-03-01 13:59:05 UTC
The log supports my suspicion:

...
2006-03-01 13:34:22 <2> luna(2610) [media] Mount.cc(mount):129 mount /dev/hdc /var/adm/mount/AP_0x00000002: Mounting media failed
...
2006-03-01 13:34:22 <3> luna(2610) [susetags] SuseTagsImpl.cc(factoryInit):161 Cannot read /media.1/media file, cannot initialize source
...
2006-03-01 13:34:22 <3> luna(2610) [YCP] Packages.ycp:512 Pkg::SourceStartCache failed
Comment 8 Klaus Kämpf 2006-03-01 14:04:02 UTC
*** Bug 154343 has been marked as a duplicate of this bug. ***
Comment 9 Klaus Kämpf 2006-03-01 14:24:34 UTC
comment #5: It was luna.suse.de but I don't know if its already reused.
Comment 10 Klaus Kämpf 2006-03-01 15:00:13 UTC
Hmm, I tried to reproduce the bug (boot into 2nd stage with no CD in drive) but this time, the "please insert CD2" popup did appear.

However, after inserting the wrong CD (I only had CD1 available) the next popup asked for CD3 :-(
Comment 11 Stanislav Visnovsky 2006-03-01 15:04:38 UTC
Which zypp revision? See the RPM changelog.
Comment 12 Klaus Kämpf 2006-03-01 15:08:22 UTC
rev 2169
Comment 13 Stanislav Visnovsky 2006-03-01 15:10:25 UTC
Recheck with at least rev. 2181
Comment 14 Holger Sickenberg 2006-03-01 15:21:29 UTC
Created attachment 70815 [details]
zypp.tgz

Content of /val/lib/zypp
Comment 15 Klaus Kämpf 2006-03-01 17:28:57 UTC
I just checked with rev 2194 and its still buggy.
This is also the cause for bug 153073. (But I won't continue in 153073 looking at the laaarge CC list ...)
Comment 16 Klaus Kämpf 2006-03-01 17:29:27 UTC
So I make this a blocker now. To be sorted out first thing tomorrow morning.
Comment 17 Stanislav Visnovsky 2006-03-02 07:16:40 UTC
Please, attach the logs.
Comment 18 Klaus Kämpf 2006-03-02 07:39:34 UTC
Even more logs ? ;-)
Comment 19 Klaus Kämpf 2006-03-02 07:41:55 UTC
Created attachment 70919 [details]
log when CD2 is skipped in 2nd stage
Comment 20 Klaus Kämpf 2006-03-02 07:45:15 UTC
I discussed this with Duncan yesterday. It looks like 3 (related) bugs
1. Restore from cache tries to access physical media
2. If physical access fails, cache restore is skipped leading to only installed packages in the zypp pool. So any 'PkgInstall' requests (which are issued according to the log) cant find packages
3. Return code from PkgInstall is ignored
Comment 21 Stanislav Visnovsky 2006-03-02 07:52:00 UTC
Where do you see physical access in the logs? (Of course, besides installing packages). The important calls are 'attach'
Comment 22 Klaus Kämpf 2006-03-02 08:24:17 UTC
Argh, comment #19 has the wrong log :-(
Comment 23 Klaus Kämpf 2006-03-02 08:24:45 UTC
Comment on attachment 70919 [details]
log when CD2 is skipped in 2nd stage

wrong log
Comment 24 Klaus Kämpf 2006-03-02 08:29:47 UTC
The log from comment #6 is it:
line 658:

SourceManager.cc(restore):270 Restoring source: url:[cd:///?devices=/dev/hdc] product_dir:[] alias:[cd:///?devices=/dev/hdc] cache_dir:[/var/lib/zypp/cache/0]

and then line 676 and following:

2006-03-01 13:34:22 <1> luna(2610) [zypp] SourceFactory.cc(createFrom):147 Trying the SUSE tags source
2006-03-01 13:34:22 <0> luna(2610) [susetags] SuseTagsImpl.cc(cacheExists):102 0
2006-03-01 13:34:22 <0> luna(2610) [media] MediaCD.cc(attachTo):278 next 0 last -1
2006-03-01 13:34:22 <0> luna(2610) [media] MediaCD.cc(attachTo):307 count 0
2006-03-01 13:34:22 <0> luna(2610) [media] MediaCD.cc(closeTray):199 Close tray /dev/hdc
2006-03-01 13:34:22 <0> luna(2610) [media] MediaHandler.cc(createAttachPoint):291 Trying to create attach point in /var/adm/mount
2006-03-01 13:34:22 <0> luna(2610) [zypp] PathInfo.cc(_Log_Result):291 mkdir /var/adm/mount/AP_0x00000002 00755
2006-03-01 13:34:22 <1> luna(2610) [media] MediaHandler.cc(createAttachPoint):268 Created default attach point /var/adm/mount/AP_0x00000002
2006-03-01 13:34:22 <0> luna(2610) [zypp] ExternalProgram.cc(start_program):166 Executing '/bin/mount' '-t' 'iso9660' '-o' 'ro' '/dev/hdc' '/var/adm$

it then tries to find media.1/media which fails (well, there is no media in the drive) and gives up:
Packages.ycp:512 Pkg::SourceStartCache failed
Comment 25 Stanislav Visnovsky 2006-03-02 08:36:23 UTC
Yes, but the log is from older revision of libzypp. I've tried hard to track down all physical accesses and avoid them when using cache.
Comment 26 Klaus Kämpf 2006-03-02 11:28:58 UTC
fixed in rev 2174 (reload-cache.diff)
Comment 27 Klaus Kämpf 2006-03-02 11:35:36 UTC
confirmed. Works nicely now :-)