Description of problem: In dmesg we now see: [27524.928226] LVM: Logical Volume autoactivation enabled. [27524.928235] LVM: Activation generator successfully completed. I don't think we need this functionality after 27524 seconds of uptime after studying info from http://www.redhat.com/archives/lvm-devel/2012-July/msg00072.html. Perhaps this lvm thing coincided with runlevel 3 -> 5 change? So: does it have to run? I doubt it. Does it need logging about this? Same deal. Version-Release number of selected component (if applicable): systemd-204-9.fc19.x86_64 How reproducible: Run Fedora 19 for a while. Actual results: See above. Expected results: No such messages Additional info:
Generators are re-run on systemd reload or reexec. I'll let lvm2 folks decide what they want to log.
At least these two messages should be logged with lower loglevel (6 or even 7).
OK, I've changed that to LOG_DEBUG for normal operation and LOG_ERR for any error conditions if encountered: https://git.fedorahosted.org/cgit/lvm2.git/commit/?id=ea333a894e93f665a515986fdebf2a6c9e10d42a
lvm2-2.02.98-10.fc19 has been submitted as an update for Fedora 19. https://admin.fedoraproject.org/updates/lvm2-2.02.98-10.fc19
Package lvm2-2.02.98-10.fc19: * should fix your issue, * was pushed to the Fedora 19 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing lvm2-2.02.98-10.fc19' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2013-13665/lvm2-2.02.98-10.fc19 then log in and leave karma (feedback).
lvm2-2.02.98-10.fc19 has been pushed to the Fedora 19 stable repository. If problems still persist, please make note of it in this bug report.
# rpm -q lvm2 lvm2-2.02.98-10.fc19.x86_64 # dmesg|tail [185466.602925] LVM: Logical Volume autoactivation enabled. [185466.602936] LVM: Activation generator successfully completed. [185469.716855] LVM: Logical Volume autoactivation enabled. [185469.716860] LVM: Activation generator successfully completed. [185470.677887] LVM: Logical Volume autoactivation enabled. [185470.677892] LVM: Activation generator successfully completed. [185471.129771] LVM: Logical Volume autoactivation enabled. [185471.129775] LVM: Activation generator successfully completed. [185475.903026] LVM: Logical Volume autoactivation enabled. [185475.903031] LVM: Activation generator successfully completed.
Well, I've changed the log severity from default to log_debug only (which is the least that is available). This information is very helpful for us if something goes wrong. I don't want to remove it completely. But at the same time, I can't differentiate between the activation generator run at boot or just as a result of systemctl daemon-reload... Maybe the question here is why the systemd daemon-reload is called so many times on your machine then.
I did not do anything specific w.r.t. systemd. I just did a few times of init 3 and later init 5.
RPM scriptlets of packages shipping systemd units call systemctl daemon-reload. Do the messages correlate with running "yum update"?
I update fedora installations almost daily. So what is the actual fix here? (BTW, I do think the whole distro really strolls away from the UNIX concept: It logs stuff that does not need to be logged by default; it logs in the wrong places, it changes stuff around (init, grub...) with no real comparable alternative; it increases dependency hell, it robs us of the upgrade dvd, etc.)
The fix here is that the message is not shown on the command line directly (without quiet on kernel cmd line). Otherwise, the messages are still logged in dmesg (and I want them to be logged).
(In reply to Peter Rajnoha from comment #12) > The fix here is that the message is not shown on the command line directly > (without quiet on kernel cmd line). Otherwise, the messages are still logged > in dmesg (and I want them to be logged). (when someone ends up with unbootable system, this is the first thing I check - how the system was booted with LVM - whether event-based via udev or direct vgchange call)
Also you can filter out debug messages if you don't want them (journalctl -p).
What is the use of journalctl versus /var/log/messages, dmesg and other log files? Please let me choose my source of logging. I do not need filtering, I need less clutter in the first place.
I see no solution, I see no problem. I do not want this daemon. It produces just noise. vgchange -ay still works very well.
Check the message that `mount` emits for a nice comparison.
(In reply to udo from comment #15) > What is the use of journalctl versus /var/log/messages, dmesg and other log > files? > Please let me choose my source of logging. > I do not need filtering, I need less clutter in the first place. If you happen to end up with some problem, it's always better to have some debug message than nothing. In reply to udo from comment #16) > vgchange -ay still works very well. Not for devices plugged/unplugged on the fly (e.g. usb attached disks, or iscsi, or fcoe disks that can appear in the system as the user plugs/connects them in...). For this you really need event-based LVM. However, we'd like to make this event-based activation (lvmetad + udev) configurable so it can be switched off if needed (e.g. there's still no support for cluster yet with lvmetad). This is controlled by lvm.conf. And that generator just generates the units based on this info. I think there's no way how I could enable/disable the systemd units based on external config - the generators are exactly made for that. (In reply to udo from comment #17) > Check the message that `mount` emits for a nice comparison. ...the mount just mounts and nothing else, it does not have 2 distinct ways of how things get activated (or mounted in this context). This is really for us to make it better when something goes wrong and we're trying to help quickly... Or when we want to log how something works. That's the point of logging. Why would we need dmesg/journalctl or whatever otherwise...
(In reply to udo from comment #15) > I do not need filtering, I need less clutter in the first place. I think you need it as the system is getting more and more support and more and more tools/utilities exist in the system to support more use cases. The system just gets more mature and increasing count of log messages comes along with that...
...also, if each tool/utility would generate its own log file, that would be much worse and unmanageable in the end I think (I have a problem with this and that - where should I look???)
I would like to add an explanation of why the generator logs into dmesg instead of somewhere else: It is because generators may be run very early when no other logging is available. It may be possible to try logging to syslog first and then fall back to dmesg only if that fails, but I haven't thought this through to be certain that it would be safe.
(In reply to Michal Schmidt from comment #21) > I would like to add an explanation of why the generator logs into dmesg > instead of somewhere else: It is because generators may be run very early > when no other logging is available. It may be possible to try logging to > syslog first and then fall back to dmesg only if that fails, but I haven't > thought this through to be certain that it would be safe. Michal, isn't kmsg the only supported logging for generators?
The documentation (http://www.freedesktop.org/wiki/Software/systemd/Generators/) insists that kmsg is the only safe logging output for generators. On the other hand, to first try a non-blocking write to syslog might be safe.
'debug message' used to mean something that one could turn on, not something on by default as it is NOW. No thanks for the messages so no thanks for plugged lvm devices for me. Please give us a choice: how to stop that stuff? It would be the easiest way out for you but has been obfuscated for mere users like me. What do I edit in lvm.conf to turn it off? Why is it on by default? The same generators prevented us from easily debugging (!) problems with enabling encrypted swap, so so much for the joys and blessings of generators. Ask the systemd people about 'my' bug. Support is not the issue. Useless messages are the issue. Deflault should AGAIN be no logging on a correctly performed action. And most certainly not TWO lines on an action that succeeds that does not do anything for me The system simply needs to be quiet until someone goes wrong.
'LVM: Logical Volume autoactivation enabled.' Enabled when/where? I want to disable this auto-thing. Where is that procedure documented please? On a fully up to date Fedora 19: [ 44.682625] f71882fg: Found f71808e chip at 0x220, revision 49 [ 44.683319] systemd-udevd[1160]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 44.689031] f71882fg f71882fg.544: Fan: 1 is in duty-cycle mode [ 44.689869] systemd-udevd[1162]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 44.690382] systemd-udevd[1163]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 44.701419] f71882fg f71882fg.544: Fan: 2 is in RPM mode [ 44.704138] f71882fg f71882fg.544: Fan: 3 is in RPM mode [ 44.707702] systemd-udevd[1165]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 45.812615] systemd[1]: Unit cpupower.service entered failed state. [ 48.804279] systemd-udevd[1200]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.804611] systemd-udevd[1201]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.814303] systemd-udevd[1204]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.819715] systemd-udevd[1210]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.822442] systemd-udevd[1211]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.822725] systemd-udevd[1212]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.823519] systemd-udevd[1213]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.826405] systemd-udevd[1214]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.827176] systemd-udevd[1215]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.827908] systemd-udevd[1216]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.829078] systemd-udevd[1217]: failed to execute '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' 'socket:@/org/freedesktop/hal/udev_event': No such file or directory [ 48.944125] systemd-logind[1176]: Watching system buttons on /dev/input/event4 (Power Button) [ 48.948194] systemd-logind[1176]: Watching system buttons on /dev/input/event3 (Power Button) [ 56.086816] r8169 0000:02:00.0 eth0: link down [ 88.877114] NFSD: starting 90-second grace period (net ffffffff81590e80) [ 107.080581] tda1004x: setting up plls for 53MHz sampling clock [ 109.211252] tda1004x: timeout waiting for DSP ready [ 109.212480] tda1004x: found firmware revision 0 -- invalid [ 109.212483] tda1004x: trying to boot from eeprom [ 111.521753] tda1004x: timeout waiting for DSP ready [ 111.522949] tda1004x: found firmware revision 0 -- invalid [ 111.522952] tda1004x: waiting for firmware upload... [ 113.149941] tda1004x: found firmware revision 20 -- ok [ 113.224569] tda1004x: setting up plls for 53MHz sampling clock [ 113.350270] tda1004x: found firmware revision 20 -- ok [ 113.424437] tda1004x: setting up plls for 53MHz sampling clock [ 113.550150] tda1004x: found firmware revision 20 -- ok [ 862.761531] r8169 0000:02:00.0 eth0: link up [64978.161564] LVM: Logical Volume autoactivation enabled. [64978.161568] LVM: Activation generator successfully completed. [65162.432670] LVM: Logical Volume autoactivation enabled. [65162.432674] LVM: Activation generator successfully completed. [65162.461709] LVM: Logical Volume autoactivation enabled. [65162.461713] LVM: Activation generator successfully completed. [65175.494814] LVM: Logical Volume autoactivation enabled. [65175.494818] LVM: Activation generator successfully completed. [65180.421691] LVM: Logical Volume autoactivation enabled. [65180.421695] LVM: Activation generator successfully completed. [65196.199164] LVM: Logical Volume autoactivation enabled. [65196.199169] LVM: Activation generator successfully completed. [65196.861881] LVM: Logical Volume autoactivation enabled. [65196.861885] LVM: Activation generator successfully completed. [65200.816633] LVM: Logical Volume autoactivation enabled. [65200.816637] LVM: Activation generator successfully completed. [65201.450031] LVM: Logical Volume autoactivation enabled. [65201.450035] LVM: Activation generator successfully completed. [65203.574472] LVM: Logical Volume autoactivation enabled. [65203.574476] LVM: Activation generator successfully completed. [65206.874681] LVM: Logical Volume autoactivation enabled. [65206.874685] LVM: Activation generator successfully completed. [65209.980225] LVM: Logical Volume autoactivation enabled. [65209.980229] LVM: Activation generator successfully completed. [65213.978611] LVM: Logical Volume autoactivation enabled. [65213.978615] LVM: Activation generator successfully completed. [65215.868002] LVM: Logical Volume autoactivation enabled. [65215.868006] LVM: Activation generator successfully completed. [65219.874338] nfsd: last server has exited, flushing export cache [65220.081116] NFSD: starting 90-second grace period (net ffffffff81590e80) [65220.105476] nfsd: last server has exited, flushing export cache [65220.154667] NFSD: starting 90-second grace period (net ffffffff81590e80) [65220.326316] LVM: Logical Volume autoactivation enabled. [65220.326320] LVM: Activation generator successfully completed. [65247.404795] LVM: Logical Volume autoactivation enabled. [65247.404799] LVM: Activation generator successfully completed. [65256.754107] LVM: Logical Volume autoactivation enabled. [65256.754111] LVM: Activation generator successfully completed. [65263.168178] LVM: Logical Volume autoactivation enabled. [65263.168182] LVM: Activation generator successfully completed. [65274.297174] LVM: Logical Volume autoactivation enabled. [65274.297178] LVM: Activation generator successfully completed. [65336.648833] LVM: Logical Volume autoactivation enabled. [65336.648837] LVM: Activation generator successfully completed. [169244.482830] traps: polkitd[1231] general protection ip:7f02da0fb9d2 sp:7fff83d35b00 error:0 in libmozjs-17.0.so[7f02d9fc4000+3a7000] [181126.530526] LogServer[1992]: segfault at 7f179000b15a ip 00007f179000b15a sp 00007f179f43d648 error 15 [181140.363516] LogServer[4059]: segfault at 20 ip 0000000000000020 sp 00007fbd7ac1f648 error 14 in mythlogserver[400000+4000] [181200.089349] tda1004x: setting up plls for 53MHz sampling clock [181200.214767] tda1004x: found firmware revision 20 -- ok [181200.289224] tda1004x: setting up plls for 53MHz sampling clock [181200.414651] tda1004x: found firmware revision 20 -- ok [181200.489091] tda1004x: setting up plls for 53MHz sampling clock [181200.614519] tda1004x: found firmware revision 20 -- ok [340334.606592] LVM: Logical Volume autoactivation enabled. [340334.606596] LVM: Activation generator successfully completed. [340342.300721] LVM: Logical Volume autoactivation enabled. [340342.300725] LVM: Activation generator successfully completed. [340343.260832] LVM: Logical Volume autoactivation enabled. [340343.260836] LVM: Activation generator successfully completed. [340345.369830] LVM: Logical Volume autoactivation enabled. [340345.369834] LVM: Activation generator successfully completed. [340346.785718] LVM: Logical Volume autoactivation enabled. [340346.785722] LVM: Activation generator successfully completed. [340351.090702] LVM: Logical Volume autoactivation enabled. [340351.090706] LVM: Activation generator successfully completed. [490695.966698] LVM: Logical Volume autoactivation enabled. [490695.966702] LVM: Activation generator successfully completed. [490697.238002] LVM: Logical Volume autoactivation enabled. [490697.238006] LVM: Activation generator successfully completed. [490706.167143] LVM: Logical Volume autoactivation enabled. [490706.167146] LVM: Activation generator successfully completed. [490708.802489] LVM: Logical Volume autoactivation enabled. [490708.802493] LVM: Activation generator successfully completed. [490712.070248] LVM: Logical Volume autoactivation enabled. [490712.070387] LVM: Activation generator successfully completed. [490717.607716] LVM: Logical Volume autoactivation enabled. [490717.607720] LVM: Activation generator successfully completed. [490735.851235] type=1305 audit(1376115762.739:2): audit_pid=26488 old=0 auid=4294967295 ses=4294967295 res=1 [517385.886415] fuse init (API version 7.21) [560259.164072] LVM: Logical Volume autoactivation enabled. [560259.164076] LVM: Activation generator successfully completed. [1044920.504056] LVM: Logical Volume autoactivation enabled. [1044920.504060] LVM: Activation generator successfully completed. [1375368.319324] LVM: Logical Volume autoactivation enabled. [1375368.319328] LVM: Activation generator successfully completed. Is that progress? Just as the .xsession-errors removal, and no response yet to the bug about that, it is a rather debilitating development.
Also: comment 19 suggests that more logging means more maturity. That is actual nonsense and the reverse doctrine of what a proper UNIX software should do. Please study UNIX history, please see how the basic tools communicate on the console. Please stop superfluous logging in the wrong places for the wrong reasons. There is no reason unless something goes wrong or perhaps at the very first startup. But even then...
(In reply to udo from comment #25) > [ 44.683319] systemd-udevd[1160]: failed to execute > '/usr/lib/udev/socket:@/org/freedesktop/hal/udev_event' > 'socket:@/org/freedesktop/hal/udev_event': No such file or directory err... which udev rule wants to talk to hal these days?
Some remaining fc15 (!) hal-related rpms. So much for well working upgrade procedures. (but thanks for mentioning!)
(In reply to udo from comment #25) > 'LVM: Logical Volume autoactivation enabled.' > Enabled when/where? > I want to disable this auto-thing. The lvm2-activation-generator is about something else... You don't need to disable the autoactivation. The purpose of the lvm2-activation-generator here is simply to generate the activation units (that call vgchange -aay directly) to activate LVM volumes IF lvmetad is not used (global/use_lvmetad=0 set in the /etc/lvm/lvm.conf). In that case, the autoactivation is not used as well (and it's not even possible as we need some daemon to cache the LVM state so we know that a VG is complete without any scanning - this is exactly the purpose of lvmetad). Otherwise, if global/use_lvmetad=1 is set in the /etc/lvm/lvm.conf, these activation units are totally useless as the LVM activation is switched to automatic mode and we don't need to call any extra vgchange -aay. Anyway, I think it's really not worth to spend more time disputing about these debug messages. To be honest, there really are more serious things to solve and things to spend time on - so I've removed those debug messages and I've kept only error messages... I see your point that it makes sense for boot, bot not later - but that's just a consequence that systemd reloads (including those generators). But I can't control that - the generators ARE revalidated. At least you saw what really happened in your system. Anyway, let's close this as it's nonsense to dispute about this more: https://git.fedorahosted.org/cgit/lvm2.git/commit/?id=99fe3b88d270fa310d05dd093bea6dd74dc75642 I've also added a few comments to lvm.conf for use_lvmetad so the relation with autoactivation is more clear: https://git.fedorahosted.org/cgit/lvm2.git/commit/?id=be9f4c77c93f347131f46a128013b0f4af8e5b32
(btw, the lvm2-activation-generator is always run, it's not supposed to be disabled. It either generates those units or exits immediately based on use_lvmetad lvm.conf setting - that's the exact and simple purpose of it)
(the generator is used because I can't make systemd units conditional based on external configuration)
Not even a decent workaround is offered like: do not bug (!) us anymore after a boot is completed. (systemd can provide a status about that I hope)