Discussion:
SCP/SFTP: Couldn't open /dev/null
Tasmanian Devil
2007-03-27 18:23:17 UTC
Permalink
Hello, list! :-)

After reading this list for several monthes with dedication and after
learning a lot from all of you, I've a strange problem myself now:

I'm following -current on an Apple Mac mini (GENERIC.MP with ACPI
enabled, dmesg below) and I transfer files with SCP and SFTP to this
server. After a few successful transfers, /dev/null obviously breaks
somehow on the server ("Couldn't open /dev/null" error on the client
side):

/dev root# ls -l null
-rw------- 1 root wheel 56 Mar 27 18:13 null

After a "./MAKEDEV std" everything works fine again, at least for the
next few file transfers:

/dev root# ls -l null
crw-rw-rw- 1 root wheel 2, 2 Mar 27 19:50 null

At first I thought the upgrade to OpenSSH 4.6 with a snapshot from
about two weeks ago would have fixed this problem, but it just
happened again. I've searched on the web and in the mailing list
archive, but couldn't find anything related to this problem so far. I
have never seen this problem on any of my other OpenBSD machines.

Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!

Tas.


OpenBSD 4.1 (GENERIC.MP) #1225: Sat Mar 10 19:23:18 MST 2007
***@i386.openbsd.org:/usr/src/sys/arch/i386/compile/GENERIC.MP
cpu0: Genuine Intel(R) CPU 1400 @ 1.83GHz ("GenuineIntel" 686-class) 1.84 GHz
cpu0: FPU,V86,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,SBF,SSE3,MWAIT,VMX,EST,TM2,xTPR
real mem = 2114367488 (2064812K)
avail mem = 1922359296 (1877304K)
using 4278 buffers containing 105840640 bytes (103360K) of memory
mainbus0 (root)
bios0 at mainbus0: AT/286+ BIOS, date 07/29/05, SMBIOS rev. 2.4 @
0xe73f0 (39 entries)
bios0: Apple Computer, Inc. Macmini1,1
pcibios at bios0 function 0x1a not configured
bios0: ROM list: 0xc0000/0xe600!
acpi0 at mainbus0: rev 0
acpi0: tables DSDT FACP HPET APIC MCFG ASF! SBST ECDT SSDT SSDT SSDT
acpitimer at acpi0 not configured
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: apic clock running at 166 MHz
cpu1 at mainbus0: apid 1 (application processor)
cpu1: Genuine Intel(R) CPU 1400 @ 1.83GHz ("GenuineIntel" 686-class) 1.84 GHz
cpu1: FPU,V86,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,SBF,SSE3,MWAIT,VMX,EST,TM2,xTPR
ioapic0 at mainbus0: apid 1 pa 0xfec00000, version 20, 24 pins
ioapic0: duplicate apic id, remapped to apid 2
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus 1 (RP01)
acpiprt2 at acpi0: bus 2 (RP02)
acpiprt3 at acpi0: bus 3 (PCIB)
acpiec at acpi0 not configured
acpibtn at acpi0 not configured
pci0 at mainbus0 bus 0: configuration mode 1 (no bios)
pchb0 at pci0 dev 0 function 0 "Intel 82945GM MCH" rev 0x03
vga1 at pci0 dev 2 function 0 "Intel 82945GM Video" rev 0x03: aperture
at 0x90380000, size 0x10000000
wsdisplay0 at vga1 mux 1: console (80x25, vt100 emulation)
wsdisplay0: screen 1-5 added (80x25, vt100 emulation)
vendor "Intel", unknown product 0x27a3 (class DASP subclass Time and
Frequency, rev 0x03) at pci0 dev 7 function 0 not configured
azalia0 at pci0 dev 27 function 0 "Intel 82801GB HD Audio" rev 0x02:
apic 2 int 22 (irq 11)
azalia0: host: High Definition Audio rev. 1.0
azalia0: codec: Sigmatel STAC9221 (rev. 52.1), HDA version 1.0
audio0 at azalia0
ppb0 at pci0 dev 28 function 0 "Intel 82801GB PCIE" rev 0x02
pci1 at ppb0 bus 1
mskc0 at pci1 dev 0 function 0 "Marvell Yukon 88E8053" rev 0x22,
Yukon-2 EC rev. A3 (0x2): apic 2 int 16 (irq 11)
msk0 at mskc0 port A, address 00:16:cb:a7:46:d0
eephy0 at msk0 phy 0: Marvell 88E1111 Gigabit PHY, rev. 2
ppb1 at pci0 dev 28 function 1 "Intel 82801GB PCIE" rev 0x02
pci2 at ppb1 bus 2
ath0 at pci2 dev 0 function 0 "Atheros AR5424" rev 0x01: apic 2 int 17 (irq 11)
ath0: AR5424 10.3 phy 6.1 rf 10.2, WORAW, address 00:17:f2:4d:21:4a
uhci0 at pci0 dev 29 function 0 "Intel 82801GB USB" rev 0x02: apic 2
int 21 (irq 11)
usb0 at uhci0: USB revision 1.0
uhub0 at usb0
uhub0: Intel UHCI root hub, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1 at pci0 dev 29 function 1 "Intel 82801GB USB" rev 0x02: apic 2
int 19 (irq 11)
usb1 at uhci1: USB revision 1.0
uhub1 at usb1
uhub1: Intel UHCI root hub, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2 at pci0 dev 29 function 2 "Intel 82801GB USB" rev 0x02: apic 2
int 18 (irq 11)
usb2 at uhci2: USB revision 1.0
uhub2 at usb2
uhub2: Intel UHCI root hub, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
uhci3 at pci0 dev 29 function 3 "Intel 82801GB USB" rev 0x02: apic 2
int 16 (irq 10)
usb3 at uhci3: USB revision 1.0
uhub3 at usb3
uhub3: Intel UHCI root hub, rev 1.00/1.00, addr 1
uhub3: 2 ports with 2 removable, self powered
ehci0 at pci0 dev 29 function 7 "Intel 82801GB USB" rev 0x02: apic 2
int 21 (irq 11)
usb4 at ehci0: USB revision 2.0
uhub4 at usb4
uhub4: Intel EHCI root hub, rev 2.00/1.00, addr 1
uhub4: 8 ports with 8 removable, self powered
ppb2 at pci0 dev 30 function 0 "Intel 82801BAM Hub-to-PCI" rev 0xe2
pci3 at ppb2 bus 3
"AT&T/Lucent FW322 1394" rev 0x61 at pci3 dev 3 function 0 not configured
ichpcib0 at pci0 dev 31 function 0 "Intel 82801GBM LPC" rev 0x02: PM disabled
pciide0 at pci0 dev 31 function 1 "Intel 82801GB IDE" rev 0x02: DMA,
channel 0 configured to compatibility, channel 1 configured to
compatibility
atapiscsi0 at pciide0 channel 0 drive 0
scsibus0 at atapiscsi0: 2 targets
cd0 at scsibus0 targ 0 lun 0: <MATSHITA, DVD-R UJ-846, FM3J> SCSI0
5/cdrom removable
cd0(pciide0:0:0): using PIO mode 4, Ultra-DMA mode 4
pciide0: channel 1 disabled (no drives)
pciide1 at pci0 dev 31 function 2 "Intel 82801GBM SATA" rev 0x02: DMA,
channel 0 configured to native-PCI, channel 1 configured to native-PCI
pciide1: using apic 2 int 19 (irq 11) for native-PCI interrupt
wd0 at pciide1 channel 0 drive 1: <FUJITSU MHV2080BHPL>
wd0: 16-sector PIO, LBA48, 76319MB, 156301488 sectors
wd0(pciide1:0:1): using PIO mode 4, Ultra-DMA mode 5
ichiic0 at pci0 dev 31 function 3 "Intel 82801GB SMBus" rev 0x02: apic
2 int 19 (irq 11)
iic0 at ichiic0
isa0 at ichpcib0
isadma0 at isa0
pcppi0 at isa0 port 0x61
midi0 at pcppi0: <PC speaker>
spkr0 at pcppi0
npx0 at isa0 port 0xf0/16: reported by CPUID; using exception 16
pctr: 686-class user-level performance counters enabled
mtrr: Pentium Pro MTRR support
uhidev0 at uhub3 port 1 configuration 1 interface 0
uhidev0: Apple Computer ADB device, rev 2.00/19.65, addr 2, iclass 3/1
ukbd0 at uhidev0: 8 modifier keys, 6 key codes
wskbd0 at ukbd0: console keyboard, using wsdisplay0
uhidev1 at uhub3 port 1 configuration 1 interface 1
uhidev1: Apple Computer ADB device, rev 2.00/19.65, addr 2, iclass 3/1
ums0 at uhidev1: 5 buttons
wsmouse0 at ums0 mux 0
uhidev2 at uhub3 port 2 configuration 1 interface 0
uhidev2: Apple Computer, Inc. IR Receiver, rev 2.00/1.10, addr 3, iclass 3/0
uhidev2: 38 report ids
uhid0 at uhidev2 reportid 36: input=4, output=0, feature=0
uhid1 at uhidev2 reportid 37: input=4, output=0, feature=0
uhid2 at uhidev2 reportid 38: input=4, output=0, feature=0
dkcsum: wd0 matches BIOS drive 0x80
root on wd0a
rootdev=0x0 rrootdev=0x300 rawdev=0x302
Joachim Schipper
2007-03-27 19:05:15 UTC
Permalink
Post by Tasmanian Devil
Hello, list! :-)
After reading this list for several monthes with dedication and after
I'm following -current on an Apple Mac mini (GENERIC.MP with ACPI
enabled, dmesg below) and I transfer files with SCP and SFTP to this
server. After a few successful transfers, /dev/null obviously breaks
somehow on the server ("Couldn't open /dev/null" error on the client
/dev root# ls -l null
-rw------- 1 root wheel 56 Mar 27 18:13 null
After a "./MAKEDEV std" everything works fine again, at least for the
/dev root# ls -l null
crw-rw-rw- 1 root wheel 2, 2 Mar 27 19:50 null
At first I thought the upgrade to OpenSSH 4.6 with a snapshot from
about two weeks ago would have fixed this problem, but it just
happened again. I've searched on the web and in the mailing list
archive, but couldn't find anything related to this problem so far. I
have never seen this problem on any of my other OpenBSD machines.
Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.

Are you sure it's OpenSSH? What other daemons are using to /dev/null
(fstat?)? It would make sense if some daemon thought it was a logfile or
somesuch and decided to 'secure' it...

Joachim
Otto Moerbeek
2007-03-27 19:27:05 UTC
Permalink
Post by Joachim Schipper
Post by Tasmanian Devil
Hello, list! :-)
After reading this list for several monthes with dedication and after
I'm following -current on an Apple Mac mini (GENERIC.MP with ACPI
enabled, dmesg below) and I transfer files with SCP and SFTP to this
server. After a few successful transfers, /dev/null obviously breaks
somehow on the server ("Couldn't open /dev/null" error on the client
/dev root# ls -l null
-rw------- 1 root wheel 56 Mar 27 18:13 null
After a "./MAKEDEV std" everything works fine again, at least for the
/dev root# ls -l null
crw-rw-rw- 1 root wheel 2, 2 Mar 27 19:50 null
At first I thought the upgrade to OpenSSH 4.6 with a snapshot from
about two weeks ago would have fixed this problem, but it just
happened again. I've searched on the web and in the mailing list
archive, but couldn't find anything related to this problem so far. I
have never seen this problem on any of my other OpenBSD machines.
Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.
The device also turned into a regular file. Maybe the content of the
null file gives a hint of what went wrong. Which files were you
copying and to which directory? scp -v might help to see what is going on.
Post by Joachim Schipper
Are you sure it's OpenSSH? What other daemons are using to /dev/null
(fstat?)? It would make sense if some daemon thought it was a logfile or
somesuch and decided to 'secure' it...
-Otto
Tasmanian Devil
2007-03-28 07:23:30 UTC
Permalink
Post by Otto Moerbeek
Post by Joachim Schipper
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.
The device also turned into a regular file. Maybe the content of the
null file gives a hint of what went wrong. Which files were you
copying and to which directory? scp -v might help to see what is going on.
I replied to this post, though only to Otto directly and not to the
list - my fault, sorry! So I exchanged a few private emails with Otto,
and thanks to Otto's really powerful magic we have a solution for my
problem. :-)

