First I want to tell you that yesterday I upgraded the system manually
without any problem, in fact, previously I had installed reportbug to send
the bugreport, you can see all this on apt history following.

> Do you have anything in the logs (e.g. /var/log/unattended-upgrades.log or
> /var/log/apt/history.log) from around this time that might give a clue why
> this happend?

/var/log/apt/history.log:
Start-Date: 2011-10-10  06:54:12
Upgrade: libkrb5-3:amd64 (1.8.3+dfsg-4squeeze1, 1.8.3+dfsg-4squeeze2), 
libk5crypto3:amd64 (1.8.3+dfsg-4squeeze1, 1.8.3+dfsg-4squeeze2), 
openssh-server:amd64 (5.5p1-6, 5.5p1-6+squeeze1), base-files:amd64 
(6.0squeeze2, 6.0squeeze3), linux-image-2.6.32-5-amd64:amd64 
(2.6.32-35squeeze2, 2.6.32-38), update-inetd:amd64 (4.38+nmu1, 
4.38+nmu1+squeeze1), libpcap0.8:amd64 (1.1.1-2, 1.1.1-2+squeeze1), 
aptitude:amd64 (0.6.3-3.2, 0.6.3-3.2+squeeze1), apache2-mpm-prefork:amd64 
(2.2.16-6+squeeze3, 2.2.16-6+squeeze4), grub-pc:amd64 (1.98+20100804-14, 
1.98+20100804-14+squeeze1), apache2-utils:amd64 (2.2.16-6+squeeze3, 
2.2.16-6+squeeze4), apache2:amd64 (2.2.16-6+squeeze3, 2.2.16-6+squeeze4), 
apache2.2-common:amd64 (2.2.16-6+squeeze3, 2.2.16-6+squeeze4), 
libkrb5support0:amd64 (1.8.3+dfsg-4squeeze1, 1.8.3+dfsg-4squeeze2), 
openssh-client:amd64 (5.5p1-6, 5.5p1-6+squeeze1), linux-base:amd64 
(2.6.32-35squeeze2, 2.6.32-38), apache2.2-bin:amd64 (2.2.16-6+squeeze3, 
2.2.16-6+squeeze4), firmware-bnx2:amd64 (0.28, 0.28+squeeze1), ssh:amd64 
(5.5p1-6, 5.5p1-6+squeeze1), tzdata:amd64 (2011d-0squeeze1, 2011k-0squeeze1), 
libssl0.9.8:amd64 (0.9.8o-4squeeze2, 0.9.8o-4squeeze3), openssl:amd64 
(0.9.8o-4squeeze2, 0.9.8o-4squeeze3), grub-common:amd64 (1.98+20100804-14, 
1.98+20100804-14+squeeze1), libgssapi-krb5-2:amd64 (1.8.3+dfsg-4squeeze1, 
1.8.3+dfsg-4squeeze2)
End-Date: 2011-10-10  06:55:38

Start-Date: 2011-10-25  21:01:53
Commandline: apt-get install reportbug
Install: python-reportbug:amd64 (4.12.6, automatic), reportbug:amd64 (4.12.6)
End-Date: 2011-10-25  21:01:57

Start-Date: 2011-10-25  21:13:37
Commandline: apt-get upgrade
Upgrade: libpam0g:amd64 (1.1.1-6.1, 1.1.1-6.1+squeeze1), libfreetype6:amd64 
(2.4.2-2.1+squeeze1, 2.4.2-2.1+squeeze2), libpam-modules:amd64 (1.1.1-6.1, 
1.1.1-6.1+squeeze1), libpam-runtime:amd64 (1.1.1-6.1, 1.1.1-6.1+squeeze1)
End-Date: 2011-10-25  21:13:50

This seems to show that the upgrade happening on the 10th ended the upgrades
correctly.

This is what /var/log/unattended-upgrades/unattended-upgrades.log shows from
previous day, problematic day and next day:

