search

bstansell / conserver

Logged, multi-user access to device consoles
https://www.conserver.com/
BSD 3-Clause "New" or "Revised" License
130 stars 38 forks source link

Intermittent error message with server-side tasks #38

Closed Yneeb closed 4 years ago

Yneeb commented 4 years ago

A basic configuration with a simple task will cause the server to emit the following error message about 50-80% of the time the task is run:

[Wed Apr 29 02:00:24 2020] conserver (1086): ERROR: FileRead(): fd 7: Input/output error

I'm using the 8.2.3 version distributed by Gentoo. I don't think there's anything in 8.2.4 that would fix this, but I can give it a try if necessary. I can reliably reproduce this issue by running the task a few times with the following configuration:

access * {
        trusted localhost;
}

console 1 {
        rw *;
        type device;
        parity none;
        device /dev/ttyS55;
        baud 9600;
        master localhost;
        logfile /tmp/&.log;
        logfilemax 4m;
        tasklist c;
}

task c {
        cmd "/bin/true";
}

The entire output from the server:

[Wed Apr 29 02:00:04 2020] conserver (1085): conserver.com version 8.2.3
[Wed Apr 29 02:00:04 2020] conserver (1085): started as `root' by `root'
[Wed Apr 29 02:00:07 2020] conserver (1086): [1] login root@localhost
[Wed Apr 29 02:00:24 2020] conserver (1086): [1] task started: pid 1095
[Wed Apr 29 02:00:24 2020] conserver (1086): ERROR: FileRead(): fd 7: Input/output error
[Wed Apr 29 02:00:24 2020] conserver (1086): [1] task terminated: pid 1095: exit(0)
[Wed Apr 29 02:03:33 2020] conserver (1086): [1] logout root@localhost

I believe that fd 7 refers to /dev/ptmx in this situation, but I'm not sure how to debug this issue past that. Let me know if I can provide any more information.

conserver commented 4 years ago

I haven't been able to reproduce this exact issue (yet, mainly from a lack of a similar setup, I believe), but I am seeing one weird thing I need to track down, which might be related. Can you post the output of conserver -V as well? It wouldn't hurt to have the debug output, if possible, also. If you add a -DD when running conserver and reproduce the problem, that might allow me to see what's happening without a setup on my end (feel free to email bryan@conserver.com as it'll be chatty). We'll see a lot of the lower-level activity, some file descriptor info, etc.

Yneeb commented 4 years ago

This is the output from conserver -V:

conserver: conserver.com version 8.2.3
conserver: default access type `r'
conserver: default escape sequence `^Ec'
conserver: default configuration in `/etc/conserver/conserver.cf'
conserver: default password in `/etc/conserver/conserver.passwd'
conserver: default logfile is `/var/log/conserver.log'
conserver: default pidfile is `/run/conserver.pid'
conserver: default limit is 16 members per group
conserver: default socket directory `/run/conserver'
conserver: options: pam, uds
conserver: built with `./configure --prefix=/usr --build=i486-pc-linux-gnu --host=i486-pc-linux-gnu --mandir=/usr/share/man --infodir=/usr/share/info --datadir=/usr/share --sysconfdir=/etc --localstatedir=/var/lib --docdir=/usr/share/doc/conserver-8.2.3 --htmldir=/usr/share/doc/conserver-8.2.3/html --libdir=/usr/lib --without-dmalloc --without-ipv6 --without-freeipmi --without-gssapi --without-openssl --with-pam --without-libwrap --with-cffile=conserver/conserver.cf --with-logfile=/var/log/conserver.log --with-master=localhost --with-pidfile=/run/conserver.pid --with-port=7782 --with-pwdfile=conserver/conserver.passwd --with-uds=/run/conserver'

This should be all of the output from running conserver -DD with my example configuration:

Click to expand ``` [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600390 created string #1 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600540 created string #2 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600560 created string #3 [Thu Apr 30 00:30:20 2020] conserver (1675): conserver.com version 8.2.3 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ac0 created string #4 [Thu Apr 30 00:30:20 2020] conserver (1675): started as `root' by `root' [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:1918] ProbeInterfaces(): ifc_len==64 max_count==2 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:1973] ProbeInterfaces(): name=lo addr=127.0.0.1 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:1973] ProbeInterfaces(): name=enp0s9 addr=192.168.10.194 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600b80 created string #5 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ba0 created string #6 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600bc0 created string #7 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600be0 created string #8 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600c00 created string #9 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600c20 created string #10 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600c40 created string #11 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600c60 created string #12 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600c80 created string #13 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ca0 created string #14 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600cc0 created string #15 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ce0 created string #16 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600d00 created string #17 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600d20 created string #18 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600d40 created string #19 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600d60 created string #20 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600d80 created string #21 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600da0 created string #22 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600dc0 created string #23 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600de0 created string #24 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600e00 created string #25 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600e20 created string #26 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600e40 created string #27 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600e60 created string #28 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600e80 created string #29 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ea0 created string #30 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ec0 created string #31 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600ee0 created string #32 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600f00 created string #33 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600f20 created string #34 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600f40 created string #35 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600f60 created string #36 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600f80 created string #37 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600fa0 created string #38 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1600fc0 created string #39 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1601170 created string #40 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2599] ReadCfg(): got keyword 'access' [/etc/conserver/conserver.cf:1] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3964] AccessBegin(*) [/etc/conserver/conserver.cf:1] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1601200 created string #41 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'trusted' [/etc/conserver/conserver.cf:1] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4271] AccessItemTrusted(localhost) [/etc/conserver/conserver.cf:2] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3985] AccessEnd() [/etc/conserver/conserver.cf:2] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2599] ReadCfg(): got keyword 'console' [/etc/conserver/conserver.cf:3] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:2391] ConsoleBegin(1) [/etc/conserver/conserver.cf:5] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'rw' [/etc/conserver/conserver.cf:5] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3850] ConsoleItemRw(*) [/etc/conserver/conserver.cf:6] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:2160] ProcessRoRw(*) [/etc/conserver/conserver.cf:6] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'type' [/etc/conserver/conserver.cf:6] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3864] ConsoleItemType(device) [/etc/conserver/conserver.cf:7] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'parity' [/etc/conserver/conserver.cf:7] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3757] ConsoleItemParity(none) [/etc/conserver/conserver.cf:8] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'device' [/etc/conserver/conserver.cf:8] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3588] ConsoleItemDevice(/dev/ttyS55) [/etc/conserver/conserver.cf:9] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'baud' [/etc/conserver/conserver.cf:9] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3574] ConsoleItemBaud(9600) [/etc/conserver/conserver.cf:10] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'master' [/etc/conserver/conserver.cf:10] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3743] ConsoleItemMaster(localhost) [/etc/conserver/conserver.cf:11] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'logfile' [/etc/conserver/conserver.cf:11] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3708] ConsoleItemLogfile(/tmp/&.log) [/etc/conserver/conserver.cf:12] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'logfilemax' [/etc/conserver/conserver.cf:12] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3715] ConsoleItemLogfilemax(4m) [/etc/conserver/conserver.cf:13] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'tasklist' [/etc/conserver/conserver.cf:13] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3822] ConsoleItemTasklist(c) [/etc/conserver/conserver.cf:14] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:2040] ProcessTasklist(c) [/etc/conserver/conserver.cf:14] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604050 created string #42 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:2455] ConsoleEnd() [/etc/conserver/conserver.cf:14] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2599] ReadCfg(): got keyword 'task' [/etc/conserver/conserver.cf:15] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4714] TaskBegin(c) [/etc/conserver/conserver.cf:17] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x16040f0 created string #43 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604110 created string #44 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:2682] got keyword 'cmd' [/etc/conserver/conserver.cf:17] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4812] TaskItemCmd(/bin/true) [/etc/conserver/conserver.cf:18] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4747] TaskEnd() [/etc/conserver/conserver.cf:18] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4784] TaskDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:259] BreakDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:423] GroupDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:861] DefaultDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3185] ConsoleDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604940 created string #45 [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4023] AccessDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4060] AccessDestroy(): adding ACL `*' [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1601200 string destroyed (count==44) [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:3920] DestroyParserAccess(): * [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [readcfg.c:4422] ConfigDestroy() [/etc/conserver/conserver.cf:19] [Thu Apr 30 00:30:20 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604990 created string #45 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604c90 created string #46 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:775] FileOpen(): opened `/tmp/1.log' as fd 4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604cb0 created string #47 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[-- ' to fd 4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `Console up' to fd 4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:1021] FileWrite(): sending ` -- Thu Apr 30 00:30:20 2020]^M'... to fd 4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 45 bytes to fd 4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604da0 created string #48 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] FileOpenFD(): encapsulated fd 5 type 0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_iflag=5122 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_oflag=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cflag=2237 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_lflag=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[0]=3 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[1]=28 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[2]=127 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[3]=21 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[4]=4 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[5]=1 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[6]=1 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[7]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[8]=17 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[9]=19 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[10]=26 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[11]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[12]=18 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[13]=15 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[14]=23 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[15]=22 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[16]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[17]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[18]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[19]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[20]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[21]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[22]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[23]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[24]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[25]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[26]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[27]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[28]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[29]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[30]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:639] TtyDev(): [1] termp.c_cc[31]=0 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604e50 created string #49 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604e70 created string #50 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604e90 created string #51 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604eb0 created string #52 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604ed0 created string #53 [Thu Apr 30 00:30:20 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 60 seconds [Thu Apr 30 00:30:21 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604a90 created string #46 [Thu Apr 30 00:30:21 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604ab0 created string #47 [Thu Apr 30 00:30:21 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604ad0 created string #48 [Thu Apr 30 00:30:21 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604af0 created string #49 [Thu Apr 30 00:30:21 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604b10 created string #50 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604bb0 created string #51 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:639] FileOpenFD(): encapsulated fd 4 type 1 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604c60 created string #52 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604c80 created string #53 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604ca0 created string #54 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1604cc0 created string #55 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [access.c:144] AccType(): ip=127.0.0.1 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [access.c:219] AccType(): who=localhost, trust=t [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [access.c:238] AccType(): addr=127.0.0.1 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1605170 created string #56 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1025] FileWrite(): sending `ok^M^J' to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1187] FileWrite(): wrote 4 bytes to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:961] FileRead(): read 12 bytes from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:299] AllocString(): 0x1605230 created string #57 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:974] FileRead(): read `login root^M^J' from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1025] FileWrite(): sending `ok^M^J' to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1187] FileWrite(): wrote 4 bytes to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:961] FileRead(): read 8 bytes from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:974] FileRead(): read `call 1^M^J' from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1025] FileWrite(): sending `1^M^J' to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1187] FileWrite(): wrote 3 bytes to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:961] FileRead(): read 6 bytes from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:974] FileRead(): read `exit^M^J' from fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1025] FileWrite(): sending `goodbye^M^J' to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:1187] FileWrite(): wrote 9 bytes to fd 4 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1604f70 created string #54 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:639] FileOpenFD(): encapsulated fd 6 type 1 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:861] FileClose(): closed fd 4 [Thu Apr 30 00:30:24 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604bb0 string destroyed (count==56) [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x16050c0 created string #55 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x16050e0 created string #56 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605100 created string #57 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605120 created string #58 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [access.c:144] AccType(): ip=127.0.0.1 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [access.c:219] AccType(): who=localhost, trust=t [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [access.c:238] AccType(): addr=127.0.0.1 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `ok^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 4 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:5014] Kiddie(): client acid initialized to `@localhost' [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605620 created string #59 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605640 created string #60 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605660 created string #61 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 12 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605680 created string #62 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `login root^M^J' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 7 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `ok^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 4 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 8 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `call 1^M^J' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:3005] state = 0 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:450] ClientAccess(): Authenticating user root [Thu Apr 30 00:30:24 2020] conserver (1676): [1] login root@localhost [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[attached]^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 12 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 3 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^Ec=' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `up]^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 5 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 3 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^EcM-V' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `8002003]^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 10 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 3 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^Ecm' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `-- MOTD --]^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 13 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 3 bytes from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^Ec;' from fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `connected]^M^J' to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 12 bytes to fd 6 [Thu Apr 30 00:30:24 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 56 seconds [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^E' from fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 54 seconds [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `c' from fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:26 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 54 seconds [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `!' from fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `task ' to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 5 bytes to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 52 seconds [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `c' from fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1605740 created string #63 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:299] AllocString(): 0x1606840 created string #64 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:639] FileOpenFD(): encapsulated fd 7 type 0 [Thu Apr 30 00:30:28 2020] conserver (1676): [1] task started: pid 1688 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending ``c' started]^M^J' to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 14 bytes to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 52 seconds [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 96 bytes from fd 7 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:970] FileRead(): read `[Thu Apr 30 00:30:28 2020] con'... from fd 7 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [group.c:2794] DoTaskRead(): read 96 bytes from fd 7 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1021] FileWrite(): sending `[Thu Apr 30 00:30:28 2020] con'... to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 96 bytes to fd 6 [Thu Apr 30 00:30:28 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 52 seconds [Thu Apr 30 00:30:29 2020] conserver (1676): ERROR: FileRead(): fd 7: Input/output error [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [cutil.c:979] FileRead(): failed attempted read of 8192 bytes from fd 7 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [group.c:2790] DoTaskRead(): got -1 bytes from fd 7 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [group.c:180] StopTask(): sending task pid 1688 signal 1 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [cutil.c:861] FileClose(): closed fd 7 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1606840 string destroyed (count==63) [Thu Apr 30 00:30:29 2020] conserver (1676): [1] task terminated: pid 1688: exit(0) [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[task terminated: exit(0)]^M^J' to fd 6 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 28 bytes to fd 6 [Thu Apr 30 00:30:29 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 51 seconds [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `^E' from fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 44 seconds [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `c' from fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[' to fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 1 byte to fd 6 [Thu Apr 30 00:30:36 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 44 seconds [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:961] FileRead(): read 1 byte from fd 6 [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:974] FileRead(): read `.' from fd 6 [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `disconnect]^M^J' to fd 6 [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 13 bytes to fd 6 [Thu Apr 30 00:30:37 2020] conserver (1676): [1] logout root@localhost [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:861] FileClose(): closed fd 6 [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604f70 string destroyed (count==62) [Thu Apr 30 00:30:37 2020] conserver (1676): DEBUG: [group.c:4639] Kiddie(): select timeout of 43 seconds [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604af0 string destroyed (count==55) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604ab0 string destroyed (count==54) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604a90 string destroyed (count==53) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604ad0 string destroyed (count==52) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:861] FileClose(): closed fd 5 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604da0 string destroyed (count==61) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604cc0 string destroyed (count==51) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604c80 string destroyed (count==50) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604c60 string destroyed (count==49) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `[-- ' to fd 4 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:1025] FileWrite(): sending `Console down' to fd 4 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604ca0 string destroyed (count==48) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:1021] FileWrite(): sending ` -- Thu Apr 30 00:30:39 2020]^M'... to fd 4 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:1187] FileWrite(): wrote 47 bytes to fd 4 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [master.c:183] SignalKids(): sending pid 1676 signal 15 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:814] Memory Usage (GRPENT objects): 36 (1) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:880] Memory Usage (CONSENT objects): 628 (1) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:894] Memory Usage (REMOTE objects): 0 (0) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:861] FileClose(): closed fd 4 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604c90 string destroyed (count==60) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:901] Memory Usage (ACCESS objects): 25 (1) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:908] Memory Usage (STRING objects): 1920 (48) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:814] Memory Usage (GRPENT objects): 36 (1) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:880] Memory Usage (CONSENT objects): 628 (1) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:894] Memory Usage (REMOTE objects): 0 (0) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:901] Memory Usage (ACCESS objects): 25 (1) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:915] Memory Usage (userList objects): 9 (1) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:919] Memory Usage (total): 2618 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:948] DumpDataStructures(): group: id=1 port=1, pid=1676, imembers=1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:908] Memory Usage (STRING objects): 2480 (60) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:915] Memory Usage (userList objects): 9 (1) [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:919] Memory Usage (total): 3178 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:948] DumpDataStructures(): group: id=1 port=1, pid=1676, imembers=1 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:956] DumpDataStructures(): server=1, type=DEVICE [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:959] DumpDataStructures(): baud=9600, parity=none, device=/dev/ttyS55 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1033] DumpDataStructures(): fup=0, fronly=0, logfile=/tmp/1.log, breakNum=1 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1037] DumpDataStructures(): mark=0, nextMark=0, autoReup=0, downHard=unset [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:956] DumpDataStructures(): server=1, type=DEVICE [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:959] DumpDataStructures(): baud=9600, parity=none, device=/dev/ttyS55 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1041] DumpDataStructures(): nolog=0, cofile=-1, activitylog=false, breaklog=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1045] DumpDataStructures(): tasklog=false, ixon=true, ixany=false, ixoff=true [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1033] DumpDataStructures(): fup=0, fronly=0, logfile=/tmp/1.log, breakNum=1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1037] DumpDataStructures(): mark=0, nextMark=0, autoReup=0, downHard=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1041] DumpDataStructures(): nolog=0, cofile=-1, activitylog=false, breaklog=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1049] DumpDataStructures(): autoreinit=true, hupcl=false, cstopb=false, ondemand=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1054] DumpDataStructures(): crtscts=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1057] DumpDataStructures(): reinitoncc=false, striphigh=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1060] DumpDataStructures(): unloved=false, login=true [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1062] DumpDataStructures(): initpid=0, initcmd=(null), initfile=-1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1045] DumpDataStructures(): tasklog=false, ixon=true, ixany=false, ixoff=true [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1049] DumpDataStructures(): autoreinit=true, hupcl=false, cstopb=false, ondemand=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1054] DumpDataStructures(): crtscts=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1066] DumpDataStructures(): inituid=0, initgid=0 [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1068] DumpDataStructures(): motd=(null), idletimeout=0, idlestring=\n, replstring=(null) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1073] DumpDataStructures(): tasklist=c, breaklist=*, taskpid=0, taskfile=-1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1057] DumpDataStructures(): reinitoncc=false, striphigh=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1060] DumpDataStructures(): unloved=false, login=true [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1062] DumpDataStructures(): initpid=0, initcmd=(null), initfile=-1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1066] DumpDataStructures(): inituid=0, initgid=0 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1068] DumpDataStructures(): motd=(null), idletimeout=0, idlestring=\n, replstring=(null) [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1088] DumpDataStructures(): rw=* [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1073] DumpDataStructures(): tasklist=c, breaklist=*, taskpid=0, taskfile=-1 [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1088] DumpDataStructures(): rw=* [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1092] DumpDataStructures(): ------ [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #1, string=\z, delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1092] DumpDataStructures(): ------ [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #1, string=\z, delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #2, string=\r~^b, delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #3, string=#., delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #2, string=\r~^b, delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #3, string=#., delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #4, string=\r\d~\d^b, delay=600, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #5, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #4, string=\r\d~\d^b, delay=600, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #6, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #7, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #8, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #5, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #6, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:39 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #7, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #9, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #a, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #b, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #c, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #8, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #9, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #a, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #d, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #e, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #f, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #b, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #c, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #d, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #g, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #h, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #i, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #e, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #f, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #g, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #j, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #k, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #l, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #h, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #i, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #m, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #n, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #j, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #o, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #k, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #l, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #m, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #p, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #q, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #r, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #n, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #o, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #p, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #s, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #t, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #q, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #r, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #u, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #s, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #t, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #v, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #u, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #v, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #w, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #w, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #x, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #y, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #x, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #y, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1106] DumpDataStructures(): break: #z, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [main.c:1113] DumpDataStructures(): task: id=c, cmd=/bin/true, descr=(null), uid=0, gid=0, subst=(null), confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1106] DumpDataStructures(): break: #z, string=(null), delay=250, confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [main.c:1113] DumpDataStructures(): task: id=c, cmd=/bin/true, descr=(null), uid=0, gid=0, subst=(null), confirm=false [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [group.c:609] DestroyGroup(): destroying group #1 (1 members) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [group.c:496] DestroyConsent(): destroying `ctl_1' [Thu Apr 30 00:30:40 2020] conserver (1675): terminated [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [group.c:609] DestroyGroup(): destroying group #1 (1 members) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [group.c:496] DestroyConsent(): destroying `1' [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [group.c:496] DestroyConsent(): destroying `1' [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604940 string destroyed (count==59) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604940 string destroyed (count==47) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600b80 string destroyed (count==46) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ba0 string destroyed (count==45) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600bc0 string destroyed (count==44) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604e50 string destroyed (count==58) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604e90 string destroyed (count==57) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604eb0 string destroyed (count==56) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600be0 string destroyed (count==43) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600c00 string destroyed (count==42) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604e70 string destroyed (count==55) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x16050c0 string destroyed (count==54) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605100 string destroyed (count==53) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605120 string destroyed (count==52) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600c20 string destroyed (count==41) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600c40 string destroyed (count==40) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600c60 string destroyed (count==39) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x16050e0 string destroyed (count==51) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600b80 string destroyed (count==50) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ba0 string destroyed (count==49) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600c80 string destroyed (count==38) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ca0 string destroyed (count==37) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600bc0 string destroyed (count==48) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600be0 string destroyed (count==47) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600c00 string destroyed (count==46) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600c20 string destroyed (count==45) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600cc0 string destroyed (count==36) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ce0 string destroyed (count==35) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600d00 string destroyed (count==34) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600c40 string destroyed (count==44) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600c60 string destroyed (count==43) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600d20 string destroyed (count==33) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600d40 string destroyed (count==32) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600d60 string destroyed (count==31) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600d80 string destroyed (count==30) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600c80 string destroyed (count==42) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ca0 string destroyed (count==41) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600cc0 string destroyed (count==40) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600da0 string destroyed (count==29) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600dc0 string destroyed (count==28) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ce0 string destroyed (count==39) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600d00 string destroyed (count==38) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600d20 string destroyed (count==37) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600de0 string destroyed (count==27) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600e00 string destroyed (count==26) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600e20 string destroyed (count==25) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600e40 string destroyed (count==24) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600d40 string destroyed (count==36) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600d60 string destroyed (count==35) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600e60 string destroyed (count==23) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600e80 string destroyed (count==22) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ea0 string destroyed (count==21) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600d80 string destroyed (count==34) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600da0 string destroyed (count==33) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600dc0 string destroyed (count==32) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600de0 string destroyed (count==31) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ec0 string destroyed (count==20) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ee0 string destroyed (count==19) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600f00 string destroyed (count==18) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600e00 string destroyed (count==30) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600e20 string destroyed (count==29) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600f20 string destroyed (count==17) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600e40 string destroyed (count==28) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600e60 string destroyed (count==27) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600e80 string destroyed (count==26) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600f40 string destroyed (count==16) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600f60 string destroyed (count==15) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600f80 string destroyed (count==14) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600fa0 string destroyed (count==13) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ea0 string destroyed (count==25) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ec0 string destroyed (count==24) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600fc0 string destroyed (count==12) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x16040f0 string destroyed (count==11) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604110 string destroyed (count==10) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ee0 string destroyed (count==23) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600f00 string destroyed (count==22) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600f20 string destroyed (count==21) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1605230 string destroyed (count==9) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1605170 string destroyed (count==8) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604b10 string destroyed (count==7) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600f40 string destroyed (count==20) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600f60 string destroyed (count==19) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600f80 string destroyed (count==18) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604990 string destroyed (count==6) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1604050 string destroyed (count==5) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600fa0 string destroyed (count==17) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600fc0 string destroyed (count==16) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x16040f0 string destroyed (count==15) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604110 string destroyed (count==14) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1601170 string destroyed (count==4) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600ac0 string destroyed (count==3) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600560 string destroyed (count==2) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605740 string destroyed (count==13) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605680 string destroyed (count==12) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600540 string destroyed (count==1) [Thu Apr 30 00:30:40 2020] conserver (1675): DEBUG: [cutil.c:276] DestroyString(): 0x1600390 string destroyed (count==0) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605660 string destroyed (count==11) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605640 string destroyed (count==10) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1605620 string destroyed (count==9) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604ed0 string destroyed (count==8) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604cb0 string destroyed (count==7) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604990 string destroyed (count==6) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1604050 string destroyed (count==5) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1601170 string destroyed (count==4) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600ac0 string destroyed (count==3) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600560 string destroyed (count==2) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600540 string destroyed (count==1) [Thu Apr 30 00:30:40 2020] conserver (1676): DEBUG: [cutil.c:276] DestroyString(): 0x1600390 string destroyed (count==0) ```

