Can't reproduce.

Incidentally, we have almost the same CPU (mine is faster, but the same CPU sig ID) and same microcode revision.

Also, your title is wrong: The microcode update only failed for CPU0.

[ 7.808242] microcode: CPU0 sig=0x20652, pf=0x10, revision=0x9
[ 10.332896] firmware microcode: firmware_loading_store: unexpected value (0)

Does it work if you use initscripts?

How about blacklisting the module and loading it manually after boot?

Is it right that udev is not started as a separate daemon, but as part of systemd?

Anyway, the firmware handler screws up somehow - notice the 2.5 second delay between the two messages above, and the error message.

no problem with initscripts, but problem every boot/reboot with systemd
may be it conflicts with something

lsmod

Module Size Used by
fuse 68768 2
ip6table_filter 1396 0
ip6_tables 18198 1 ip6table_filter
ipt_MASQUERADE 1738 3
iptable_nat 4024 1
nf_nat 15100 2 ipt_MASQUERADE,iptable_nat
nf_conntrack_ipv4 6871 4 nf_nat,iptable_nat
nf_defrag_ipv4 1339 1 nf_conntrack_ipv4
xt_state 1295 1
aes_x86_64 7508 1
cryptd 8741 0
aes_generic 26138 1 aes_x86_64
nf_conntrack 61584 5 ipt_MASQUERADE,nf_nat,xt_state,iptable_nat,nf_conntrack_ipv4
ipt_REJECT 2281 2
xt_CHECKSUM 1231 1
iptable_mangle 1584 1
xt_tcpudp 2503 5
iptable_filter 1456 1
ip_tables 16946 3 iptable_filter,iptable_mangle,iptable_nat
x_tables 16954 11 ip6table_filter,xt_CHECKSUM,ip_tables,xt_tcpudp,ipt_MASQUERADE,xt_state,iptable_filter,ipt_REJECT,iptable_mangle,ip6_tables,iptable_nat
bridge 78242 0
stp 1608 1 bridge
llc 3825 2 stp,bridge
tun 15297 2
hidp 14922 2
hid 85285 1 hidp
rfcomm 33627 8
bnep 8793 2
zram 9907 4
snd_hda_codec_hdmi 23672 4
nfs 275752 0
nfs_acl 2359 1 nfs
lockd 62788 1 nfs
auth_rpcgss 32327 1 nfs
sunrpc 184821 4 nfs,auth_rpcgss,lockd,nfs_acl
fscache 41059 1 nfs
arc4 1410 2
brcmsmac 528035 0
cordic 1105 1 brcmsmac
crc8 1186 1 brcmsmac
brcmutil 3152 1 brcmsmac
bcma 22725 1 brcmsmac
nvidia 12283355 54
joydev 9991 0
mac80211 395232 1 brcmsmac
cfg80211 169978 2 brcmsmac,mac80211
loop 18160 0
kvm_intel 125165 0
ir_lirc_codec 4027 0
lirc_dev 9071 1 ir_lirc_codec
kvm 361546 1 kvm_intel
snd_hrtimer 1700 0
ir_mce_kbd_decoder 3254 0
ir_sanyo_decoder 1677 0
snd_hda_codec_realtek 60313 1
ir_sony_decoder 1579 0
ir_jvc_decoder 1673 0
uvcvideo 69437 0
btusb 11764 0
bluetooth 190551 29 bnep,hidp,btusb,rfcomm
snd_seq_midi_emul 6113 0
snd_seq 50881 1 snd_seq_midi_emul
snd_seq_device 5300 1 snd_seq
snd_hda_intel 24053 5
snd_hda_codec 94273 3 snd_hda_codec_realtek,snd_hda_codec_hdmi,snd_hda_intel
ir_rc6_decoder 2153 0
videobuf2_vmalloc 2468 1 uvcvideo
cpuid 2276 0
snd_hwdep 6300 1 snd_hda_codec
snd_pcm 74958 3 snd_hda_codec_hdmi,snd_hda_codec,snd_hda_intel
cpufreq_stats 3826 0
cpufreq_userspace 2144 0
ir_rc5_decoder 1609 0
acpi_cpufreq 5933 1
videobuf2_memops 2246 1 videobuf2_vmalloc
ir_nec_decoder 1705 0
videobuf2_core 20415 1 uvcvideo
toshiba_acpi 12820 0
sparse_keymap 3056 1 toshiba_acpi
rc_rc6_mce 1380 0
cpufreq_conservative 5393 0
mperf 1267 1 acpi_cpufreq
serio_raw 4653 0
jmb38x_ms 8417 0
snd_page_alloc 7217 2 snd_pcm,snd_hda_intel
videodev 93086 1 uvcvideo
intel_agp 10904 0
cpufreq_powersave 990 0
snd_timer 18966 3 snd_hrtimer,snd_pcm,snd_seq
sdhci_pci 10833 0
wmi 8475 1 toshiba_acpi
r8169 49354 0
iTCO_wdt 12813 0
media 10213 2 uvcvideo,videodev
sdhci 23854 1 sdhci_pci
mmc_core 82070 2 sdhci,sdhci_pci
snd 58997 19 snd_hda_codec_realtek,snd_hwdep,snd_timer,snd_hda_codec_hdmi,snd_pcm,snd_seq,snd_hda_codec,snd_hda_intel,snd_seq_device
soundcore 5410 1 snd
mii 4123 1 r8169
rfkill 15604 6 cfg80211,toshiba_acpi,bluetooth
coretemp 5654 0
crc32c_intel 1987 0
i2c_i801 8180 0
i2c_core 20369 3 i2c_i801,nvidia,videodev
intel_ips 11219 0
toshiba_bluetooth 2066 0
intel_gtt 14047 1 intel_agp
iTCO_vendor_support 1929 1 iTCO_wdt
mei 32152 0
evdev 9754 24
memstick 7016 1 jmb38x_ms
button 4502 0
psmouse 70792 0
ac 2376 0
battery 6517 0
video 11307 0
processor 26567 1 acpi_cpufreq
ene_ir 11622 0
rc_core 13088 11 ir_lirc_codec,ir_rc5_decoder,ir_nec_decoder,ir_sony_decoder,ene_ir,ir_mce_kbd_decoder,ir_jvc_decoder,ir_rc6_decoder,ir_sanyo_decoder,rc_rc6_mce
microcode 12185 0
ext4 424175 3
crc16 1359 2 ext4,bluetooth
jbd2 73919 1 ext4
mbcache 5977 1 ext4
sr_mod 14823 0
cdrom 35648 1 sr_mod
sd_mod 29239 5
ahci 20549 4
libahci 20023 1 ahci
libata 167515 2 ahci,libahci
scsi_mod 132942 3 libata,sd_mod,sr_mod
ehci_hcd 41154 0
usbcore 147533 4 btusb,uvcvideo,ehci_hcd

