Support the Salticidae minimal C++ asynchronous network library (FIONBIO, TCP_NODELAY, and CLOCK_PROCESS_CPUTIME_ID) #1637
Description
Describe the issue
Dear developers,
I encountered a problem running an application that uses the Salticidae minimal C++ asynchronous network library, to be concrete tried simulating HotStuff, a blockchain consensus protocol. Unfortunately, it did not run out of the box, it seems some required functionality of the network library used by HotStuff does not go well yet, or is unsupported (?) in Shadow. Maybe you can help me to shed some light on the issue (I'm very interested if it can work now or in future):
The Shadow log basically warns because of an unsupported ioctl operation (I guess the the network library tries to open a socket?)
[syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 9 of type 6
Shadow.log
00:00:00.000001 [shadow] n/a [INFO] [n/a] [disable_aslr.c:14] [disable_aslr] ASLR disabled for processes forked from this parent process.
00:00:00.000023 [shadow] n/a [INFO] [n/a] [main.c:104] [_main_helper] Starting Shadow v2.0.0-pre.4-159-g2dbbeddc 2021-09-04--09:38:58 with GLib v2.64.6
00:00:00.000068 [shadow] n/a [INFO] [n/a] [main.c:111] [_main_helper] Shadow was built from branch main on 2021-09-07--16:16:32 in Release mode with compile options: -ggdb;-fno-omit-frame-pointer;-Wreturn-type;-Wswitch;-O3 and link options: -Wl,--no-as-needed
00:00:00.000069 [shadow] n/a [INFO] [n/a] [main.c:112] [_main_helper] For more information, visit https://shadow.github.io or https://github.com/shadow
00:00:00.000070 [shadow] n/a [INFO] [n/a] [main.c:113] [_main_helper] logging current startup arguments and environment
00:00:00.000081 [shadow] n/a [INFO] [n/a] [main.c:41] [_main_logEnvironment] arg: shadow
00:00:00.000081 [shadow] n/a [INFO] [n/a] [main.c:41] [_main_logEnvironment] arg: shadow.yaml
00:00:00.000084 [shadow] n/a [INFO] [n/a] [main.c:119] [_main_helper] startup checks passed, we are ready to start simulation
00:00:00.000085 [shadow] n/a [INFO] [n/a] [controller.c:103] [controller_new] simulation controller created
00:00:00.000086 [shadow] n/a [INFO] [n/a] [controller.c:422] [controller_run] loading and initializing simulation data
00:00:00.000301 [shadow] n/a [INFO] [n/a] [manager.c:204] [manager_new] found required preload library libshadow-shim.so at path /home/cb/.local/lib/libshadow-shim.so
00:00:00.000307 [shadow] n/a [INFO] [n/a] [manager.c:213] [manager_new] found optional preload library libshadow_openssl_rng.so at path /home/cb/.local/lib/libshadow_openssl_rng.so
00:00:00.000437 [shadow] n/a [INFO] [n/a] [scheduler.c:179] [scheduler_new] main scheduler thread will operate with 1 worker threads
00:00:00.000558 [shadow] n/a [INFO] [n/a] [controller.c:442] [controller_run] registering plugins and hosts
00:00:00.000572 [shadow] n/a [INFO] [n/a] [host.c:131] [host_new] Created host id '1' name 'replica0'
00:00:00.000669 [shadow] n/a [INFO] [n/a] [host.c:222] [host_setup] Setup host id '1' name 'replica0' with seed 1105148392, ip 11.0.0.1, 122070 bwUpKiBps, 122070 bwDownKiBps, 131072 initSockSendBufSize, 174760 initSockRecvBufSize, 4100000 cpuFrequency, 0 cpuThreshold, 200 cpuPrecision
00:00:00.001133 [shadow] n/a [INFO] [n/a] [controller.c:467] [controller_run] running simulation
00:00:00.001136 [shadow] n/a [INFO] [n/a] [controller.c:471] [controller_run] log message buffering is enabled for efficiency
00:00:00.001150 [worker-0] n/a [INFO] [n/a] [scheduler.c:70] [_scheduler_startHostsWorkerTaskFn] starting to boot 1 hosts
00:00:00.001168 [worker-0] 00:00:00.000000000 [INFO] [replica0:11.0.0.1] [tracker.c:430] [_tracker_logNode] [shadow-heartbeat] [node-header] interval-seconds,recv-bytes,send-bytes,cpu-percent,delayed-count,avgdelay-milliseconds;inbound-localhost-counters;outbound-localhost-counters;inbound-remote-counters;outbound-remote-counters where counters are: packets-total,bytes-total,packets-control,bytes-control-header,packets-control-retrans,bytes-control-header-retrans,packets-data,bytes-data-header,bytes-data-payload,packets-data-retrans,bytes-data-header-retrans,bytes-data-payload-retrans
00:00:00.001184 [worker-0] 00:00:00.000000000 [INFO] [replica0:11.0.0.1] [tracker.c:456] [_tracker_logNode] [shadow-heartbeat] [node] 1,0,0,0.000000,0,0.000000;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0
00:00:00.001195 [worker-0] n/a [INFO] [n/a] [scheduler.c:72] [_scheduler_startHostsWorkerTaskFn] 1 hosts are booted
00:00:00.001350 [worker-0] 00:00:01.000000000 [INFO] [replica0:11.0.0.1] [tracker.c:456] [_tracker_logNode] [shadow-heartbeat] [node] 1,0,0,0.000000,0,0.000000;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0
00:00:00.001366 [worker-0] 00:00:02.000000000 [INFO] [replica0:11.0.0.1] [tracker.c:456] [_tracker_logNode] [shadow-heartbeat] [node] 1,0,0,0.000000,0,0.000000;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0
00:00:00.001370 [shadow] n/a [INFO] [n/a] [manager.c:623] [_manager_heartbeat] process resource usage at simtime 2000000000 reported by getrusage(): ru_maxrss=0.151661 GiB, ru_utime=0.000000 minutes, ru_stime=0.000000 minutes, ru_nvcsw=34, ru_nivcsw=66
00:00:00.001553 [worker-0] 00:00:03.000000000 [INFO] [replica0:11.0.0.1] [process.c:497] [_process_start] starting process 'replica0.hotstuff-app.1000'
00:00:00.001566 [worker-0] 00:00:03.000000000 [INFO] [replica0:11.0.0.1] [thread_ptrace.c:722] [threadptrace_run] forking new thread with environment 'SHADOW_SPAWNED=TRUE SHADOW_LOG_START_TIME=2734310912 SHADOW_LOG_LEVEL=3 SHADOW_INTERPOSE_METHOD=PTRACE LD_PRELOAD=/home/cb/.local/lib/libshadow-shim.so:/home/cb/.local/lib/libshadow_openssl_rng.so SHADOW_LOG_FILE=/home/cb/git/libhotstuff/shadow.data/hosts/replica0/replica0.hotstuff-app.1000.shimlog SHADOW_SHM_BLK=8,134217728,24,/shadow_shmemfile_2734.312372823-8391', arguments '/home/cb/git/libhotstuff/examples/hotstuff-app --conf /home/cb/git/libhotstuff/hotstuff-sec0.conf', and working directory '/home/cb/git/libhotstuff'
00:00:00.001659 [worker-0] 00:00:03.000000000 [INFO] [replica0:11.0.0.1] [process.c:519] [_process_start] process 'replica0.hotstuff-app.1000' started
00:00:00.036667 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [time.c:109] [syscallhandler_clock_gettime] Unsupported clock ID 2 during gettime
00:00:00.036675 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [time.c:109] [syscallhandler_clock_gettime] Unsupported clock ID 2 during gettime
00:00:00.038571 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 9 of type 6
00:00:00.038675 [w```orker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 11 of type 6
00:00:00.038732 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 10 of type 6
00:00:00.038786 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 16 of type 6
00:00:00.044346 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 25 of type 6
00:00:00.044426 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 26 of type 6
00:00:00.044535 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 17 of type 6
00:00:00.047835 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [ioctl.c:204] [syscallhandler_ioctl] We do not support ioctl request 21537 on descriptor 18 of type 6
00:00:00.052346 [worker-0] 00:00:03.000000000 [INFO] [replica0:11.0.0.1] [tracker.c:456] [_tracker_logNode] [shadow-heartbeat] [node] 1,0,0,0.000000,0,0.000000;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0;0,0,0,0,0,0,0,0,0,0,0,0
00:00:00.052564 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [socket.c:1157] [syscallhandler_setsockopt] setsockopt called with unsupported level 6
00:00:00.052950 [worker-0] 00:00:03.000000000 [WARN] [replica0:11.0.0.1] [thread_ptrace.c:489] [_threadptrace_enterStateSignalled] Delivering signal 6
Meanwhile, the output of the Hotstuff process is just the following error:
replica0.hotstuff-app.1000.stderr
2000-01-01 00:00:03.000000 [net info] loaded configuration from hotstuff.conf
2000-01-01 00:00:03.000000 [net info] loading extra configuration from /home/cb/git/libhotstuff/hotstuff-sec0.conf
2000-01-01 00:00:03.000000 [net info] starting all threads...
terminate called after throwing an instance of 'salticidae::ConnPoolError'
what(): unable to listen: Protocol not available
The protocol not available error is actually thrown by the libuv used by Salticidae.
To Reproduce
I used a simple shadow.yaml for my test:
general:
# stop after 10 simulated seconds
stop_time: 10s
network:
graph:
# use a built-in network graph containing
# a single vertex with a bandwidth of 1 Gbit
type: 1_gbit_switch
experimental:
use_legacy_working_dir: true
host_defaults:
pcap_directory: .
hosts:
# a host with the hostname 'server'
replica0:
network_node_id: 0
processes:
- path: /home/cb/git/libhotstuff/examples/hotstuff-app
args: "--conf /home/cb/git/libhotstuff/hotstuff-sec0.conf"
start_time: 3s
Operating System (please complete the following information):
Ubuntu 20.04
Shadow (please complete the following information):
- Version: Shadow v2.0.0-pre.4-159-g2dbbeddc 2021-09-04--09:38:58
Does someone have a clue what could be the issue here? Is ist maybe the missing (?) IPv6 functionality or something related to SSL ?