2011-10-09 06:46:14,445 INFO Initial blacklisted packages: 
2011-10-09 06:46:14,445 INFO Starting unattended upgrades script
2011-10-09 06:46:14,445 INFO Allowed origins are: ["('Debian', 'stable')", 
"('Debian', 'squeeze-security')"]
2011-10-09 06:46:15,690 INFO No packages found that can be upgraded unattended
2011-10-10 06:53:53,709 INFO Initial blacklisted packages: 
2011-10-10 06:53:53,709 INFO Starting unattended upgrades script
2011-10-10 06:53:53,709 INFO Allowed origins are: ["('Debian', 'stable')", 
"('Debian', 'squeeze-security')"]
2011-10-10 06:54:11,138 INFO Packages that are upgraded: apache2-mpm-prefork 
apache2-utils apache2.2-bin apache2.2-common aptitude base-files firmware-bnx2 
grub-common grub-pc libgssapi-krb5-2 libk5crypto3 libkrb5-3 libkrb5support0 
libpcap0.8 libssl0.9.8 linux-base linux-image-2.6.32-5-amd64 openssh-client 
openssh-server openssl ssh tzdata update-inetd
2011-10-10 06:54:11,139 INFO Writing dpkg log to 
'/var/log/unattended-upgrades/unattended-upgrades-dpkg_2011-10-10_06:54:11.138913.log'
2011-10-10 06:55:38,157 INFO All upgrades installed
2011-10-11 06:51:55,205 INFO Initial blacklisted packages: 
2011-10-11 06:51:55,205 INFO Starting unattended upgrades script
2011-10-11 06:51:55,206 INFO Allowed origins are: ["('Debian', 'stable')", 
"('Debian', 'squeeze-security')"]
2011-10-11 06:51:56,459 INFO No packages found that can be upgraded unattended

> Does this mean that since the 10th no other cron.daily runs for apt happend?

I thought this was the case, and that's why I set the Severity to Critical
but as you can see on the unattended-upgrades log on this machine
unattended-upgrades was run normally on the next day, so cron.daily was
running.

However I have connected to another machine (i386 based) also experimenting
this problem to see how it was behaving and found that indeed this was the
case, no cron.daily was run since the 9th, no logs rotated or any other
cron.daily jobs run.  On this machine I have already killed the stale
process and cron.daily is now running normaly, so I wont be able to provide
info of the running processes like on the amd64 based.  Here is the
/var/log/unattended-upgrades/unattended-upgrades.log part from the i386
machine that shows this:

2011-10-08 07:58:29,216 INFO No packages found that can be upgraded unattended
2011-10-09 07:36:53,499 INFO Initial blacklisted packages: 
2011-10-09 07:36:53,508 INFO Starting unattended upgrades script
2011-10-09 07:36:53,508 INFO Allowed origins are: ["('Debian', 'stable')", 
"('Debian', 'squeeze-security')"]
2011-10-09 07:38:51,890 INFO Packages that are upgraded: apache2-mpm-prefork 
apache2-utils apache2.2-bin apache2.2-common base-files ca-certificates 
firmware-linux-nonfree grub-common grub-pc libasn1-8-heimdal libgssapi-krb5-2 
libgssapi2-heimdal libheimntlm0-heimdal libhx509-5-heimdal libk5crypto3 
libkrb5-26-heimdal libkrb5-3 libkrb5support0 libpcap0.8 libroken18-heimdal 
libssl0.9.8 libwind0-heimdal linux-base linux-image-2.6.32-5-686 linux-libc-dev 
openssh-client openssh-server openssl tzdata update-inetd
2011-10-09 07:38:51,891 INFO Writing dpkg log to 
'/var/log/unattended-upgrades/unattended-upgrades-dpkg_2011-10-09_07:38:51.890993.log'
2011-10-09 07:41:58,682 INFO All upgrades installed
2011-10-25 19:23:27,015 INFO Initial blacklisted packages: 

I'm wondering now why on one machine cron.daily stopped working and not on
the other machine, is there some config on how run-parts runs that could be
causing this different behaviour?

> It might be interessting to get a "strace -p 29690" to see what the parent
> is doing and if its waiting for a different PID maybe?

I have installed strace and attached it, I only got it to say:

select(6, [3 5], NULL, NULL, NULL <unfinished ...>

These are the fd of 29690:
lr-x------ 1 root root 64 oct 26 09:48 0 -> pipe:[31980929]
lrwx------ 1 root root 64 oct 26 09:48 1 -> /tmp/tmpfUNztPA (deleted)
lrwx------ 1 root root 64 oct 26 09:48 2 -> /tmp/tmpfUNztPA (deleted)
lr-x------ 1 root root 64 oct 26 09:48 3 -> pipe:[31980936]
lr-x------ 1 root root 64 oct 26 09:48 5 -> pipe:[31980937]

pipe:[31980929] is a pipe to 29688 and 29689 which are its parents, that's ok
pipe:[31980936] and pipe:[31980937] seems to be pipes to apache:
root     32003  0.0  0.0 170248 15268 ?        Ss   Oct10   3:09 
/usr/sbin/apache2 -k start

ls -l /proc/32003/fd|grep -v var/log/apache
total 0
lr-x------ 1 root root 64 oct 26 09:49 0 -> /dev/null
l-wx------ 1 root root 64 oct 26 09:49 1 -> /dev/null
lrwx------ 1 root root 64 oct 26 09:49 10 -> socket:[32002079]
lrwx------ 1 root root 64 oct 26 09:49 11 -> socket:[32002083]
lrwx------ 1 root root 64 oct 26 09:49 12 -> socket:[32002087]
lrwx------ 1 root root 64 oct 26 09:49 13 -> socket:[32002091]
lrwx------ 1 root root 64 oct 26 09:49 14 -> socket:[32002119]
lrwx------ 1 root root 64 oct 26 09:49 15 -> socket:[32002123]
lrwx------ 1 root root 64 oct 26 09:49 16 -> socket:[32002127]
lrwx------ 1 root root 64 oct 26 09:49 17 -> socket:[32002131]
lr-x------ 1 root root 64 oct 26 09:49 18 -> pipe:[47339017]
l-wx------ 1 root root 64 oct 26 09:49 19 -> pipe:[47339017]
lrwx------ 1 root root 64 oct 26 09:49 3 -> socket:[32002052]
lrwx------ 1 root root 64 oct 26 09:49 4 -> socket:[32002054]
lr-x------ 1 root root 64 oct 26 09:49 40 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 42 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 44 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 46 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 48 -> /var/lib/dpkg/status (deleted)
lrwx------ 1 root root 64 oct 26 09:49 5 -> socket:[32002057]
lr-x------ 1 root root 64 oct 26 09:49 50 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 52 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 54 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 56 -> /var/lib/dpkg/status (deleted)
lr-x------ 1 root root 64 oct 26 09:49 58 -> /var/lib/dpkg/status (deleted)
lrwx------ 1 root root 64 oct 26 09:49 6 -> socket:[32002061]
lr-x------ 1 root root 64 oct 26 09:49 60 -> /var/lib/dpkg/status (deleted)
lrwx------ 1 root root 64 oct 26 09:49 61 -> /dev/null
lrwx------ 1 root root 64 oct 26 09:49 62 -> 
/var/log/unattended-upgrades/unattended-upgrades-dpkg_2011-10-10_06:54:11.138913.log
l-wx------ 1 root root 64 oct 26 09:49 63 -> pipe:[31980936]
l-wx------ 1 root root 64 oct 26 09:49 64 -> pipe:[31980937]
l-wx------ 1 root root 64 oct 26 09:49 66 -> /var/log/apt/history.log
l-wx------ 1 root root 64 oct 26 09:49 69 -> /var/run/apache2/ssl_mutex 
(deleted)
lrwx------ 1 root root 64 oct 26 09:49 7 -> socket:[32002067]
lr-x------ 1 root root 64 oct 26 09:49 70 -> /dev/urandom
lrwx------ 1 root root 64 oct 26 09:49 8 -> socket:[32002071]
lrwx------ 1 root root 64 oct 26 09:49 9 -> socket:[32002075]

Wow, it has still around all dpkg and apt stuff from parent, is that ok?

So, it appears that it is waiting for apache, I'm quite sure that if I stop
apache and then start it again process will continue, if you don't need more
info on the machine I can try that.

So... any other info I can provide?

Regards...
-- 
Santiago García Mantiñán



--
To UNSUBSCRIBE, email to debian-bugs-rc-requ...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org

Reply via email to