and menu.lst

# (0) Arch Linux
title Arch Linux
root (hd0,0)
kernel /vmlinuz-linux root=/dev/disk/by-uuid/450c949d-0afb-4ea6-aa4a-ac0ff0756284 ro resume=/dev/sda2 libata.noacpi=1 nomodeset notsc clocksource=hpet nmi_watchdog=0 numa=off fastboot usbhid.mousepoll=2 init=/bin/systemd
initrd /initramfs-linux.img

udev should work the same in this respect under systemd/initscripts. only thing i can imagine is that this is a timing issue, and that there is some race.

I think you right because I tested now more times and can say it's really depends on moon phase. After a lot of repeated errors it started working flawlessly with systemd. May be it's something in CPU init state or BIOS reset helped I don't know, but it's strange just because reproduced only on CPU0

There was an udev upgrade that said that now modules will autoload better. Since then I removed microcode from /etc/modules-load.d/modules.conf and it loads just fine.

I had the same problem before when it was explicitly loaded with the .conf file.

The same story with acpi_cpufreq and coretemp. They load just fine without me telling it so.

So, according to your comment it is really a race in systemd somewhere between modules list load sources

@Ivan: as far as I know you should be able to remove most of those modules from your modules.conf file. kvm-intel needs to stay there until 3.5 is out (then it can go to), I don't know about brcmsmac, but the rest I think can be removed.

What happens is that udev and systemd-modules-load are both trying to insert the microcode module at the same time. This _should_ work just fine, but I guess there is a race either in the kernel, or in udev when it receives the kernel's two firmware requests.

If there really is a race condition here, it should be sufficient to re-order the module load service. Can you try to attached unit in place of /usr/lib/systemd/system/systmed-modules-load.service (it's only changing the Before= dependencies)

This will at least prove or disprove...

Thank you all for helping me. Now it works without any flawless. I'll test little bit more but it works good in previously failed cases

@Ivan: just to clarify: it now works perfectly with dave's new .service file, but with microcode still in your modules-load.d/modules.conf ?

If so we need to take this upstream to systemd or the kernel to have it sorted out as it is clearly a bug.

I just used Dave's new service file, no change in modules.conf at all - no error now on boot or rebooting.
Removing Dave's patch does not fall my system to bug state again for now, so it may take a time to check
and I plan to test it more in daily usage case with Dave's patches since bug is really important for me especcially with latest Intel microcode updates for SYSRET

@Ivan: thanks for clarifying. It would also be interesting to know if the problem is solved by removing microcode from modules.conf, even without Dave's patch. The module should still be loaded, but this time only once.

week test result
- no problem with Dave's patch
- appeared once without it and restarting service helps again no problem on reboot, so I returned Dave's patch again now and seems working fine for a two days

thanks a lot

Bug appears again with latest update and reproduses frequently, so removed microcode from /etc/modules-load.d for now
Hope this helps

Reproduced today another pc I moved to systemd. Removing from modules helps

So this appears to be a kernel bug caused by trying to insert the microcode modules more than once (at the same time).

Luckily, the microcode module is always autodetected on new kernels, so there is never any need to have it in /etc/modules-load.d.

As to the bug, I'd take that upstream to the microcode developers.