The cause for the disappearing /dev/null is not SCP or SFTP but mysql
on the command line. The bug is described here:
http://bugs.mysql.com/bug.php?id=16803 and at the bottom of that
thread it seems that they say it's fixed since version 5.0.22, but
that's obviously not true. I'm running MySQL 5.0.33 (from
snapshots/packages/i386/) and the bug is still there.

I had "MYSQL_HISTFILE=/dev/null" in my .profile file because I didn't
want to have a file with my mysql history. That works fine as long as
you *don't* start mysql as the system user "root". You can start it as
normal user with "mysql -u root -p" to log into MySQL as the MySQL
user "root" and still everything's working fine.

But if you start mysql as sytem user "root" with "mysql -p" or "mysql
-u root -p", /dev/null will become a normal file with your latest
mysql history inside (or nothing inside if you didn't type any mysql
commands except "quit"), *after* you left the mysql shell with "quit".

So the solution is: Don't start mysql on the command line as system
user "root" or let mysql keep it's history whereever it wants (no
"MYSQL_HISTFILE=/dev/null" in .profile).

It seems that I always played with mysql while transfering a few
files, so I thought it would be a SFTP or SCP issue, but thanks to
Otto we know what is really happening. :-)

And while testing with mysql Darren's tip to test for changes on
/dev/null with a cronjob was very useful: The cronjob found the
changes at once. :-)

