Bug 672527
Summary: | Remote logging via virtio failed | ||||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
Product: | [Fedora] Fedora | Reporter: | Hongqing Yang <hoyang> | ||||||||||||||
Component: | anaconda | Assignee: | Ales Kozumplik <akozumpl> | ||||||||||||||
Status: | CLOSED ERRATA | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||||||||||||
Severity: | urgent | Docs Contact: | |||||||||||||||
Priority: | unspecified | ||||||||||||||||
Version: | rawhide | CC: | akozumpl, amit.shah, anaconda-maint-list, awilliam, hoyang, jlaska, jonathan, jzeleny, vanmeeuwen+fedora | ||||||||||||||
Target Milestone: | --- | Keywords: | Reopened | ||||||||||||||
Target Release: | --- | ||||||||||||||||
Hardware: | x86_64 | ||||||||||||||||
OS: | Linux | ||||||||||||||||
Whiteboard: | AcceptedNTH | ||||||||||||||||
Fixed In Version: | anaconda-15.26-1.fc15 | Doc Type: | Bug Fix | ||||||||||||||
Doc Text: | Story Points: | --- | |||||||||||||||
Clone Of: | Environment: | ||||||||||||||||
Last Closed: | 2011-04-02 03:19:10 UTC | Type: | --- | ||||||||||||||
Regression: | --- | Mount Type: | --- | ||||||||||||||
Documentation: | --- | CRM: | |||||||||||||||
Verified Versions: | Category: | --- | |||||||||||||||
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||||||
Cloudforms Team: | --- | Target Upstream Version: | |||||||||||||||
Embargoed: | |||||||||||||||||
Bug Depends On: | 677713 | ||||||||||||||||
Bug Blocks: | 657619 | ||||||||||||||||
Attachments: |
|
Description
Hongqing Yang
2011-01-25 12:54:35 UTC
Hi, (In reply to comment #0) > <channel type='tcp'> > <source mode='connect' host='127.0.0.1' service='6080'/> > <protocol type='raw'/> > <target type='virtio' name='org.fedoraproject.anaconda.log.0'/> > <address type='virtio-serial' controller='0' bus='0' port='0'/> > </channel> this looks correct. Mine looks: <channel type='tcp'> <source mode='connect' host='127.0.0.1' service='6080'/> <protocol type='raw'/> <target type='virtio' name='org.fedoraproject.anaconda.log.0'/> <alias name='channel0'/> <address type='virtio-serial' controller='0' bus='0' port='0'/> </channel> so I have an extra alias tag, but that should not be important. > 4. eval `./analog -p 6080 ./home/hongqing/logs -o rsyslogd.conf -s` Look at the dot in front of the logs path: it says the path behind it is relative to your current working directory (which in your case is /usr/libexec/anaconda). This concept is heavily used in the linux shell, see also http://www.linfo.org/current_directory.html. To do what you want to do just give analog the absolute path, for instance: ./analog -p 6080 /home/hongqing/logs -o rsyslogd.conf -s > There is no logs in /home/hongqing/logs, and directory /home/hongqing/logs is > create under anaconda, it does not recognize /home as the user's home. > only two logs in /home/hongqing/logs You say you only can see two log files and they are almost empty. This would point to the fact that the sending side of the communication (that is the guest machine) does not write anything into the virtio port. This can be for two reasons: 1) /dev/virtio-ports/org.fedoraproject.anaconda.1 does not exist on guest (but you confirmed in a previous email it did exist) 2) the communication is not forwarded to the destination tcp port on the host for some reason. You can check if this is the case by running 'nc -l 0.0.0.0 6080' and then starting the guest. The terminal where you started nc should get filled quickly with the raw debug messages. > Additional info: > org.fedoraproject.org.anaconda.log.0 exists under /dev/virtio-ports/ on guest > ryslog.conf can be found in enclosure. I think you forgot to attach it. Also when I'm thinking about it: what distro are you trying to install? What is the anaconda version there? Created attachment 475329 [details]
guest define xml
Created attachment 475330 [details]
rsyslog config file
Hi, Ales The Anaconda version is 14.22, and both the host and guest are Fedora 14. I have used eval `./analog -p 6080 /home/hongqing/logs -o rsyslogd.conf -s`, it works fine. I has opened port use nc -l 0.0.0.0 6080 as you said above, and start the guest, there is nothing output on the terminal. if I do not open it, the guest will give error: Error starting domain: internal error Process exited while reading console log output: char device redirected to /dev/pts/2 inet_connect_opts: connect(ipv4,127.0.0.1,127.0.0.1,6080): Connection refused chardev: opening backend "socket" failed so i think the guest has already tried to connect with the host on port 6080. one thing different is, under the guest /dev/virtio-ports/ is org.fedoraproject.anaconda.log.0, not org.fedoraproject.anaconda.1 (In reply to comment #5) > Hi, Ales > > The Anaconda version is 14.22, and both the host and guest are Fedora 14. ok, that is my setup, so it should work. > I have used eval `./analog -p 6080 /home/hongqing/logs -o rsyslogd.conf -s`, > it works fine. ok, we have that figured out. > I has opened port use nc -l 0.0.0.0 6080 as you said above, and start the > guest, there is nothing output on the terminal. if I do not open it, the guest > will give error: > Error starting domain: internal error Process exited while reading console log > output: char device redirected to /dev/pts/2 > inet_connect_opts: connect(ipv4,127.0.0.1,127.0.0.1,6080): Connection refused > chardev: opening backend "socket" failed this shows us that we have the port number and everything right, but yet we see no messages coming in. Either 1) the rsyslog on the guest side doesn't write anything into the port, or 2) your kvm/virtio is simply broken for some reason. To decide between these two explanations, can you please: 1) start nc on the host as described above 2) start the guest, wait until the stage2 GUI comes up. 3) on the guest: ctrl-alt-f2 to switch to the terminal, 4) then 'killall rsyslogd' 5) try to write something into the port manually, like: echo "hi host" > /dev/virtio-ports/org.fedoraproject.anaconda.log.0 the message 'hi host' should appear the the terminal where you started nc. Does that happen? If yes: please attach /etc/rsyslog.conf from the guest to this BZ. You can copy it out of the installer using scp, in a manner similar to what is described here: http://fedoraproject.org/wiki/Anaconda/Logging#Logging_tips Thanks. > one thing different is, under the guest /dev/virtio-ports/ is > org.fedoraproject.anaconda.log.0, not org.fedoraproject.anaconda.1 Sorry, my bad, it should always be /dev/virtio-ports/org.fedoraproject.anaconda.log.0. (In reply to comment #6) > (In reply to comment #5) > > Hi, Ales > > > > The Anaconda version is 14.22, and both the host and guest are Fedora 14. > > ok, that is my setup, so it should work. > > > I have used eval `./analog -p 6080 /home/hongqing/logs -o rsyslogd.conf -s`, > > it works fine. > > ok, we have that figured out. > > > I has opened port use nc -l 0.0.0.0 6080 as you said above, and start the > > guest, there is nothing output on the terminal. if I do not open it, the guest > > will give error: > > Error starting domain: internal error Process exited while reading console log > > output: char device redirected to /dev/pts/2 > > inet_connect_opts: connect(ipv4,127.0.0.1,127.0.0.1,6080): Connection refused > > chardev: opening backend "socket" failed > > this shows us that we have the port number and everything right, but yet we see > no messages coming in. Either > 1) the rsyslog on the guest side doesn't write anything into the port, or > 2) your kvm/virtio is simply broken for some reason. > > To decide between these two explanations, can you please: > 1) start nc on the host as described above > 2) start the guest, wait until the stage2 GUI comes up. > 3) on the guest: ctrl-alt-f2 to switch to the terminal, > 4) then 'killall rsyslogd' > 5) try to write something into the port manually, like: > echo "hi host" > /dev/virtio-ports/org.fedoraproject.anaconda.log.0 > > the message 'hi host' should appear the the terminal where you started nc. Does > that happen? If yes: please attach /etc/rsyslog.conf from the guest to this BZ. > You can copy it out of the installer using scp, in a manner similar to what is > described here: > http://fedoraproject.org/wiki/Anaconda/Logging#Logging_tips > > Thanks. > > > one thing different is, under the guest /dev/virtio-ports/ is > > org.fedoraproject.anaconda.log.0, not org.fedoraproject.anaconda.1 > > Sorry, my bad, it should always be > /dev/virtio-ports/org.fedoraproject.anaconda.log.0. Ales, I tried what u said above, there is no /dev/virtio-ports/org.fedoraproject.anaconda.log.0 during the installation, after installation, rebooting the guest, it comes, it seems this is the point of the problem. (In reply to comment #7)> > Ales, > > I tried what u said above, there is no > /dev/virtio-ports/org.fedoraproject.anaconda.log.0 during the installation, > after installation, rebooting the guest, it comes, it seems this is the point > of the problem. Allright. That sounds like anaconda is not loading the required virtio module. Can you please attach /tmp/anaconda.log, /tmp/syslog and contents of /proc/cpuinfo to this bug? Created attachment 475368 [details]
anaconda log
Created attachment 475370 [details]
anaconda.syslog
Created attachment 475371 [details]
cpuinfo
this is going to be difficult: the logs do not help as much since the part where anaconda enables the virtio logging of course has to happen before we initialize logging (and before we get the first logging messages). Can you paste the output of 'lsmod' from the installer? Also you say that the virtio port device is missing during install: what happens if you manually do 'modprobe virtio_pci' from the install? Does the virtio port appear?
> I tried what u said above, there is no
> /dev/virtio-ports/org.fedoraproject.anaconda.log.0 during the installation,
> after installation, rebooting the guest, it comes, it seems this is the point
> of the problem.
Hm. What if you just reboot the machine after stage2 starts and let it boot into the installer again? Can you see the virtio ports then?
Created attachment 475378 [details]
lsmod installer modules
The module modprobe virtio_pci has been loaded, if I modprobe virtio_pci, nothing happens. there is still no /virtio-ports/ folder. I see there are some modules should be loaded as stated in analog, such as imtcp.so and imuxsock. I cannot find the rsyslog folder and these two modules. (In reply to comment #12) > this is going to be difficult: the logs do not help as much since the part > where anaconda enables the virtio logging of course has to happen before we > initialize logging (and before we get the first logging messages). > > Can you paste the output of 'lsmod' from the installer? Also you say that the > virtio port device is missing during install: what happens if you manually do > 'modprobe virtio_pci' from the install? Does the virtio port appear? (In reply to comment #13) > > I tried what u said above, there is no > > /dev/virtio-ports/org.fedoraproject.anaconda.log.0 during the installation, > > after installation, rebooting the guest, it comes, it seems this is the point > > of the problem. > > Hm. What if you just reboot the machine after stage2 starts and let it boot > into the installer again? Can you see the virtio ports then? Hi, Ales, I have tested that, after I reboot, a new id will be assigned to the guest. and also it does not make sense. (In reply to comment #15) > The module modprobe virtio_pci has been loaded, if I modprobe virtio_pci, > nothing happens. there is still no /virtio-ports/ folder. note that we are looking for /dev/virtio-ports folder. and how come you say it does not exist on the guest when you said in Comment #0 it does?: > Additional info: > org.fedoraproject.org.anaconda.log.0 exists under /dev/virtio-ports/ on guest > I see there are some modules should be loaded as stated in analog, such as > imtcp.so and imuxsock. I cannot find the rsyslog folder and these two modules. > > have you got rsyslog rpm installed on the host? or are you talking about the guest? (In reply to comment #17) > (In reply to comment #15) > > The module modprobe virtio_pci has been loaded, if I modprobe virtio_pci, > > nothing happens. there is still no /virtio-ports/ folder. > > note that we are looking for /dev/virtio-ports folder. > > and how come you say it does not exist on the guest when you said in Comment #0 > it does?: /dev/virtio-ports does not exits during installation, after installation finished and system reboots, perform the post installation configuration steps, the folder /dev/virtio-ports exits. > > Additional info: > > org.fedoraproject.org.anaconda.log.0 exists under /dev/virtio-ports/ on guest > > > I see there are some modules should be loaded as stated in analog, such as > > imtcp.so and imuxsock. I cannot find the rsyslog folder and these two modules. > > > > > > have you got rsyslog rpm installed on the host? or are you talking about the > guest? please ignore this. the modules imtcp and imuxsock is under folder /usr/lib64, I only checked /usr/lib. sorry for the inconvenience. OK, I am running out of ideas here. In your email from yesterday you mention that you use the following steps to add the virtio channel: > 1. use virt-manager create a guest from a local iso image > 2. at the step starting bios, I pause it. > virsh -c qemu:///system > edit <machinename> > paste the script below in the <devices> section > > <channel type='tcp'> > <source mode='connect' host='127.0.0.1' service='6080'/> > <target type='virtio' name='org.fedoraproject.anaconda.log.0'/> > </channel> Are you still doing that? Because adding the channel after the machine was started would not cause it to see the new channel! That's why I asked what happens if you reboot into the same installation again in comment 13. Please try that and tell me if you can see the virtio ports. I am regularly rebooting the same virtual machine into installation many times, without touching its .xml definition (sometimes in virt-manager you need to change the booting order back to the cd media or pxe or what you have). (In reply to comment #19) > OK, > > I am running out of ideas here. In your email from yesterday you mention that > you use the following steps to add the virtio channel: > > > 1. use virt-manager create a guest from a local iso image > > 2. at the step starting bios, I pause it. > > virsh -c qemu:///system > > edit <machinename> > > paste the script below in the <devices> section > > > > <channel type='tcp'> > > <source mode='connect' host='127.0.0.1' service='6080'/> > > <target type='virtio' name='org.fedoraproject.anaconda.log.0'/> > > </channel> > > Are you still doing that? Because adding the channel after the machine was > started would not cause it to see the new channel! That's why I asked what > happens if you reboot into the same installation again in comment 13. Please > try that and tell me if you can see the virtio ports. I am regularly rebooting > the same virtual machine into installation many times, without touching its > .xml definition (sometimes in virt-manager you need to change the booting order > back to the cd media or pxe or what you have). Hi, Ales I realized it was wrong to pause and resume, I have replied you in the following email. Now What I doing is exactly the same with the description, Force off it, edit the xml, change boot option to cdrom, dumpxml guest, I can see channel is in the xml, then I start it to install, after installation, change boot option to hd. And also I have tried to restart it. The rsyslogd on guest and host are running. One funny thing happens, just now I tried to install Fedora 14 i386, It works fine, but I try the Fedora 14 x86_64, it still does not work. The host is Fedora 14 x86_64. I have downloaded the Fedora 14 x86_64 from a different mirror, the situation is the same. Doh! now I see that this is really the case with all x86_64 composes: it is so because virtio logging needs virtio_console kernel module. On i386 (where I usually test), this is built in the kernel so I never came across the necessity to pull it in. Will fix this for rawhide (F15), if you want to use virtio remote logging on F14 you will have to stick with i386. Thanks for helping in debugging this. please leave this opened until I commit the fix. Hi, Ales, I have tested the F15 rawhide, it seems still not work on F15 rawhide x86_64. Just an update on the status: there's my patch waiting for review: https://www.redhat.com/archives/anaconda-devel-list/2011-February/msg00055.html but a colleague who was reviewing it decided to try to get kernel make the virito_console module built-in just like on i386: see bug 677713. Waiting for how that bug will be resolved now. This change is not going to make F15 since it's hard to be seen as a blocker. (In reply to comment #26) > Waiting for how that bug will be resolved now. This change is not going to make > F15 since it's hard to be seen as a blocker. I agree this isn't a blocker for F15 Alpha, but we have *plenty* of time for F15 Final. While this isn't critical for any release criteria, this definitely fits the NICE-TO-HAVE criteria [1] since we'd like to use this for our install automation. How long do you anticipate patch reviews will take, do you expect this support will be available for F15 Beta or Final? This only fails on i386 right? We can still explore our proof-of-concept virtio logging with x86_64, right? [1] http://fedoraproject.org/wiki/QA:SOP_nth_bug_process > I agree this isn't a blocker for F15 Alpha, but we have *plenty* of time for > F15 Final. While this isn't critical for any release criteria, this definitely > fits the NICE-TO-HAVE criteria [1] since we'd like to use this for our install > automation. How long do you anticipate patch reviews will take, do you expect > this support will be available for F15 Beta or Final? There's just been an update from kernel. See https://bugzilla.redhat.com/show_bug.cgi?id=677713#c2. Can you guys retest on x86_64 f15 after kernel-2.6.38-0.rc5.git1.1.fc15 ? If it works we can close this (and I don't need a review for the patch). > > This only fails on i386 right? We can still explore our proof-of-concept > virtio logging with x86_64, right? The other way round: this only fails on x86_64 and works on i386. So you can already try this out on i386 (see comment 21 and comment 23). I'd suggest to attempt to load the virtio-console module in any case. This will prevent such incidences with other architectures and distributions. There's one more thing why a built-in module is more useful: if it is not, and we modprobe it manually, the virito device doesn't appear right after the modprobe returns but a second or two later. This means we need that ugly sleep()y loop in anaconda to wait for it to come up: if the user did not start a machine that actually has any virtio channels (which we can only know after the timeout) this wait is a waste of time. I also witnessed some random freezes shortly after this point in anaconda's loader with my proposed patch. But that might have been something else. (In reply to comment #28) > > I agree this isn't a blocker for F15 Alpha, but we have *plenty* of time for > > F15 Final. While this isn't critical for any release criteria, this definitely > > fits the NICE-TO-HAVE criteria [1] since we'd like to use this for our install > > automation. How long do you anticipate patch reviews will take, do you expect > > this support will be available for F15 Beta or Final? > > There's just been an update from kernel. See > https://bugzilla.redhat.com/show_bug.cgi?id=677713#c2. > > Can you guys retest on x86_64 f15 after kernel-2.6.38-0.rc5.git1.1.fc15 ? > > If it works we can close this (and I don't need a review for the patch). > > > > > This only fails on i386 right? We can still explore our proof-of-concept > > virtio logging with x86_64, right? > > The other way round: this only fails on x86_64 and works on i386. So you can > already try this out on i386 (see comment 21 and comment 23). just tested on f15-alpha-rc1 with kernel version 2.6.38-0.rc5.git1.1.fc15, it still does not work. > just tested on f15-alpha-rc1 with kernel version 2.6.38-0.rc5.git1.1.fc15, it
> still does not work.
Hongqing, what architecture is that?
Thanks.
still X86_64 I checked the kernel, seems not fixed still: https://bugzilla.redhat.com/show_bug.cgi?id=677713#c4 Let's wait for what they have to say. Hongqing, please see https://bugzilla.redhat.com/show_bug.cgi?id=677713#c6 and test with the kernel version mentioned there (not sure if it's going to make f15 or just rawhide). Thanks. Ales, I have tested the kernel 2.6.38-0.rc6.git6.1.fc15.x86_64, now the port org.fedoraproject.anaconda.log.0 is created during installation. It can also communicate with the host by doing like below: echo "hello host" > org.fedoraproject.anaconda.log.0. But the virtio_pci module is not loaded, the logs are still not forwarded to the host. (In reply to comment #36) > Ales, > > I have tested the kernel 2.6.38-0.rc6.git6.1.fc15.x86_64, now the port > org.fedoraproject.anaconda.log.0 is created during installation. It can also > communicate with the host by doing like below: > echo "hello host" > org.fedoraproject.anaconda.log.0. If this works, the communication part works alright. > But the virtio_pci module is not loaded, the logs are still not forwarded to > the host. That's now built into the kernel, you won't see modules for virtio-pci and virtio-console. Amit, With the new kernel I found out that the devices appear at the point where the anaconda loader makes udevadm settle all devices, many modules are loaded then. What specific modules do I need to load for the device to appear very soon after boot (we need the logging much sooner than when we can actually start calling udev)? I tried manually loading virtio_net and virtio_blk, but that's not enough. Thanks. Ales The module can get loaded pretty soon, but for the /dev/virtio-ports/... files to appear, udev needs to be around. That's because udev rules create the entries in /dev/virtio-ports/. Thanks Ales, Amit and Hongqing. Proposing as a nice-to-have (NTH) fix for Fedora 15 Beta. This isn't a high profile feature where many users will be impacted, but this does restrict the installation automation work Hongqing has been doing. Having virtio logging on both architectures during virt-installs will help us move to the next step with regards to installation automation. I support this as a NTH. Patch awaiting review: https://www.redhat.com/archives/anaconda-devel-list/2011-March/msg00114.html Fixed in F15: Fixed on master: de3d6e5538ca851a261492924ff80585db7ab455. Discussed at 2011-03-11 blocker/NTH review meeting. Agreed this is accepted as nice-to-have due to impact on QA's automated installation testing process. anaconda-15.26-1.fc15 has been submitted as an update for Fedora 15. https://admin.fedoraproject.org/updates/anaconda-15.26-1.fc15 Package anaconda-15.26-1.fc15: * should fix your issue, * was pushed to the Fedora 15 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing anaconda-15.26-1.fc15' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/anaconda-15.26-1.fc15 then log in and leave karma (feedback). fixed on anaconda 15.19 and kernel-2.6.35.11-83.fc14.x86_64. anaconda-15.26-1.fc15 has been pushed to the Fedora 15 stable repository. If problems still persist, please make note of it in this bug report. |