One other piece of information that may be useful is that I'm running this on a very slow machine. It just has a 133 Mhz single-core processor. Maybe it's some sort of race condition issue that doesn't show up on faster machines? I'll see if I can replicate this on some faster hardware.

Yneeb commented 4 years ago

One other piece of information that may be useful is that I'm running this on a very slow machine. It just has a 133 Mhz single-core processor. Maybe it's some sort of race condition issue that doesn't show up on faster machines? I'll see if I can replicate this on some faster hardware.

It seems that my theory was wrong. I gave this a try on a four-core 3.4 Ghz machine and saw the exact same issue. Let me know if there's anything else you'd like me to try.

conserver commented 4 years ago

Thanks for the info - it helped. I was also able to replicate the issue and dug out the missing piece (process exiting and causing read to return something that wasn't being caught). A quick fix for the situation:

diff --git a/conserver/cutil.c b/conserver/cutil.c
index 24ce826..4a4defe 100644
--- a/conserver/cutil.c
+++ b/conserver/cutil.c
@@ -890,7 +890,7 @@ FileRead(CONSFILE *cfp, void *buf, int len)
        case simpleSocket:
            while (retval < 0) {
                if ((retval = read(cfp->fd, buf, len)) <= 0) {
-                   if (retval == 0) {
+                   if (retval == 0 || errno == EIO) {
                        retval = -1;
                        break;
                    }

I'm not 100% sure that's the right solution, but it will do the job for now. I might come up with a more creative long-term fix (or not).

conserver commented 4 years ago

So, yeah, after more thought, the above will do. It's basically just preventing the error message - there's no functional change.

Yneeb commented 4 years ago

I gave 02d0c15a77210f8636f51168444d4003148bea54 a try on my setup, and it appears to be working correctly. Thanks!