You can avoid the problems easily like described above, but maybe it's
even possible that someone fixes MySQL now or maybe adds a warning to
the mysql man page.

Again thank you very much, Otto and all the others on this great list!
I'll keep reading here every day. :-)

Tas.
Tasmanian Devil
2007-03-28 08:14:56 UTC
Permalink
Post by Tasmanian Devil
So the solution is: Don't start mysql on the command line as system
user "root" or let mysql keep it's history whereever it wants (no
"MYSQL_HISTFILE=/dev/null" in .profile).
Just a little addition to that: I'll try my luck with a 2 MB RAM disk
instead of /dev/null just for the mysql history file now:

$ grep mfs /etc/fstab
swap /mfs mfs rw,nodev,nosuid,-s=4386 0 0

$ df -h /mfs
Filesystem Size Used Avail Capacity Mounted on
mfs:22758 2.0M 1.0K 1.9M 0% /mfs

and

$ grep MYSQL .profile
MYSQL_HISTFILE=/mfs/.mysql_history
export MYSQL_HISTFILE

I had the RAM disk created already anyway.

Tas.

Tasmanian Devil
2007-03-27 19:56:34 UTC
Permalink
Post by Joachim Schipper
Post by Tasmanian Devil
Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.
Are you sure it's OpenSSH? What other daemons are using to /dev/null
(fstat?)? It would make sense if some daemon thought it was a logfile or
somesuch and decided to 'secure' it...
Hm, fstat doesn't show much unusual, mainly httpd and mysql besides
the standard daemons. I have the same combination of daemons running
on older machines (GENERIC 4.0 -stable without ACPI though), but no
problem there.

