Re: init scripts problems ?
denis bonnenfant <[email protected]>
| Newsgroups | gmane.linux.enbd.general |
|---|---|
| Message-ID | <[email protected]> |
> I've just checked the enbd_open() code and I see nothing suspicious
> there _except_ maybe the "media check" that is launched in the kernel:
>
> if (do_media_check) {
> // PTB this invalidates buffers, if necessary
> ENBD_INFO ("DISK CHECK wanted in open on device nd%s\n",
> lo->devnam);
> lo->last_checked = jiffies;
> check_disk_change(inode->i_bdev);
> }
>
>
> It may be worth disabling that whole check and seeing what happens. As
> I recall the kernel tries to read the partition table (the first
> sectors) of the "disk" (enbd) and then adds the result to
> /proc/partitions.
this may be a problem, as enbd device may not be partitionned !
>
> This is a bit of a race condition in itself, since on first opening by
> the client, the enbd device hasn't got a client there and hence can't
> ask the server for a sector. I think the race is solved by some fancy
> code just above which checks if we are opening it in order to become
> the client, or we are opening the device because we already are the
> client, something that the kernel code can only tell by checking if we
> have the pid of the client that opened the device first.
>
> That code might be wrong. It's certainly the case that with two openers
> close in time we might get throough this test both times:
>
> if ((part == 0 || (slot->pid && slot->pid != current->pid))
> && lo->last_checked + timeout < jiffies) {
> /*
> * PTB induce a remote check and maybe invalidate
> * device.
> * This currently requires enbd_ioctl for remote
> * ioctl support.
> */
> do_media_check = 1;
> }
>
> I can't help wondering if that != might have been supposed to be an
> ==. IT SAYS the code only is activated if we are the first checker
> (last checked = 0, surely less than jiffies), or it's been a long while
> since the media was checked. But the check condition is that either
> we're opening the full device (and thus we're a master client daemon) or
> we're opening a minor device (and hence we're a slave client daemon) but
> not the slave client daemon that is assigned to that minor (which has
> already registered).
>
> Weird. Would it make more sense with an ==?
>
> I suspect that that check_disk_change(inode->i_bdev) is mandated by the
> kernel for some reason, or no requests will ever be let through. But
> the times when it is done or should be done are bscure.
>
> There is definitely some kind of race POSSIBLE. The media check sets te
> last_checked time.
>
> One might investigate the result of turning that code to either ALWAYS
> do (on open), or always not do. I.e. setting do_media_check to 1 or 0
> withut thinking.
>
> But I'm not even sure the code sticks in OPEN, rather than at the first
> read. The WCHAN value might indicate.
>
>
>
just for information, from syslog of the production server : not very useful, i'm afraid to
but that's the only thing that i can do before setting up my test machine !
first a successful negotiation and reconstruction :
ENBD #2535[2]: enbd_enable set VALID on nda
ENBD #2605[0]: enbd_clr_sock enabled device nda
ENBD #4234[0]: enbd_release (0): erasing slot pid 2457
ENBD #2194[7]: enbd_clr_queue unqueued 0 reqs
ENBD #3224[5]: enbd_soft_reset INVALIDATE DEVICE nda
ENBD #3234[5]: enbd_soft_reset run enbd_request on nda
ENBD #4234[1]: enbd_release (1): erasing slot pid 2458
md: error, md_import_device() returned -22
ENBD #81[0]: enbd_notify_md_device ioctl 2344 to raid devices returned -22
ENBD #2894[0]: enbd_set_remote_invalid INVALIDATE drive on nda
ENBD #3767[1]: fixup_slot failed to find slot for pid 4953 ioctl
4004ab10 arg bfeeb0d8 (322d41)
ENBD #2535[3]: enbd_enable set VALID on nda
ENBD #824[4]: enbd_open DISK CHECK wanted in open on device nda
ENBD #4404[4]: enbd_media_changed MEDIA CHANGED called
ENBD #4454[0]: enbd_media_changed REMOTE CHECK set REMOTE VALID on nda
ENBD #4508[2]: enbd_revalidate REVALIDATE called on nda
ENBD #4540[1]: enbd_revalidate set VALID on nda
ENBD #4508[3]: enbd_revalidate REVALIDATE called on nda
nda: unknown partition table
ENBD #824[5]: enbd_open DISK CHECK wanted in open on device nda
ENBD #4404[5]: enbd_media_changed MEDIA CHANGED called
ENBD #4460[3]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
ENBD #824[6]: enbd_open DISK CHECK wanted in open on device nda
ENBD #4404[6]: enbd_media_changed MEDIA CHANGED called
ENBD #4460[4]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
md 1233: lock_rdev restores bdev 2b00000 rdev(c26dfe80)->bdev(f3c0c700)
nda (read) [events: 003ad769]
md: old uuid 97bd4b7d ff209919 2b98e343 be27526f
md: new uuid 97bd4b7d ff209919 2b98e343 be27526f
md0: repairing old mirror component 2b00000 (disk 3856233 >= bitmap 3822471)
md: bind<nda>
md0: notifying dev 2b00000 it is now in array
ENBD #4143[1]: enbd_ioctl received BLKMDNTFY, am now in raid 900000
md0: set repair bit to 1 on superblock f5646200
md0: md_check_recovery 2: repair bit 100 on sb f5646200 preserved
RAID1 conf printout:
--- wd:1 rd:2
disk 0, wo:1, o:1, dev:nda
disk 1, wo:0, o:1, dev:sda
..<6>md: syncing RAID array md0)
md: minimum _guaranteed_ reconstruction speed: 1000000 KB/sec/disc.
md: using maximum available idle IO bandwith (but not more than 200000
KB/sec) for reconstruction.
md: using 128k window, over a total of 156217280 blocks.
md0: repair bit set on sb so retained bitmap f5473480
raid1: synced dirty sectors 0-312434559
raid1: synced dirty sectors 0-312434687
md: md0: sync done.
bitmap: 1812 pages in use
bitmap: 1812 pages allocated
bitmap: 0 pages pre-allocated
RAID1 conf printout:
--- wd:2 rd:2
disk 0, wo:0, o:1, dev:nda
disk 1, wo:0, o:1, dev:sda
md0: md_check_recovery 1: repair bit 0 on sb f5646200 preserved
md0: md_check_recovery 2: repair bit 0 on sb f5646200 preserved
then the problematic one, with nda and ndb connected simutlaneously
(and unusable):
Nov 28 08:49:26 ldap kernel: ENBD #5159[0]: enbd_init Network Block Device originally by [email protected]
Nov 28 08:49:26 ldap kernel: ENBD #5160[0]: enbd_init Network Block Device port to 2.0 by [email protected]
Nov 28 08:49:26 ldap kernel: ENBD #5162[0]: enbd_init Network Block Device move networking to user space by [email protected]
Nov 28 08:49:26 ldap kernel: ENBD #5164[0]: enbd_init Enhanced Network Block Device 2.4.30 $Date: 2002/09/17 16:33:22 $ by [email protected]
Nov 28 08:49:26 ldap kernel: ENBD #5204[0]: enbd_init registered device at major 43
Nov 28 10:12:33 ldap enbd-cstatd: enbd-cstatd: no client known for A-2 - restarting
Nov 28 10:12:33 ldap enbd-cstatd: enbd-cstatd: no client known for B-2 - restarting
Nov 28 10:12:34 ldap enbd-cstatd: enbd-cstatd: client A-2 check or restart failed
Nov 28 10:12:34 ldap enbd-cstatd: nbd/pidfile 6315: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:12:34 ldap enbd-cstatd: enbd-cstatd: client B-2 check or restart failed
Nov 28 10:12:34 ldap enbd-cstatd: nbd/pidfile 6348: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:12:39 ldap enbd-client: enbd-client: client says target 0 is se3-croise:12355
Nov 28 10:12:39 ldap enbd-client: enbd-client: client identifier is A-2
Nov 28 10:12:39 ldap enbd-client: enbd-client: client channels is 4
Nov 28 10:12:39 ldap enbd-client: enbd-client: client cksum flag is 1
Nov 28 10:12:39 ldap enbd-client: enbd-client: client says blksize is 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) opened device /dev/nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager opened NBD device /dev/nda (2b00)
Nov 28 10:12:39 ldap kernel: warning: process `enbd-client' used the obsolete bdflush system call
Nov 28 10:12:39 ldap kernel: warning: process `enbd-client' used the obsolete bdflush system call
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set kernel bdflush sync boundary to 80% from -1210166288%
Nov 28 10:12:39 ldap kernel: warning: process `enbd-client' used the obsolete bdflush system call
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) left kernel bdflush async boundary at -1081920908%
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager detaches from shell
Nov 28 10:12:39 ldap enbd-client: nbd/pidfile 6387: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager made pidfile /var/run/enbd-client-A-2.pid with pid 6387
Nov 28 10:12:39 ldap enbd-client: nbd/time 6387: <# 64> mygettimeofday time was 0+0E-6 s and is 1133169159+319974E-6 s
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) starts introduction sequence on se3-croise:12355
Nov 28 10:12:39 ldap enbd-client: enbd-client: client says target 0 is se3-croise:12360
Nov 28 10:12:39 ldap enbd-client: enbd-client: client identifier is B-2
Nov 28 10:12:39 ldap enbd-client: enbd-client: client channels is 4
Nov 28 10:12:39 ldap enbd-client: enbd-client: client cksum flag is 1
Nov 28 10:12:39 ldap enbd-client: enbd-client: client says blksize is 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) opened device /dev/ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager opened NBD device /dev/ndb (2b10)
Nov 28 10:12:39 ldap kernel: warning: process `enbd-client' used the obsolete bdflush system call
Nov 28 10:12:39 ldap kernel: warning: process `enbd-client' used the obsolete bdflush system call
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set kernel bdflush sync boundary to 80% from -1210354704%
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) left kernel bdflush async boundary at -1081057100%
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager detaches from shell
Nov 28 10:12:39 ldap enbd-client: nbd/pidfile 6388: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager made pidfile /var/run/enbd-client-B-2.pid with pid 6388
Nov 28 10:12:39 ldap enbd-client: nbd/time 6388: <# 64> mygettimeofday time was 0+0E-6 s and is 1133169159+333945E-6 s
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) starts introduction sequence on se3-croise:12360
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got size 159966560256
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got size 500082671616
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got signature [A-2], had []
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) negotiated blksize 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) negotiated pulse_intvl 10
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got session port 12356 ok
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) introduction sequence ends ok
Nov 28 10:12:39 ldap kernel: ENBD #3767[0]: fixup_slot failed to find slot for pid 6387 ioctl 4004ab10 arg bf831888 (322d41)
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set device size 159966560256
Nov 28 10:12:39 ldap enbd-client: enbd-client 6387: <#1693> setdeviceblksize client (-1) Warning! kernel says blksz is 4096 != 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set md5sum flags on device
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) sets session slots to 0-3
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got signature [B-2], had []
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) negotiated blksize 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) negotiated pulse_intvl 10
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) got session port 12361 ok
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) introduction sequence ends ok
Nov 28 10:12:39 ldap kernel: ENBD #3767[1]: fixup_slot failed to find slot for pid 6388 ioctl 4004ab10 arg bf9046c8 (322d42)
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set device size 500082671616
Nov 28 10:12:39 ldap enbd-client: enbd-client 6388: <#1693> setdeviceblksize client (-1) Warning! kernel says blksz is 4096 != 512
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) set md5sum flags on device
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) sets session slots to 0-3
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 0 (6393) for se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (6394) for se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 2 (6395) for se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 3 (6396) for se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 0 (6397) for se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (6398) for se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 2 (6399) for se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) opened device /dev/nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) opened device /dev/nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (-1) manager launched daemon 3 (6400) for se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) opened socket 6 to se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) opened socket 6 to se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) opened device /dev/ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) opened device /dev/ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) read passwd ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) got cliserv magic ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) read passwd ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) got cliserv magic ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) opened device /dev/ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) opened socket 6 to se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) opened socket 6 to se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) got a signature ok from se3-croise:12356
Nov 28 10:12:39 ldap kernel: ENBD #2740[0]: enbd_set_sock increased socket count to 2
Nov 28 10:12:39 ldap kernel: ENBD #2535[0]: enbd_enable set VALID on nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) begins main loop
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) got a signature ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) read passwd ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) got cliserv magic ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) opened socket 6 to se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) read passwd ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) got cliserv magic ok from se3-croise:12361
Nov 28 10:12:39 ldap kernel: ENBD #2740[1]: enbd_set_sock increased socket count to 3
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) begins main loop
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) read passwd ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) got cliserv magic ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) got a signature ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) got a signature ok from se3-croise:12361
Nov 28 10:12:39 ldap kernel: ENBD #2740[2]: enbd_set_sock increased socket count to 1
Nov 28 10:12:39 ldap kernel: ENBD #2535[1]: enbd_enable set VALID on ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) begins main loop
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) got a signature ok from se3-croise:12361
Nov 28 10:12:39 ldap kernel: ENBD #2740[3]: enbd_set_sock increased socket count to 2
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (1) begins main loop
Nov 28 10:12:39 ldap kernel: ENBD #2740[4]: enbd_set_sock increased socket count to 3
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (2) begins main loop
Nov 28 10:12:39 ldap kernel: ENBD #824[0]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:39 ldap kernel: ENBD #4404[0]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap kernel: ENBD #4460[0]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:39 ldap kernel: ENBD #824[1]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:39 ldap kernel: ENBD #4404[1]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap kernel: ENBD #4460[1]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) opened device /dev/nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) opened socket 6 to se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) read passwd ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) got cliserv magic ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) got a signature ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (0) begins main loop
Nov 28 10:12:39 ldap kernel: ENBD #824[2]: enbd_open DISK CHECK wanted in open on device ndb
Nov 28 10:12:39 ldap kernel: ENBD #4404[2]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap kernel: ENBD #824[3]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:39 ldap kernel: ENBD #4404[3]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap kernel: ENBD #4460[2]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on ndb
Nov 28 10:12:39 ldap kernel: ENBD #824[4]: enbd_open DISK CHECK wanted in open on device ndb
Nov 28 10:12:39 ldap kernel: ENBD #4404[4]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap kernel: ENBD #4460[3]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:39 ldap kernel: ENBD #4460[4]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on ndb
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) opened device /dev/ndb
Nov 28 10:12:39 ldap kernel: ENBD #824[5]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:39 ldap kernel: ENBD #4404[5]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) opened socket 6 to se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) read passwd ok from se3-croise:12361
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) got cliserv magic ok from se3-croise:12361
Nov 28 10:12:39 ldap kernel: ENBD #4460[5]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:39 ldap kernel: ENBD #824[6]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:39 ldap kernel: ENBD #4404[6]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) got a signature ok from se3-croise:12361
Nov 28 10:12:39 ldap kernel: ENBD #2740[5]: enbd_set_sock increased socket count to 4
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) begins main loop
Nov 28 10:12:39 ldap kernel: ENBD #4460[6]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) opened device /dev/nda
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) opened socket 6 to se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) read passwd ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) got cliserv magic ok from se3-croise:12356
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) got a signature ok from se3-croise:12356
Nov 28 10:12:39 ldap kernel: ENBD #2740[6]: enbd_set_sock increased socket count to 4
Nov 28 10:12:39 ldap enbd-client: enbd-client: client (3) begins main loop
Nov 28 10:12:44 ldap kernel: ENBD #824[7]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:12:44 ldap kernel: ENBD #4404[7]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:44 ldap enbd-client: enbd-client: client (-1) opened device /dev/nda
Nov 28 10:12:44 ldap kernel: ENBD #4460[7]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on nda
Nov 28 10:12:44 ldap kernel: ENBD #824[8]: enbd_open DISK CHECK wanted in open on device ndb
Nov 28 10:12:44 ldap kernel: ENBD #4404[8]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:12:44 ldap enbd-client: enbd-client: client (-1) opened device /dev/ndb
Nov 28 10:12:44 ldap kernel: ENBD #4460[8]: enbd_media_changed REMOTE CHECK still has REMOTE VALID on ndb
Nov 28 10:13:04 ldap enbd-cstatd: enbd-cstatd: sending SIGPWR to live client A-2 (process 6387)
Nov 28 10:13:04 ldap enbd-client: enbd-client 6387: <# 298> managersighandler received signal 30
Nov 28 10:13:04 ldap enbd-cstatd: enbd-cstatd: sending SIGPWR to live client B-2 (process 6388)
Nov 28 10:13:04 ldap enbd-client: enbd-client 6388: <# 298> managersighandler received signal 30
Nov 28 10:13:05 ldap enbd-client: enbd-client: sighandler asks manager to break off all and restart
Nov 28 10:13:05 ldap enbd-client: enbd-client: sighandler asks manager to break off all and restart
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) restarts and closes net
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) restarts and closes net
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) closes all descriptors except dev 5
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) waits for dead children 1
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) closes all descriptors except dev 5
Nov 28 10:13:06 ldap enbd-client: enbd-client: client (-1) waits for dead children 1
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) waits for dead children 2
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) waits for dead children 2
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) waits for dead children 3
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) ctlp reset to 12360
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) port reset to 12360
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) pid reset to 6388
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) restarts
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) reuses old ioctl buffer
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) set kernel bdflush sync boundary to 80% from -1081057100%
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) left kernel bdflush async boundary at -1081057100%
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) manager detaches from shell
Nov 28 10:13:07 ldap enbd-client: nbd/pidfile 6465: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) manager made pidfile /var/run/enbd-client-B-2.pid with pid 6465
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) last error Bad file descriptor
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) waits for dead children 3
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) ctlp reset to 12355
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) port reset to 12355
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) pid reset to 6387
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) restarts
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) reuses old ioctl buffer
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) set kernel bdflush sync boundary to 80% from -1081920908%
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) left kernel bdflush async boundary at -1081920908%
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) manager detaches from shell
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) last error Bad file descriptor
Nov 28 10:13:07 ldap enbd-client: nbd/pidfile 6466: <# 144> lockpidfile returning err 0 for lock attempt
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) manager made pidfile /var/run/enbd-client-A-2.pid with pid 6466
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) starts introduction sequence on se3-croise:12355
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) got size 159966560256
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) got signature [A-2], had [A-2]
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) negotiated blksize 512
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) negotiated pulse_intvl 10
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) got session port 12357 ok
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) introduction sequence ends ok
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) set device size 159966560256
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) set md5sum flags on device
Nov 28 10:13:07 ldap enbd-client: enbd-client: client (-1) sets session slots to 0-3
Nov 28 10:13:08 ldap kernel: ENBD #3767[2]: fixup_slot failed to find slot for pid 6466 ioctl 4004ab10 arg bf831888 (322d41)
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 0 (6467) for se3-croise:12357
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (6468) for se3-croise:12357
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 2 (6469) for se3-croise:12357
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 3 (6470) for se3-croise:12357
Nov 28 10:13:08 ldap kernel: ENBD #824[9]: enbd_open DISK CHECK wanted in open on device nda
Nov 28 10:13:08 ldap kernel: ENBD #4404[9]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) starts introduction sequence on se3-croise:12360
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) got size 500082671616
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) got signature [B-2], had [B-2]
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) negotiated blksize 512
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) negotiated pulse_intvl 10
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) got session port 12362 ok
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) introduction sequence ends ok
Nov 28 10:13:08 ldap kernel: ENBD #3767[3]: fixup_slot failed to find slot for pid 6465 ioctl 4004ab10 arg bf9046c8 (322d42)
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) set device size 500082671616
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) set md5sum flags on device
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) sets session slots to 0-3
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 0 (6471) for se3-croise:12362
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (6472) for se3-croise:12362
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 2 (6473) for se3-croise:12362
Nov 28 10:13:08 ldap enbd-client: enbd-client: client (-1) manager launched daemon 3 (6474) for se3-croise:12362
Nov 28 10:13:08 ldap kernel: ENBD #824[10]: enbd_open DISK CHECK wanted in open on device ndb
Nov 28 10:13:08 ldap kernel: ENBD #4404[10]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:13:18 ldap kernel: ENBD #3518[1]: enbd_wait_on_ioctl_timeout remote ioctl timed out (-1 remaining)
Nov 28 10:13:18 ldap kernel: ENBD #3602[1]: do_enbd_remote_ioctl timed out remote ioctl d9759ec4 lost
Nov 28 10:13:18 ldap kernel: ENBD #1040[0]: enbd_error error out req d9759ec4 from slot 3!
Nov 28 10:13:18 ldap kernel: ENBD #1046[0]: enbd_error erroring and putting ioctl req d9759ec4
Nov 28 10:13:18 ldap kernel: ENBD #3518[2]: enbd_wait_on_ioctl_timeout remote ioctl timed out (-1 remaining)
Nov 28 10:13:18 ldap kernel: ENBD #3602[2]: do_enbd_remote_ioctl timed out remote ioctl d9759b4c lost
Nov 28 10:13:18 ldap kernel: ENBD #1040[1]: enbd_error error out req d9759b4c from slot 3!
Nov 28 10:13:18 ldap kernel: ENBD #1046[1]: enbd_error erroring and putting ioctl req d9759b4c
Nov 28 10:13:28 ldap kernel: ENBD #3518[3]: enbd_wait_on_ioctl_timeout remote ioctl timed out (-1 remaining)
Nov 28 10:13:28 ldap kernel: ENBD #3607[0]: do_enbd_remote_ioctl remote ioctl f699c050 found on dev queue
Nov 28 10:13:28 ldap kernel: ENBD #3627[0]: do_enbd_remote_ioctl timed out remote ioctl f699c050 cleaned up
Nov 28 10:13:28 ldap kernel: ENBD #4429[0]: enbd_media_changed REMOTE CHECK remote is down!
Nov 28 10:13:28 ldap kernel: ENBD #4508[0]: enbd_revalidate REVALIDATE called on nda
Nov 28 10:13:28 ldap kernel: ENBD #4540[0]: enbd_revalidate set VALID on nda
Nov 28 10:13:28 ldap kernel: ENBD #4508[1]: enbd_revalidate REVALIDATE called on nda
Nov 28 10:13:28 ldap kernel: ENBD #3607[1]: do_enbd_remote_ioctl remote ioctl cdcd3334 found on dev queue
Nov 28 10:13:28 ldap kernel: ENBD #3627[1]: do_enbd_remote_ioctl timed out remote ioctl cdcd3334 cleaned up
Nov 28 10:13:28 ldap kernel: ENBD #4429[1]: enbd_media_changed REMOTE CHECK remote is down!
Nov 28 10:13:28 ldap kernel: ENBD #4508[2]: enbd_revalidate REVALIDATE called on ndb
Nov 28 10:13:28 ldap kernel: ENBD #4540[1]: enbd_revalidate set VALID on ndb
Nov 28 10:13:28 ldap kernel: ENBD #4508[3]: enbd_revalidate REVALIDATE called on ndb
At this point, all the nbd devices were stuck, i tried to kill them with differents signals :
Nov 28 10:42:24 ldap enbd-client: enbd-client 6466: <# 298> managersighandler received signal 10
Nov 28 10:42:24 ldap enbd-client: enbd-client: sighandler delivers soft reset from manager
Nov 28 10:42:24 ldap kernel: ENBD #3134[0]: enbd_disable disabled device nda
Nov 28 10:42:24 ldap kernel: ENBD #3141[0]: enbd_disable INVALIDATEd device nda
Nov 28 10:42:24 ldap kernel: ENBD #2194[0]: enbd_clr_queue unqueued 8 reqs
Nov 28 10:42:24 ldap enbd-client: enbd-client 6466: <# 298> managersighandler received signal 17
Nov 28 10:42:24 ldap kernel: ENBD #2194[1]: enbd_clr_queue unqueued 0 reqs
Nov 28 10:42:24 ldap enbd-client: enbd-client: sighandler relaunches child from manager
Nov 28 10:42:24 ldap kernel: ENBD #3224[0]: enbd_soft_reset INVALIDATE DEVICE nda
Nov 28 10:42:24 ldap enbd-client: enbd-client: sighandler relaunches child from manager
Nov 28 10:42:24 ldap kernel: ENBD #3234[0]: enbd_soft_reset run enbd_request on nda
Nov 28 10:42:24 ldap kernel: ENBD #2412[1]: do_enbd_request device not enabled.
Nov 28 10:42:24 ldap kernel: ENBD #2535[2]: enbd_enable set VALID on nda
Nov 28 10:42:24 ldap kernel: ENBD #2605[0]: enbd_clr_sock enabled device nda
Nov 28 10:42:24 ldap kernel: ENBD #4234[0]: enbd_release (3): erasing slot pid 6396
Nov 28 10:42:24 ldap kernel: ENBD #4234[1]: enbd_release (2): erasing slot pid 6395
Nov 28 10:42:24 ldap kernel: ENBD #4234[2]: enbd_release (0): erasing slot pid 6393
Nov 28 10:42:24 ldap kernel: ENBD #4234[3]: enbd_release (1): erasing slot pid 6394
Nov 28 10:42:24 ldap enbd-client: enbd-client 6465: <# 298> managersighandler received signal 10
Nov 28 10:42:24 ldap enbd-client: enbd-client: sighandler delivers soft reset from manager
Nov 28 10:42:24 ldap kernel: ENBD #3134[1]: enbd_disable disabled device ndb
Nov 28 10:42:24 ldap kernel: ENBD #3141[1]: enbd_disable INVALIDATEd device ndb
Nov 28 10:42:24 ldap kernel: ENBD #2194[2]: enbd_clr_queue unqueued 8 reqs
Nov 28 10:42:24 ldap kernel: ENBD #2194[3]: enbd_clr_queue unqueued 0 reqs
Nov 28 10:42:24 ldap kernel: ENBD #3224[1]: enbd_soft_reset INVALIDATE DEVICE ndb
Nov 28 10:42:24 ldap kernel: ENBD #3234[1]: enbd_soft_reset run enbd_request on ndb
Nov 28 10:42:24 ldap kernel: ENBD #2412[2]: do_enbd_request device not enabled.
Nov 28 10:42:24 ldap kernel: ENBD #2535[3]: enbd_enable set VALID on ndb
Nov 28 10:42:24 ldap kernel: ENBD #2605[1]: enbd_clr_sock enabled device ndb
Nov 28 10:42:24 ldap kernel: ENBD #4234[4]: enbd_release (3): erasing slot pid 6400
Nov 28 10:42:24 ldap enbd-client: enbd-client 6465: <# 298> managersighandler received signal 17
Nov 28 10:42:24 ldap enbd-client: enbd-client: sighandler relaunches child from manager
Nov 28 10:42:24 ldap kernel: ENBD #824[11]: enbd_open DISK CHECK wanted in open on device ndb
Nov 28 10:42:24 ldap kernel: ENBD #4404[11]: enbd_media_changed MEDIA CHANGED called
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) reaped dead child 6472 (died of signal 10 with exit status 0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (8690) for se3-croise:12362
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) childminder launched pid 8690 (1)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) reaped dead child 6467 (died of signal 10 with exit status 0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) reaped dead child 6468 (died of signal 10 with exit status 0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) reaped dead child 6469 (died of signal 10 with exit status 0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) reaped dead child 6470 (died of signal 10 with exit status 0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) manager launched daemon 0 (8691) for se3-croise:12357
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) childminder launched pid 8691 (0)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) manager launched daemon 1 (8692) for se3-croise:12357
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) childminder launched pid 8692 (1)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) manager launched daemon 2 (8693) for se3-croise:12357
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) childminder launched pid 8693 (2)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) manager launched daemon 3 (8694) for se3-croise:12357
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (-1) childminder launched pid 8694 (3)
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (0) opened device /dev/nda
Nov 28 10:42:24 ldap enbd-client: enbd-client: client (2) opened device /dev/nda
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (1) opened device /dev/nda
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (0) opened socket 5 to se3-croise:12357
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (2) opened socket 5 to se3-croise:12357
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (3) opened device /dev/nda
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (1) opened socket 5 to se3-croise:12357
Nov 28 10:42:25 ldap enbd-client: enbd-client: client (3) opened socket 5 to se3-croise:12357
Nov 28 10:42:27 ldap enbd-client: enbd-client: sighandler terminates manager safely
Nov 28 10:42:27 ldap enbd-client: enbd-client: client (-1) last error No such process
Nov 28 10:42:27 ldap enbd-client: enbd-client: client (-1) last error No such process
Nov 28 10:42:28 ldap enbd-client: enbd-client: sighandler terminates manager safely
Nov 28 10:42:28 ldap enbd-client: enbd-client: client (-1) last error No such process
Nov 28 10:42:28 ldap enbd-client: enbd-client: client (-1) last error No such process
Nov 28 10:42:35 ldap kernel: ENBD #3607[2]: do_enbd_remote_ioctl remote ioctl cc0be8fc found on dev queue
Nov 28 10:42:35 ldap kernel: ENBD #3627[2]: do_enbd_remote_ioctl timed out remote ioctl cc0be8fc cleaned up
Nov 28 10:42:47 ldap kernel: ENBD #3607[3]: do_enbd_remote_ioctl remote ioctl cc0be8fc found on dev queue
Nov 28 10:42:47 ldap kernel: ENBD #3627[3]: do_enbd_remote_ioctl timed out remote ioctl cc0be8fc cleaned up
Nov 28 10:42:47 ldap kernel: ENBD #4429[2]: enbd_media_changed REMOTE CHECK remote is down!
Nov 28 10:42:47 ldap kernel: ENBD #4508[4]: enbd_revalidate REVALIDATE called on ndb
Nov 28 10:42:47 ldap kernel: ENBD #4540[2]: enbd_revalidate set VALID on ndb
Nov 28 10:42:47 ldap kernel: ENBD #4508[5]: enbd_revalidate REVALIDATE called on ndb
and the only way to stop that was with echo 0>/proc/nbdinfo :
Nov 28 10:57:44 ldap kernel: ndb:<1>ENBD #3134[2]: enbd_disable disabled device nda
Nov 28 10:57:44 ldap kernel: ENBD #2194[4]: enbd_clr_queue unqueued 1 reqs
Nov 28 10:57:44 ldap kernel: ENBD #2194[5]: enbd_clr_queue unqueued 0 reqs
Nov 28 10:57:44 ldap kernel: ENBD #3224[2]: enbd_soft_reset INVALIDATE DEVICE nda
Nov 28 10:57:44 ldap kernel: ENBD #3234[2]: enbd_soft_reset run enbd_request on nda
Nov 28 10:57:44 ldap kernel: ENBD #3134[3]: enbd_disable disabled device ndb
Nov 28 10:57:44 ldap kernel: ENBD #3141[2]: enbd_disable INVALIDATEd device ndb
Nov 28 10:57:44 ldap kernel: ENBD #2194[6]: enbd_clr_queue unqueued 8 reqs
Nov 28 10:57:44 ldap kernel: ENBD #2194[7]: enbd_clr_queue unqueued 0 reqs
Nov 28 10:57:44 ldap kernel: ENBD #3224[3]: enbd_soft_reset INVALIDATE DEVICE ndb
Nov 28 10:57:44 ldap kernel: ENBD #3234[3]: enbd_soft_reset run enbd_request on ndb
Nov 28 10:57:44 ldap kernel: ENBD #2412[3]: do_enbd_request device not enabled.
Nov 28 10:57:44 ldap kernel: ENBD #2535[4]: enbd_enable set VALID on ndb
Nov 28 10:57:44 ldap kernel: ENBD #2605[2]: enbd_clr_sock enabled device ndb
Nov 28 10:57:44 ldap kernel: ENBD #4234[5]: enbd_release (1): erasing slot pid 6398
Nov 28 10:57:44 ldap kernel: ENBD #4234[6]: enbd_release (2): erasing slot pid 6399
Nov 28 10:57:44 ldap kernel: ENBD #4234[7]: enbd_release (0): erasing slot pid 6397
it works, "liberating" the devices (with a kernel oops) and allowing shutdown.