Re: bash uses tmp files for inter-process communication instead of pipes?

[Linda Walsh]

Chet Ramey wrote:
> On 10/7/14, 8:55 AM, Dan Douglas wrote:
>
> > > Um... it used a socket.. to transfer it, then it uses a tmp file on top
> > > of that?!  :
> > That's the wrong process. AF_NETLINK is the interface used by iproute2 for IPC 
> > with the kernel. Bash doesn't use netlink sockets.
>
> It's syslog.  Some vendors integrated patches that log all shell commands
> to syslog.
>
> Chet
----
No... that wasn't syslog, it was strace in another terminal where I attached
the bacsh that was doing the various types of data transfer (pipes, process 
subst)
assignment... etc)....

> strace -p 48785 -ff
Process 48785 attached
read(0, "\r", 1)                        = 1
write(2, "\n", 1)                       = 1
socket(PF_NETLINK, SOCK_RAW, 9)         = 3
sendmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, 
msg_iov(2)=[{"*\0\0\0d\4\1\0\0\0\0\0\0\0\0\0", 16}, {"read a b c d 
<<<${arr[@]}\0", 26}], msg_controllen=0, msg_flags=0}, 0) = 42
close(3)                                = 0
-----
Um... it used a socket.. to transfer *i^Ht^H*SOMETHING,
then it uses a tmp file on top of that:

rt_sigaction(SIGINT, {0x4320b1, [], SA_RESTORER|SA_RESTART, 0x30020358d0}, 
{0x4320b1, [], SA_RESTORER|SA_RESTART, 0x30020358d0}, 8) = 0
open("/tmp/sh-thd-110678907923", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC, 0600) = 3
write(3, "one two three four", 18)      = 18
write(3, "\n", 1)                       = 1
open("/tmp/sh-thd-110678907923", O_RDONLY) = 4
close(3)                                = 0
unlink("/tmp/sh-thd-110678907923")      = 0
fcntl(0, F_GETFD)                       = 0
fcntl(0, F_DUPFD, 10)                   = 10
fcntl(0, F_GETFD)                       = 0
fcntl(10, F_SETFD, FD_CLOEXEC)          = 0
dup2(4, 0)                              = 0
close(4)                                = 0



Bash may not use netlink sockets directly, but perhaps that was a weird looking 
call
to 'nss' to do some name or group lookup... but the presence of the read text as
part of one of the messages seems a bit peculiar.


Of NOTE:
straces I ran with the system up in normal RL3 -- that is where I see it writing
to tmp.  I have neither TMP nor TMPDIR set at this point.  I don't
think TMP or TMPDIR is set in the runscript at boot, but the script could be 
inheriting
a value from the bootup-infrastructure environment.  I would have expected them
to write into /tmp -- which was why in one of the listings I did the "du" on 
both
/tmp and /var/tmp to show they were mounted and did a test "write" (touch) on
a file in /tmp and verified I was able to do so and see it with "ls".

If TMP{DIR} are set to a value, it isn't "/tmp or /var/tmp" since both are up 
and
available at that point.

The problem is that if I manually break into the boot process (this system goes
through a 'B' state to do these things:

/etc/rc.d/boot.d/S01boot.sysctl@
/etc/rc.d/boot.d/S01boot.usr-mount@
/etc/rc.d/boot.d/S02boot.udev@
/etc/rc.d/boot.d/S04boot.lvm@
/etc/rc.d/boot.d/S05boot.clock@
/etc/rc.d/boot.d/S06boot.localnet@
/etc/rc.d/boot.d/S07boot.cgroup@
/etc/rc.d/boot.d/S11boot.localfs@
/etc/rc.d/boot.d/S13boot.klog@
/etc/rc.d/boot.d/S13boot.lvm_monitor@
/etc/rc.d/boot.d/S13boot.swap@
/etc/rc.d/boot.d/S13setserial@
/etc/rc.d/boot.d/S14boot.isapnp@
/etc/rc.d/boot.d/S14boot.ldconfig@
/etc/rc.d/boot.d/S50boot.assign_netif_names@
/etc/rc.d/boot.d/S50boot.sys_settings@
/etc/rc.d/boot.d/S50boot.sysstat@

----the script in question is "assign_netif_names" run fairly late.
But if I Break in on 'B', I get control before S01boot.  If I run the command
manually at that point, **it works**.   Only when I'm letting it boot normally, 
does
it hit this problem.

During a normal boot some of these are happening in parallel, however, that was
why I tested the writability of /tmp (verified it to be so).  I'll print out
TMP and TMPDIR -- and see if they contain unexpected values, but my assumption 
has
been they are empty then as they are after boot, with /tmp taking the tmp file 
(as
was the case in the strace I ran w/system up).

The messages I see, record and transmit are the boot logs -- not trace logs, and
show the kernel boot followed by a switchover (when klog is called) from the
kernel format to a more user-ish format i.e:
[    4.058222] rtc_cmos 00:01: RTC can wake from S4
[    4.058567] rtc_cmos 00:01: rtc core: registered rtc_cmos as rtc0
[    4.058607] rtc_cmos 00:01: alarms up to one day, y3k, 242 bytes nvram, hpet 
irqs
[    4.058772] device-mapper: uevent: version 1.0.3
[    4.059034] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised...
----
.....root fs is next:
(> mount |grep sdc1
/dev/sdc1 on / type xfs (rw,nodiratime,relatime,attr2,inode64,noquota))
----
[    4.356688] XFS (sdc1): Mounting V4 Filesystem
[    4.423530] usb 1-3.1: new low-speed USB device number 3 using ehci-pci
[    4.447749] XFS (sdc1): Ending clean mount
[    4.451993] VFS: Mounted root (xfs filesystem) on device 8:33.
[    4.461451] devtmpfs: mounted

... last kernel USB probe.. then a 15-second gap while MOST of the disk
subsystems come on line (i.e. there are no messages in the kernel log during
this point.... this used to take about 12 seconds before I added another 48T
disk container...

[    4.764898] usb 1-3.2: Product: Dell USB Keyboard
[    4.769789] usb 1-3.2: Manufacturer: Dell
[    4.778342] input: Dell Dell USB Keyboard as 
/devices/pci0000:00/0000:00:1a.7/usb1/1-3/1-3.2/1-3.2:1.0/0003:413C:2003.0002/input/input4
[    4.791334] hid-generic 0003:413C:2003.0002: input,hidraw1: USB HID v1.10 
Keyboard [Dell Dell USB Keyboard] on usb-0000:00:1a.7-3.2/input0
[   19.364744] modprobe (169) used greatest stack depth: 12768 bytes left
[   19.601136] XFS (sdc6): Mounting V4 Filesystem
[   19.697669] XFS (sdc6): Ending clean mount

^^^ that was /usr -- 2nd script in 'boot'


[   20.241849] mountpoint (243) used greatest stack depth: 12720 bytes left
[   20.297137] boot.assign_net (252) used greatest stack depth: 12688 bytes left
[   20.299075] XFS (sdc2): Mounting V4 Filesystem
[   20.375385] ip (302) used greatest stack depth: 12608 bytes left
[   20.446923] XFS (sdc2): Ending clean mount
---
sdc2 is used for *both* tmp devices... though root is mounted 'r/w' and
the tmp dir is writable until "/var/rtmp" is mounted via 'rbind' onto /tmp.
/var is mounted in the same script as the /usr script (both considered vital
file systems for further boot)... but /var/rtmp is mounted on
/tmp in the "localfs" stage (S11boot.localfs).

[Maybe I'll try moving that to the same time var is mounted
since both would be ready then...]


--- more startup script stuff...

[   20.626771] udevd[313]: starting version 173
[   21.128558] bnx2: Broadcom NetXtreme II Gigabit Ethernet Driver bnx2 v2.2.5 
(December 20, 2013)
[   21.138419] bnx2 0000:01:00.0 eth2: Broadcom NetXtreme II BCM5709 1000Base-T 
(C0) PCI Express found at mem da000000, IRQ 36, node addr 00:26:b9:48:71:e2
[   21.153175] bnx2 0000:01:00.1 eth3: Broadcom NetXtreme II BCM5709 1000Base-T 
(C0) PCI Express found at mem dc000000, IRQ 48, node addr 00:26:b9:48:71:e4
[   21.167507] modprobe (335) used greatest stack depth: 12272 bytes left
[   21.237907] dca service started, version 1.12.1
[   21.345894] ixgbe: Intel(R) 10 Gigabit PCI Express Network Driver - version 
3.19.1-k
[   21.353845] ixgbe: Copyright (c) 1999-2014 Intel Corporation.
[   21.382128] wmi: Mapper loaded
[   21.383595] input: Power Button as 
/devices/LNXSYSTM:00/LNXPWRBN:00/input/input5
[   21.383677] ACPI: Power Button [PWRF]
[   21.386788] EDAC MC1: Giving out device to module i7core_edac.c controller i7 
core #1: DEV 0000:fe:03.0 (POLLED)
[   21.386888] EDAC PCI0: Giving out device to module i7core_edac controller 
EDAC PCI controller: DEV 0000:fe:03.0 (POLLED)
[   21.387586] EDAC MC0: Giving out device to module i7core_edac.c controller i7 
core #0: DEV 0000:ff:03.0 (POLLED)
[   21.387651] EDAC PCI1: Giving out device to module i7core_edac controller 
EDAC PCI controller: DEV 0000:ff:03.0 (POLLED)
[   21.387990] EDAC i7core: Driver loaded, 2 memory controller(s) found.
[   21.437048] iTCO_vendor_support: vendor-support=0
[   21.457915] gpio_ich: GPIO from 195 to 255 on gpio_ich
[   21.489767] ipmi message handler version 39.2
[   21.519579] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.11
[   21.525481] iTCO_wdt: Found a ICH9 TCO device (Version=2, TCOBASE=0x0860)
[   21.533454] iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
[   21.551797] alg: No test for crc32 (crc32-pclmul)
[   21.565184] IPMI System Interface driver.
[   21.569442] ipmi_si: probing via SMBIOS
[   21.573451] ipmi_si: SMBIOS: io 0xca8 regsize 1 spacing 4 irq 0
....
[   21.592113] ioatdma: Intel(R) QuickData Technology Driver 4.00
[   21.593327] ioatdma 0000:00:16.0: irq 95 for MSI/MSI-X
....
[   21.769176] ixgbe 0000:05:00.0: Multiqueue Enabled: Rx Queue count = 12, Tx 
Queue count = 12
[   21.828045] ipmi_si ipmi_si.0: Found new BMC (man_id: 0x0002a2, prod_id: 
0x0100, dev_id: 0x20)
[   21.836825] ipmi_si ipmi_si.0: IPMI kcs interface initialized
[   21.837817] ixgbe 0000:05:00.0: PCI Express bandwidth of 32GT/s available
[   21.837819] ixgbe 0000:05:00.0: (Speed:5.0GT/s, Width: x8, Encoding Loss:20%)
....
[   22.086455] coretemp coretemp.1: TjMax is 96 degrees C
[   22.087051] coretemp coretemp.0: TjMax is 96 degrees C
[   22.142151] ixgbe 0000:05:00.0: Intel(R) 10 Gigabit Network Connection
[   22.416768] XFS (dm-5): Mounting V4 Filesystem
[   22.534705] XFS (dm-5): Ending clean mount
---
^^/usr/share finished mounting...

[   22.558327] ixgbe 0000:05:00.1: irq 116 for MSI/MSI-X
[   23.663225] Adding 8393924k swap on /dev/sdc5.  Priority:-1 extents:1 
across:8393924k FS
Kernel logging (ksyslog) stopped.
Kernel log daemon terminating.
----
Note 'swap' was script numbered S13boot.swap

And different log format begins here... the early times OVERLAP
the later lines above

Boot logging started on /dev/tty1(/dev/console) at Mon Oct  6 14:18:20 2014
<notice -- Oct  6 14:18:20.580328000> service boot.usr-mount start
<notice -- Oct  6 14:18:20.588498000> service boot.assign_netif_names start
<notice -- Oct  6 14:18:20.589287000> service boot.cgroup start
<notice -- Oct  6 14:18:20.595436000> service boot.localnet start
<notice -- Oct  6 14:18:20.600526000> service boot.lvm start
<notice -- Oct  6 14:18:20.609959000> service boot.sysctl start
mounting cgroup file systems... cpuset cpu cpuacct memory devices freezer 
net_cls blkio net_prio debugdone
<notice -- Oct  6 14:18:20.718993000> service boot.cgroup done
Applying sysctl settings*
Setting up hostname 'Ishtar'done
Setting up NIS domainname 'sc.tlinx.org'done
Setting up loopback interface done
----
In local.mount below -- I mount most of these earlier along with /usr and /var

mount: devtmpfs is already mounted or /dev busy
       devtmpfs is already mounted on /dev
mount: proc is already mounted or /proc busy
       proc is already mounted on /proc
mount: sysfs is already mounted or /sys busy
       sysfs is already mounted on /sys
mount: devpts is already mounted or /dev/pts busy
       devpts is already mounted on /dev/pts
mount: /dev/sdc6 is already mounted or /usr busy
       /dev/sdc6 is already mounted on /usr
<notice -- Oct  6 14:18:20.785436000> service boot.sysctl done<notice -- Oct  6 
14:18:20.793997000> service boot.localnet done<notice -- Oct  6 
14:18:20.870962000> service boot.usr-mount done<notice -- Oct  6 
14:18:20.876027000> service boot.udev start
Starting udevd: done
Loading drivers, configuring devices: done
<notice -- Oct  6 14:18:21.83146000> service boot.udev done<notice -- Oct  6 
14:18:21.88975000> service boot.clock start


---Not until HERE does the assign netif names get started:


assign_netif_names=/etc/init.d/boot.assign_netif_names start
> > /etc/init.d/boot.assign_netif_names#208(read_actuals)> typeset -p act_hw2if
declare -A act_hw2if='()'
> > /etc/init.d/boot.assign_netif_names#209(read_actuals)> typeset -p act_if2hw
declare -A act_if2hw='()'
> > /etc/init.d/boot.assign_netif_names#210(read_actuals)> du -s /tmp /var/tmp
27776 /tmp
13156 /var/tmp
> > > /etc/init.d/boot.assign_netif_names#211(read_actuals)> date +%Y%m%d.%H%M
> > /etc/init.d/boot.assign_netif_names#211(read_actuals)> touch 
> > /tmp/boot-20141006.1418
> > /etc/init.d/boot.assign_netif_names#212(read_actuals)> ls -l 
> > /tmp/boot-20141006.1418
-rw-r--r-- 1 root root 0 Oct  6 14:18 /tmp/boot-20141006.1418
> > > /etc/init.d/boot.assign_netif_names#204(read_actuals)> get_net_IFnames_hwaddrs
> > > /etc/init.d/boot.assign_netif_names#185(get_net_IFnames_hwaddrs)> vrfy_drivers
> > > /etc/init.d/boot.assign_netif_names#171(vrfy_drivers)> declare -i errors=0
> > > /etc/init.d/boot.assign_netif_names#172(vrfy_drivers)> for i in 
> > > '${needed_drivers[@]}'
> > > /etc/init.d/boot.assign_netif_names#173(vrfy_drivers)> [[ ! -d 
> > > /sys/module/e1000e ]]
> > > /etc/init.d/boot.assign_netif_names#172(vrfy_drivers)> for i in 
> > > '${needed_drivers[@]}'
> > > /etc/init.d/boot.assign_netif_names#173(vrfy_drivers)> [[ ! -d /sys/module/bnx2 
> > > ]]
> > > /etc/init.d/boot.assign_netif_names#174(vrfy_drivers)> /sbin/modprobe bnx2
> > > /etc/init.d/boot.assign_netif_names#172(vrfy_drivers)> for i in 
> > > '${needed_drivers[@]}'
> > > /etc/init.d/boot.assign_netif_names#173(vrfy_drivers)> [[ ! -d 
> > > /sys/module/ixgbe ]]
> > > /etc/init.d/boot.assign_netif_names#174(vrfy_drivers)> /sbin/modprobe ixgbe
> > > /etc/init.d/boot.assign_netif_names#180(vrfy_drivers)> return 0
> > > /etc/init.d/boot.assign_netif_names#186(get_net_IFnames_hwaddrs)> 
> > > pseudo_devs=(br bond ifb team)
> > > /etc/init.d/boot.assign_netif_names#186(get_net_IFnames_hwaddrs)> declare -a 
> > > pseudo_devs
> > > /etc/init.d/boot.assign_netif_names#187(get_net_IFnames_hwaddrs)> declare 
> > > 'pseudo_RE=^+(br bond ifb team)$'
> > > /etc/init.d/boot.assign_netif_names#188(get_net_IFnames_hwaddrs)> 
> > > pseudo_RE='^+(br|bond|ifb|team)$'
> > > /etc/init.d/boot.assign_netif_names#189(get_net_IFnames_hwaddrs)> declare 
> > > 'netdev_pat=+([_0-9a-z])+([0-9])'
> > > /etc/init.d/boot.assign_netif_names#190(get_net_IFnames_hwaddrs)> cd 
> > > /sys/class/net
> > > > /etc/init.d/boot.assign_netif_names#184(get_net_IFnames_hwaddrs)> printf '%s\n' eth0 eth1 eth2 eth3 eth4 eth5 
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth0 
> > > 00:15:17:bf:be:b2
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth1 
> > > 00:15:17:bf:be:b3
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth2 
> > > 00:26:b9:48:71:e2
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth3 
> > > 00:26:b9:48:71:e4
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth4 
> > > a0:36:9f:15:c9:c0
> > > /etc/init.d/boot.assign_netif_names#191(get_net_IFnames_hwaddrs)> for nm in '$( printf 
> > > "%s\n" $netdev_pat)'
> > > /etc/init.d/boot.assign_netif_names#192(get_net_IFnames_hwaddrs)> [[ '' =~ nm ]]
> > > /etc/init.d/boot.assign_netif_names#193(get_net_IFnames_hwaddrs)> echo eth5 
> > > a0:36:9f:15:c9:c2
/etc/init.d/boot.assign_netif_names: line 204: cannot create temp file for 
here-document: No such file or directory
> > /etc/init.d/boot.assign_netif_names#221(read_actuals)> typeset -p act_hw2if
declare -A act_hw2if='()'
> > /etc/init.d/boot.assign_netif_names#222(read_actuals)> typeset -p act_if2hw
declare -A act_if2hw='()'
----
more errors after this because the tmp doc died.
will send this off... have another comment or two about some other
stuff... but wanted to send this off to help clarify any misunderstandings...