The permissions of /dev/null change directly after (or maybe even
while) using SFTP, and not always. Sometimes I can log in several
times over a few hours without fixing /dev/null, and then again only
one single time. E.g. right now I can't reproduce the error. And if I
don't use SCP/SFTP at all, everything works fine, for weeks, so it
seems to be related to SCP/SFTP. Probably it's only happening after
using SFTP (and SCP doesn't work afterwards), but unfortunately I'm
not sure as I don't transfer files that often.

I'll search in the direction of other deamons though. Thank you for the hint!

Tas.
Joachim Schipper
2007-03-27 23:05:35 UTC
Permalink
Post by Tasmanian Devil
Post by Joachim Schipper
Post by Tasmanian Devil
Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.
Are you sure it's OpenSSH? What other daemons are using to /dev/null
(fstat?)? It would make sense if some daemon thought it was a logfile or
somesuch and decided to 'secure' it...
Hm, fstat doesn't show much unusual, mainly httpd and mysql besides
the standard daemons. I have the same combination of daemons running
on older machines (GENERIC 4.0 -stable without ACPI though), but no
problem there.
The permissions of /dev/null change directly after (or maybe even
while) using SFTP, and not always. Sometimes I can log in several
times over a few hours without fixing /dev/null, and then again only
one single time. E.g. right now I can't reproduce the error. And if I
don't use SCP/SFTP at all, everything works fine, for weeks, so it
seems to be related to SCP/SFTP. Probably it's only happening after
using SFTP (and SCP doesn't work afterwards), but unfortunately I'm
not sure as I don't transfer files that often.
I'll search in the direction of other deamons though. Thank you for the hint!
If that doesn't turn up anything, could you post /etc/sshd_config? And,
perhaps, the result of ssh -vvv your.problematic.host?

Joachim
Tasmanian Devil
2007-03-27 23:59:47 UTC
Permalink
Post by Joachim Schipper
Post by Tasmanian Devil
I'll search in the direction of other deamons though. Thank you for the hint!
If that doesn't turn up anything, could you post /etc/sshd_config? And,
perhaps, the result of ssh -vvv your.problematic.host?
Sure, posted below.

I tried to force the problem to show up with a *lot* of connection
attempts now, probably more today alone than in many weeks before, but
it always worked so far. Two weeks ago I was about to post about the
problem here, but thought I should try with a latest snapshot first,
installed it (it's still installed), and the problem seemed to be
fixed until today, when the problem showed up again. Before that I had
several 4.0 snapshots installed, and the problem showed up much more
often at that time, after roughly 10 successful connections via SFTP.
I never tried to force the problem to show up before though as I don't
transfer files via SFTP that often, and the "temporary" fix with
"./MAKEDEV std" was easy, though it gets really a bit annoying now as
I thought it would be fixed with OpenSSH 4.6...

Tas.


$ cat /etc/ssh/sshd_config
# $OpenBSD: sshd_config,v 1.74 2006/07/19 13:07:10 dtucker Exp $

# This is the sshd server system-wide configuration file. See
# sshd_config(5) for more information.

# The strategy used for options in the default sshd_config shipped with
# OpenSSH is to specify options with their default value where
# possible, but leave them commented. Uncommented options change a
# default value.

#Port 22
Protocol 2
AddressFamily inet
ListenAddress XX.XX.XX.XX # Edited before posting here
#ListenAddress ::

# HostKey for protocol version 1
#HostKey /etc/ssh/ssh_host_key
# HostKeys for protocol version 2
#HostKey /etc/ssh/ssh_host_rsa_key
#HostKey /etc/ssh/ssh_host_dsa_key

# Lifetime and size of ephemeral version 1 server key
#KeyRegenerationInterval 1h
#ServerKeyBits 768

# Logging
# obsoletes QuietMode and FascistLogging
#SyslogFacility AUTH
#LogLevel INFO

# Authentication:

LoginGraceTime 10m
PermitRootLogin no
#StrictModes yes
#MaxAuthTries 6

#RSAAuthentication yes
#PubkeyAuthentication yes
AuthorizedKeysFile /etc/ssh/authorized_keys

AllowUsers tas

# For this to work you will also need host keys in /etc/ssh/ssh_known_hosts
#RhostsRSAAuthentication no
# similar for protocol version 2
#HostbasedAuthentication no
# Change to yes if you don't trust ~/.ssh/known_hosts for
# RhostsRSAAuthentication and HostbasedAuthentication
#IgnoreUserKnownHosts no
# Don't read the user's ~/.rhosts and ~/.shosts files
#IgnoreRhosts yes

# To disable tunneled clear text passwords, change to no here!
PasswordAuthentication no
#PermitEmptyPasswords no

# Change to no to disable s/key passwords
ChallengeResponseAuthentication no

# Kerberos options
#KerberosAuthentication no
#KerberosOrLocalPasswd yes
#KerberosTicketCleanup yes
#KerberosGetAFSToken no

# GSSAPI options
#GSSAPIAuthentication no
#GSSAPICleanupCredentials yes

#AllowTcpForwarding yes
#GatewayPorts no
#X11Forwarding no
#X11DisplayOffset 10
#X11UseLocalhost yes
#PrintMotd yes
#PrintLastLog yes
#TCPKeepAlive yes
#UseLogin no
#UsePrivilegeSeparation yes
#PermitUserEnvironment no
#Compression delayed
#ClientAliveInterval 0
#ClientAliveCountMax 3
#UseDNS yes
#PidFile /var/run/sshd.pid
#MaxStartups 10
PermitTunnel yes

# no default banner path
#Banner /some/path

# override default of no subsystems
Subsystem sftp /usr/libexec/sftp-server

# Example of overriding settings on a per-user basis
#Match User anoncvs
# X11Forwarding no
# AllowTcpForwarding no
# ForceCommand cvs server



$ ssh -vvv tas
OpenSSH_4.6, OpenSSL 0.9.7j 04 May 2006
debug1: Reading configuration data /etc/ssh/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to tas [XX.XX.XX.XX] port 22.
debug1: Connection established.
debug1: identity file /home/tas/.ssh/identity type -1
debug3: Not a RSA1 key file /home/tas/.ssh/id_rsa.
debug2: key_type_from_name: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key_type_from_name: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /home/tas/.ssh/id_rsa type 1
debug1: identity file /home/tas/.ssh/id_dsa type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_4.6
debug1: match: OpenSSH_4.6 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.6
debug2: fd 4 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-***@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-***@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-***@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-***@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,***@openssh.com,zlib
debug2: kex_parse_kexinit: none,***@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-***@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-***@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-***@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,hmac-ripemd160,hmac-***@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,***@openssh.com
debug2: kex_parse_kexinit: none,***@openssh.com
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug2: dh_gen_key: priv key bits set: 130/256
debug2: bits set: 525/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: check_host_in_hostfile: filename /home/tas/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 3
debug3: check_host_in_hostfile: filename /home/tas/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 3
debug1: Host 'tas' is known and matches the RSA host key.
debug1: Found key in /home/tas/.ssh/known_hosts:3
debug2: bits set: 514/1024
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /home/tas/.ssh/identity (0x0)
debug2: key: /home/tas/.ssh/id_rsa (0x8433faa0)
debug2: key: /home/tas/.ssh/id_dsa (0x0)
debug1: Authentications that can continue: publickey
debug3: start over, passed a different list publickey
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /home/tas/.ssh/identity
debug3: no such identity: /home/tas/.ssh/identity
debug1: Offering public key: /home/tas/.ssh/id_rsa
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input_userauth_pk_ok: fp 8e:18:58:f1:c7:ee:61:29:84:f0:6e:81:16:74:ea:18
debug3: sign_and_send_pubkey
debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug1: Entering interactive session.
debug2: callback start
debug1: Requesting tun.
debug1: tun_open: /dev/tun0 open failed: Permission denied
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 0
debug3: tty_make_modes: ospeed 9600
debug3: tty_make_modes: ispeed 9600
debug3: tty_make_modes: 1 3
debug3: tty_make_modes: 2 28
debug3: tty_make_modes: 3 127
debug3: tty_make_modes: 4 21
debug3: tty_make_modes: 5 4
debug3: tty_make_modes: 6 255
debug3: tty_make_modes: 7 255
debug3: tty_make_modes: 8 17
debug3: tty_make_modes: 9 19
debug3: tty_make_modes: 10 26
debug3: tty_make_modes: 11 25
debug3: tty_make_modes: 12 18
debug3: tty_make_modes: 13 23
debug3: tty_make_modes: 14 22
debug3: tty_make_modes: 17 20
debug3: tty_make_modes: 18 15
debug3: tty_make_modes: 30 0
debug3: tty_make_modes: 31 0
debug3: tty_make_modes: 32 0
debug3: tty_make_modes: 33 0
debug3: tty_make_modes: 34 0
debug3: tty_make_modes: 35 0
debug3: tty_make_modes: 36 1
debug3: tty_make_modes: 37 0
debug3: tty_make_modes: 38 1
debug3: tty_make_modes: 39 1
debug3: tty_make_modes: 40 0
debug3: tty_make_modes: 41 1
debug3: tty_make_modes: 50 1
debug3: tty_make_modes: 51 1
debug3: tty_make_modes: 52 0
debug3: tty_make_modes: 53 1
debug3: tty_make_modes: 54 1
debug3: tty_make_modes: 55 0
debug3: tty_make_modes: 56 0
debug3: tty_make_modes: 57 0
debug3: tty_make_modes: 58 0
debug3: tty_make_modes: 59 1
debug3: tty_make_modes: 60 1
debug3: tty_make_modes: 61 1
debug3: tty_make_modes: 62 1
debug3: tty_make_modes: 70 1
debug3: tty_make_modes: 71 0
debug3: tty_make_modes: 72 1
debug3: tty_make_modes: 73 0
debug3: tty_make_modes: 74 0
debug3: tty_make_modes: 75 0
debug3: tty_make_modes: 90 1
debug3: tty_make_modes: 91 1
debug3: tty_make_modes: 92 0
debug3: tty_make_modes: 93 0
debug2: channel 0: request shell confirm 0
debug2: fd 4 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 131072
Last login: Wed Mar 28 01:19:54 2007 from [REMOVED]
OpenBSD 4.1 (GENERIC.MP) #1225: Sat Mar 10 19:23:18 MST 2007

tas:~ tas$ exit
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0

debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: rcvd close
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1)

debug3: channel 0: close_fds r -1 w -1 e 7 c -1
Connection to tas closed.
debug1: Transferred: stdin 0, stdout 0, stderr 28 bytes in 4.2 seconds
debug1: Bytes per second: stdin 0.0, stdout 0.0, stderr 6.6
debug1: Exit status 0
Darren Tucker
2007-03-28 02:10:52 UTC
Permalink
Post by Tasmanian Devil
Post by Joachim Schipper
Post by Tasmanian Devil
Has anybody an idea what I could do to find the cause of this
"disappearing /dev/null"? Thank you in advance for your help!
Well, it doesn't disappear so much as having its permissions altered,
but I'm certain you are aware of that.
Are you sure it's OpenSSH? What other daemons are using to /dev/null
(fstat?)? It would make sense if some daemon thought it was a logfile or
somesuch and decided to 'secure' it...
Hm, fstat doesn't show much unusual, mainly httpd and mysql besides
the standard daemons. I have the same combination of daemons running
on older machines (GENERIC 4.0 -stable without ACPI though), but no
problem there.
The permissions of /dev/null change directly after (or maybe even
while) using SFTP, and not always.
It's not just permissions, it's no longer a character special (device)
file, it's a regular file. This usually happens when /dev/null is
deleted, and sooner or later something with root perms will write to it,
at which point it gets recreated as a regular file.
Post by Tasmanian Devil
Sometimes I can log in several
times over a few hours without fixing /dev/null, and then again only
one single time. E.g. right now I can't reproduce the error. And if I
don't use SCP/SFTP at all, everything works fine, for weeks, so it
seems to be related to SCP/SFTP.
During that time, is /dev/null still a character special, or has it
turned into a regular file?

I suspect that something else (maybe a cron job?) is removing /dev/null
and the scp/sftp error is just a symptom.

You could try something like this running from cron regularly:

test -c /dev/null || echo /dev/null vanished or not character special

and see if/when it starts mailing you.
Post by Tasmanian Devil
Probably it's only happening after
using SFTP (and SCP doesn't work afterwards), but unfortunately I'm
not sure as I don't transfer files that often.
--
Darren Tucker (dtucker at zip.com.au)
GPG key 8FF4FA69 / D9A3 86E9 7EEE AF4B B2D4 37C9 C982 80C7 8FF4 FA69
Good judgement comes with experience. Unfortunately, the experience
usually comes from bad judgement.
Tasmanian Devil
2007-03-28 02:47:36 UTC
Permalink
Post by Darren Tucker
Post by Tasmanian Devil
The permissions of /dev/null change directly after (or maybe even
while) using SFTP, and not always.
It's not just permissions, it's no longer a character special (device)
file, it's a regular file. This usually happens when /dev/null is
deleted, and sooner or later something with root perms will write to it,
at which point it gets recreated as a regular file.
Yes, that might be it.
Post by Darren Tucker
Post by Tasmanian Devil
Sometimes I can log in several
times over a few hours without fixing /dev/null, and then again only
one single time. E.g. right now I can't reproduce the error. And if I
don't use SCP/SFTP at all, everything works fine, for weeks, so it
seems to be related to SCP/SFTP.
During that time, is /dev/null still a character special, or has it
turned into a regular file?
I'm quite sure it's still a character special during that time (or at
least most of that time). Every time I checked it was one, though I
never checked directly before using SCP or SFTP, especially not after
I was hoping that last snapshot installation had fixed it.
Post by Darren Tucker
I suspect that something else (maybe a cron job?) is removing /dev/null
and the scp/sftp error is just a symptom.
Yes, that's possible, though on that server are only the original
cronjobs which came with the default install. I didn't add any
additional cronjob.
Post by Darren Tucker
test -c /dev/null || echo /dev/null vanished or not character special
and see if/when it starts mailing you.
Good idea, I'll try that, but maybe it's even not necessary? I have
the timestamp on the regular file which was created somehow (from my
Post by Darren Tucker
/dev root# ls -l null
-rw------- 1 root wheel 56 Mar 27 18:13 null
So I checked /var/log for this timestamp (I hope I catched all entries
this way, I'm not an professional like many of you are, though I learn
more and more about OpenBSD and it's a lot of fun for me :-) ):

# zgrep 'Mar 27 18:1' /var/log/*
/var/log/daemon:Mar 27 18:13:12 tas identd[20077]: Connection from localhost
/var/log/daemon:Mar 27 18:13:12 tas identd[13260]: Connection from localhost
/var/log/daemon:Mar 27 18:13:12 tas identd[24972]: Connection from localhost
/var/log/daemon:Mar 27 18:13:17 tas identd[20077]: scanf:
invalid-port(s): 0 , 0 from localhost
/var/log/maillog.0.gz:Mar 27 18:13:12 tas sm-mta[22178]:
l2RGDCfv022178: ***@localhost [127.0.0.1] did not issue
MAIL/EXPN/VRFY/ETRN during connection to MTA
/var/log/maillog.0.gz:Mar 27 18:13:12 tas sm-mta[1887]:
l2RGDCxT001887: ***@localhost [127.0.0.1] did not issue
MAIL/EXPN/VRFY/ETRN during connection to MSA
/var/log/messages.0.gz:Mar 27 18:13:17 tas identd[20077]: scanf:
invalid-port(s): 0 , 0 from localhost

Does that help somehow?

Tas.
Tasmanian Devil
2007-03-28 03:11:10 UTC
Permalink
Do a "cat /dev/null" when it is a regular file (as root, we can see the
permissions are tight).. The contents of the file may give a clue as to
the last process that (successfully) wrote to /dev/null.
I'll do that as soon as the problem shows up again, and I'll try to
force that, but if it stays as "stable" as over the last two weeks,
it'll take another two weeks... Anyway, I'll post the file content as
soon as I have it.

Tas.
Steve Williams
2007-03-28 03:01:00 UTC
Permalink
Post by Tasmanian Devil
Post by Darren Tucker
Post by Tasmanian Devil
The permissions of /dev/null change directly after (or maybe even
while) using SFTP, and not always.
It's not just permissions, it's no longer a character special (device)
file, it's a regular file. This usually happens when /dev/null is
deleted, and sooner or later something with root perms will write to it,
at which point it gets recreated as a regular file.
Yes, that might be it.
Post by Darren Tucker
Post by Tasmanian Devil
Sometimes I can log in several
times over a few hours without fixing /dev/null, and then again only
one single time. E.g. right now I can't reproduce the error. And if I
don't use SCP/SFTP at all, everything works fine, for weeks, so it
seems to be related to SCP/SFTP.
During that time, is /dev/null still a character special, or has it
turned into a regular file?
I'm quite sure it's still a character special during that time (or at
least most of that time). Every time I checked it was one, though I
never checked directly before using SCP or SFTP, especially not after
I was hoping that last snapshot installation had fixed it.
Post by Darren Tucker
I suspect that something else (maybe a cron job?) is removing /dev/null
and the scp/sftp error is just a symptom.
Yes, that's possible, though on that server are only the original
cronjobs which came with the default install. I didn't add any
additional cronjob.
Post by Darren Tucker
test -c /dev/null || echo /dev/null vanished or not character special
and see if/when it starts mailing you.
Good idea, I'll try that, but maybe it's even not necessary? I have
the timestamp on the regular file which was created somehow (from my
Post by Darren Tucker
/dev root# ls -l null
-rw------- 1 root wheel 56 Mar 27 18:13 null
So I checked /var/log for this timestamp (I hope I catched all entries
this way, I'm not an professional like many of you are, though I learn
# zgrep 'Mar 27 18:1' /var/log/*
/var/log/daemon:Mar 27 18:13:12 tas identd[20077]: Connection from localhost
/var/log/daemon:Mar 27 18:13:12 tas identd[13260]: Connection from localhost
/var/log/daemon:Mar 27 18:13:12 tas identd[24972]: Connection from localhost
invalid-port(s): 0 , 0 from localhost
MAIL/EXPN/VRFY/ETRN during connection to MTA
MAIL/EXPN/VRFY/ETRN during connection to MSA
invalid-port(s): 0 , 0 from localhost
Does that help somehow?
Tas.
Do a "cat /dev/null" when it is a regular file (as root, we can see the
permissions are tight).. The contents of the file may give a clue as to
the last process that (successfully) wrote to /dev/null.

Just my $.02 worth.

Good luck!

Cheers,
Steve Williams
Tasmanian Devil
2007-03-28 03:48:37 UTC
Permalink
No, that tells you when the new /dev/null got created, not when the real
one got deleted (which may have been hours earlier).
Ah, I see. I've two cronjobs already installed and tested (I've two of
these machines, same hardware, same snapshot installed, one is far
away, the other one is local - which hopefully doubles my chances to
catch something).

Tas.
Loading...