search

nanovms / nanos

A kernel designed to run one and only one application in a virtualized environment
https://nanos.org
Apache License 2.0
2.64k stars 137 forks source link

issue(smp): tokio-rs/sled deadlock (probable) on cpu count > 1 #1930

Closed rinor closed 1 year ago

rinor commented 1 year ago

As an example OpenObserve can't boot properly on cpu count > 1 (it keeps all vCpu cores/threads at 100%).

Tested also some internal programs that use similar tech stack (tokio, sled, ..) and the behavior is the same.

Will investigate further and provide more info when/if available.

ops commands and config - **create volume** ```sh $ ops volume create nanos-openobserve-data -s 1G ``` - **ops config.json** ```json { "BaseVolumeSz": "128M", "Mounts": { "nanos-openobserve-data": "data" }, "Dirs": [ "proc" ], "Klibs": [ "special_files" ], "ManifestPassthrough": { "special_files": { "disks": {} } }, "Env": { "__pyroscope__": "", "ZO_PROF_PYROSCOPE_SERVER_URL": "http://localhost:4040", "ZO_PROF_PYROSCOPE_PROJECT_NAME": "openobserve", "__auth__": "", "ZO_ROOT_USER_EMAIL": "test@test.io", "ZO_ROOT_USER_PASSWORD": "test@test.io", "__http__": "", "ZO_HTTP_PORT": "5080", "ZO_HTTP_ADDR": "", "ZO_HTTP_IPV6_ENABLED": "false", "__grpc__": "", "ZO_GRPC_PORT": "5081", "ZO_GRPC_ADDR": "", "ZO_GRPC_TIMEOUT": "600", "ZO_GRPC_ORG_HEADER_KEY": "openobserve-org-id", "ZO_INTERNAL_GRPC_TOKEN": "", "__tcp__": "", "ZO_TCP_PORT": "5514", "ZO_UDP_PORT": "5514", "__route__": "", "ZO_ROUTE_TIMEOUT": "600", "__common__": "", "ZO_LOCAL_MODE": "true", "ZO_LOCAL_MODE_STORAGE": "disk", "ZO_NODE_ROLE": "all", "ZO_CLUSTER_NAME": "zo1", "ZO_INSTANCE_NAME": "", "ZO_DATA_DIR": "./data/openobserve/", "ZO_DATA_WAL_DIR": "./data/openobserve/wal/", "ZO_DATA_STREAM_DIR": "./data/openobserve/stream/", "ZO_BASE_URI": "", "ZO_WAL_MEMORY_MODE_ENABLED": "false", "ZO_WAL_LINE_MODE_ENABLED": "true", "ZO_PARQUET_COMPRESSION": "zstd", "ZO_COLUMN_TIMESTAMP": "_timestamp", "ZO_WIDENING_SCHEMA_EVOLUTION": "false", "ZO_SKIP_SCHEMA_VALIDATION": "false", "ZO_FEATURE_PER_THREAD_LOCK": "false", "ZO_FEATURE_FULLTEXT_ON_ALL_FIELDS": "false", "ZO_UI_ENABLED": "true", "ZO_UI_SQL_BASE64_ENABLED": "false", "ZO_METRICS_DEDUP_ENABLED": "true", "ZO_TRACING_ENABLED": "false", "OTEL_OTLP_HTTP_ENDPOINT": "", "ZO_TRACING_HEADER_KEY": "Authorization", "ZO_TRACING_HEADER_VALUE": "Basic YWRtaW46Q29tcGxleHBhc3MjMTIz", "ZO_TELEMETRY": "false", "ZO_TELEMETRY_URL": "https://e1.zinclabs.dev", "ZO_PROMETHEUS_ENABLED": "false", "ZO_PRINT_KEY_CONFIG": "false", "ZO_PRINT_KEY_SQL": "false", "ZO_USAGE_REPORTING_ENABLED": "false", "ZO_USAGE_REPORTING_COMPRESSED_SIZE": "false", "ZO_USAGE_ORG": "_meta", "ZO_USAGE_BATCH_SIZE": "2000", "ZO_DYNAMO_META_STORE_ENABLED": "false", "ZO_DYNAMO_FILE_LIST_TABLE": "", "__limit__": "", "ZO_JSON_LIMIT": "209715200", "ZO_PAYLOAD_LIMIT": "209715200", "ZO_MAX_FILE_SIZE_ON_DISK": "32", "ZO_MAX_FILE_RETENTION_TIME": "600", "ZO_FILE_PUSH_INTERVAL": "60", "ZO_FILE_MOVE_THREAD_NUM": "0", "ZO_QUERY_THREAD_NUM": "0", "ZO_INGEST_ALLOWED_UPTO": "5", "ZO_METRICS_LEADER_PUSH_INTERVAL": "15", "ZO_METRICS_LEADER_ELECTION_INTERVAL": "30", "ZO_METRICS_FILE_RETENTION": "daily", "ZO_HEARTBEAT_INTERVAL": "30", "ZO_COLS_PER_RECORD_LIMIT": "0", "ZO_HTTP_WORKER_NUM": "0", "ZO_CALCULATE_STATS_INTERVAL": "600", "__compact__": "", "ZO_COMPACT_ENABLED": "true", "ZO_COMPACT_FAKE_MODE": "false", "ZO_COMPACT_INTERVAL": "60", "ZO_COMPACT_SYNC_TO_DB_INTERVAL": "1800", "ZO_COMPACT_MAX_FILE_SIZE": "256", "ZO_COMPACT_DATA_RETENTION_DAYS": "3650", "ZO_COMPACT_BLOCKED_ORGS": "", "__memorycache__": "", "ZO_MEMORY_CACHE_ENABLED": "true", "ZO_MEMORY_CACHE_CACHE_LATEST_FILES": "false", "ZO_MEMORY_CACHE_MAX_SIZE": "0", "ZO_MEMORY_CACHE_SKIP_SIZE": "0", "ZO_MEMORY_CACHE_RELEASE_SIZE": "0", "__log__": "", "RUST_LOG": "debug", "EVENTS_ENABLED": "false", "EVENTS_AUTH": "cm9vdEBleGFtcGxlLmNvbTpUZ0ZzZFpzTUZQdzg2SzRK", "EVENTS_EP": "https://api.openobserve.ai/api/debug/events/_json", "EVENTS_BATCH_SIZE": "10", "__etcd__": "", "ZO_ETCD_ADDR": "localhost:2379", "ZO_ETCD_PREFIX": "/data/openobserve/etcd_prefix/", "ZO_ETCD_CONNECT_TIMEOUT": "5", "ZO_ETCD_COMMAND_TIMEOUT": "10", "ZO_ETCD_LOCK_WAIT_TIMEOUT": "3600", "ZO_ETCD_USER": "", "ZO_ETCD_PASSWORD": "", "ZO_ETCD_CLIENT_CERT_AUTH": "false", "ZO_ETCD_TRUSTED_CA_FILE": "", "ZO_ETCD_CERT_FILE": "", "ZO_ETCD_KEY_FILE": "", "ZO_ETCD_DOMAIN_NAME": "", "ZO_ETCD_LOAD_PAGE_SIZE": "1000", "__sled__": "", "ZO_SLED_DATA_DIR": "/data/openobserve/sled_data/", "ZO_SLED_PREFIX": "/data/openobserve/sled_prefix/", "__s3__": "", "ZO_S3_PROVIDER": "s3", "ZO_S3_SERVER_URL": "", "ZO_S3_REGION_NAME": "", "ZO_S3_ACCESS_KEY": "", "ZO_S3_SECRET_KEY": "", "ZO_S3_BUCKET_NAME": "", "ZO_S3_BUCKET_PREFIX": "", "ZO_S3_CONNECT_TIMEOUT": "10", "ZO_S3_REQUEST_TIMEOUT": "3600", "ZO_S3_FEATURE_FORCE_PATH_STYLE": "false", "ZO_S3_FEATURE_HTTP1_ONLY": "false", "ZO_S3_FEATURE_HTTP2_ONLY": "false", "ZO_S3_ALLOW_INVALID_CERTIFICATES": "false", "ZO_S3_SYNC_TO_CACHE_INTERVAL": "600", "__prometheus__": "", "ZO_PROMETHEUS_HA_CLUSTER": "cluster", "ZO_PROMETHEUS_HA_REPLICA": "__replica__", "__s3_swift__": "", "AWS_EC2_METADATA_DISABLED": "false" }, "Debugflags": [ "reboot_on_exit" ], "RunConfig": { "Memory": "2G", "UDPPorts": [ "5514" ], "Ports": [ "5514", "5080", "5081" ] }, "Boot": "/usr/local/src/nanos/output/platform/pc/boot/boot.img", "Kernel": "/usr/local/src/nanos/output/platform/pc/bin/kernel.img", "KlibDir": "/usr/local/src/nanos/output/klib/bin" } ``` - **proc folder** ```sh $ tree proc proc └── sys └── kernel ├── osrelease └── ostype 3 directories, 2 files ```
francescolavra commented 1 year ago

I couldn't reproduce this issue: OpenObserve v0.5.2 (downloaded from https://github.com/openobserve/openobserve/releases) runs fine with ops run openobserve -c config-openobserve.json --smp 2. My configuration file is as below:

$ cat config-openobserve.json 
{
  "BaseVolumeSz": "200m",
  "RunConfig": {
    "Memory": "2G",
    "Ports": ["5080", "5081"]
  },
  "Files": ["proc/sys/kernel/ostype", "proc/sys/kernel/osrelease"],
  "Env": {
    "ZO_ROOT_USER_EMAIL": "bob@bob.com",
    "ZO_ROOT_USER_PASSWORD": "bob"
  }
}

I also tried with the nightly kernel build (-n), and also with different CPU count (e.g. --smp 8), and it always ran correctly, with CPU usage near 0 after application startup.

eyberg commented 1 year ago

fyi, i just made a pkg of openobserve last week - https://repo.ops.city/v2/packages/eyberg/openobserve/0.5.1/x86_64/show - it seems to boot fine for me on latest && also nightly - can you post a '--trace' ?

rinor commented 1 year ago

Here is the trace of one run with clean storage that deadlocks.

ops run -c config.json openobserve --smp=2 --trace # with clean storage ```sh ops run -c config.json openobserve --smp=2 --trace running local instance booting /home/rinor/.ops/images/openobserve ... NET: starting DHCP for interface en1 NET: starting DHCPv6 for interface en1 en1: assigned 10.0.2.15 read program complete: 0xffff80c000000000 gitversion: d9e2d9887f9a0745f0af9b988b931c6648c22c1f 2 brk 2 direct return: 129441792, rsp 0xffde4c28 2 mmap 2 mmap: addr 0x0000000000000000, length 0x2000, prot 0x3, flags 0x22, fd -1, offset 0x0 2 returning 0x10fe31ca1000 2 direct return: 18683943063552, rsp 0xffde48d8 2 access 2 access: "/etc/ld.so.preload", mode 4 2 direct return: -2, rsp 0xffde4968 2 openat 2 "/etc/ld.so.cache" - not found 2 direct return: -2, rsp 0xffde3df8 2 openat 2 "/lib/x86_64-linux-gnu/glibc-hwcaps/x86-64-v2/liblzma.so.5" - not found 2 direct return: -2, rsp 0xffde3ce8 2 newfstatat 2 direct return: -2, rsp 0xffde3d38 2 openat 2 "/lib/x86_64-linux-gnu/tls/x86_64/liblzma.so.5" - not found 2 direct return: -2, rsp 0xffde3ce8 2 newfstatat 2 direct return: -2, rsp 0xffde3d38 2 openat 2 "/lib/x86_64-linux-gnu/tls/liblzma.so.5" - not found 2 direct return: -2, rsp 0xffde3ce8 2 newfstatat 2 direct return: -2, rsp 0xffde3d38 2 openat 2 "/lib/x86_64-linux-gnu/x86_64/liblzma.so.5" - not found 2 direct return: -2, rsp 0xffde3ce8 2 newfstatat 2 direct return: -2, rsp 0xffde3d38 2 openat 2 fd 3, length 190456, offset 0 2 direct return: 3, rsp 0xffde3ce8 2 read 2 file_read: f 0xffffc00000a3e4b0, dest 0x00000000ffde3f68, offset 0 (file), length 832, file length 190456 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3e00 2 st_ino ffff80c000000980, st_mode 0x81a4, st_size 2e7f8 2 direct return: 0, rsp 0xffde3d68 2 mmap 2 mmap: addr 0x0000000000000000, length 0x2e018, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802a00 @ offset 0x0 2 returning 0x23881cf5000 2 direct return: 2441719271424, rsp 0xffde3b68 2 mmap 2 mmap: addr 0x0000023881cf9000, length 0x1d000, prot 0x5, flags 0x812, fd 3, offset 0x4000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802a00 @ offset 0x4000 2 vmap_remove_intersection: q [0x23881cf9000 0x23881d16000), r [0x23881cf5000 0x23881d24000) 2 returning 0x23881cf9000 2 direct return: 2441719287808, rsp 0xffde3b68 2 mmap 2 mmap: addr 0x0000023881d16000, length 0xc000, prot 0x1, flags 0x812, fd 3, offset 0x21000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802a00 @ offset 0x21000 2 vmap_remove_intersection: q [0x23881d16000 0x23881d22000), r [0x23881d16000 0x23881d24000) 2 returning 0x23881d16000 2 direct return: 2441719406592, rsp 0xffde3b68 2 mmap 2 mmap: addr 0x0000023881d22000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0x2d000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802a00 @ offset 0x2d000 2 vmap_remove_intersection: q [0x23881d22000 0x23881d24000), r [0x23881d16000 0x23881d24000) 2 returning 0x23881d22000 2 direct return: 2441719455744, rsp 0xffde3b68 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3d68 2 openat 2 fd 3, length 121280, offset 0 2 direct return: 3, rsp 0xffde3cc8 2 read 2 file_read: f 0xffffc00000a3e578, dest 0x00000000ffde3f48, offset 0 (file), length 832, file length 121280 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3de0 2 st_ino ffff80c000000a40, st_mode 0x81a4, st_size 1d9c0 2 direct return: 0, rsp 0xffde3d48 2 mmap 2 mmap: addr 0x0000000000000000, length 0x1e190, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802400 @ offset 0x0 2 returning 0x2246aa1f000 2 direct return: 2355431075840, rsp 0xffde3b48 2 mmap 2 mmap: addr 0x000002246aa22000, length 0x13000, prot 0x5, flags 0x812, fd 3, offset 0x3000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802400 @ offset 0x3000 2 vmap_remove_intersection: q [0x2246aa22000 0x2246aa35000), r [0x2246aa1f000 0x2246aa3e000) 2 returning 0x2246aa22000 2 direct return: 2355431088128, rsp 0xffde3b48 2 mmap 2 mmap: addr 0x000002246aa35000, length 0x7000, prot 0x1, flags 0x812, fd 3, offset 0x16000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802400 @ offset 0x16000 2 vmap_remove_intersection: q [0x2246aa35000 0x2246aa3c000), r [0x2246aa35000 0x2246aa3e000) 2 returning 0x2246aa35000 2 direct return: 2355431165952, rsp 0xffde3b48 2 mmap 2 mmap: addr 0x000002246aa3c000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0x1c000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802400 @ offset 0x1c000 2 vmap_remove_intersection: q [0x2246aa3c000 0x2246aa3e000), r [0x2246aa35000 0x2246aa3e000) 2 returning 0x2246aa3c000 2 direct return: 2355431194624, rsp 0xffde3b48 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3d48 2 openat 2 fd 3, length 125312, offset 0 2 direct return: 3, rsp 0xffde3ca8 2 read 2 file_read: f 0xffffc00000a3e640, dest 0x00000000ffde3f28, offset 0 (file), length 832, file length 125312 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3dc0 2 st_ino ffff80c000000bc0, st_mode 0x81a4, st_size 1e980 2 direct return: 0, rsp 0xffde3d28 2 mmap 2 mmap: addr 0x0000000000000000, length 0x1f2c8, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802800 @ offset 0x0 2 returning 0x1a14c5b5000 2 direct return: 1792282415104, rsp 0xffde3b28 2 mmap 2 mmap: addr 0x000001a14c5b8000, length 0x17000, prot 0x5, flags 0x812, fd 3, offset 0x3000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802800 @ offset 0x3000 2 vmap_remove_intersection: q [0x1a14c5b8000 0x1a14c5cf000), r [0x1a14c5b5000 0x1a14c5d5000) 2 returning 0x1a14c5b8000 2 direct return: 1792282427392, rsp 0xffde3b28 2 mmap 2 mmap: addr 0x000001a14c5cf000, length 0x4000, prot 0x1, flags 0x812, fd 3, offset 0x1a000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802800 @ offset 0x1a000 2 vmap_remove_intersection: q [0x1a14c5cf000 0x1a14c5d3000), r [0x1a14c5cf000 0x1a14c5d5000) 2 returning 0x1a14c5cf000 2 direct return: 1792282521600, rsp 0xffde3b28 2 mmap 2 mmap: addr 0x000001a14c5d3000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0x1d000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802800 @ offset 0x1d000 2 vmap_remove_intersection: q [0x1a14c5d3000 0x1a14c5d5000), r [0x1a14c5cf000 0x1a14c5d5000) 2 returning 0x1a14c5d3000 2 direct return: 1792282537984, rsp 0xffde3b28 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3d28 2 openat 2 fd 3, length 14480, offset 0 2 direct return: 3, rsp 0xffde3c88 2 read 2 file_read: f 0xffffc00000a3e708, dest 0x00000000ffde3f08, offset 0 (file), length 832, file length 14480 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3da0 2 st_ino ffff80c000000c80, st_mode 0x81a4, st_size 3890 2 direct return: 0, rsp 0xffde3d08 2 mmap 2 mmap: addr 0x0000000000000000, length 0x4010, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802c00 @ offset 0x0 2 returning 0x15f675f2000 2 direct return: 1509267808256, rsp 0xffde3a98 2 mmap 2 mmap: addr 0x0000015f675f3000, length 0x1000, prot 0x5, flags 0x812, fd 3, offset 0x1000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802c00 @ offset 0x1000 2 vmap_remove_intersection: q [0x15f675f3000 0x15f675f4000), r [0x15f675f2000 0x15f675f7000) 2 returning 0x15f675f3000 2 direct return: 1509267812352, rsp 0xffde3a98 2 mmap 2 mmap: addr 0x0000015f675f4000, length 0x1000, prot 0x1, flags 0x812, fd 3, offset 0x2000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802c00 @ offset 0x2000 2 vmap_remove_intersection: q [0x15f675f4000 0x15f675f5000), r [0x15f675f4000 0x15f675f7000) 2 returning 0x15f675f4000 2 direct return: 1509267816448, rsp 0xffde3a98 2 mmap 2 mmap: addr 0x0000015f675f5000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0x2000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802c00 @ offset 0x2000 2 vmap_remove_intersection: q [0x15f675f5000 0x15f675f7000), r [0x15f675f4000 0x15f675f7000) 2 returning 0x15f675f5000 2 direct return: 1509267820544, rsp 0xffde3a98 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3d08 2 openat 2 fd 3, length 907784, offset 0 2 direct return: 3, rsp 0xffde3c68 2 read 2 file_read: f 0xffffc00000a3e7d0, dest 0x00000000ffde3ee8, offset 0 (file), length 832, file length 907784 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3d80 2 st_ino ffff80c000000d80, st_mode 0x81a4, st_size dda08 2 direct return: 0, rsp 0xffde3ce8 2 mmap 2 mmap: addr 0x0000000000000000, length 0xde0f8, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803200 @ offset 0x0 2 returning 0x8fcc5ec000 2 direct return: 617609084928, rsp 0xffde3a78 2 mmap 2 mmap: addr 0x0000008fcc5fc000, length 0x73000, prot 0x5, flags 0x812, fd 3, offset 0x10000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803200 @ offset 0x10000 2 vmap_remove_intersection: q [0x8fcc5fc000 0x8fcc66f000), r [0x8fcc5ec000 0x8fcc6cb000) 2 returning 0x8fcc5fc000 2 direct return: 617609150464, rsp 0xffde3a78 2 mmap 2 mmap: addr 0x0000008fcc66f000, length 0x5a000, prot 0x1, flags 0x812, fd 3, offset 0x83000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803200 @ offset 0x83000 2 vmap_remove_intersection: q [0x8fcc66f000 0x8fcc6c9000), r [0x8fcc66f000 0x8fcc6cb000) 2 returning 0x8fcc66f000 2 direct return: 617609621504, rsp 0xffde3a78 2 mmap 2 mmap: addr 0x0000008fcc6c9000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0xdc000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803200 @ offset 0xdc000 2 vmap_remove_intersection: q [0x8fcc6c9000 0x8fcc6cb000), r [0x8fcc66f000 0x8fcc6cb000) 2 returning 0x8fcc6c9000 2 direct return: 617609990144, rsp 0xffde3a78 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3ce8 2 openat 2 fd 3, length 14480, offset 0 2 direct return: 3, rsp 0xffde3c48 2 read 2 file_read: f 0xffffc00000a3e898, dest 0x00000000ffde3ec8, offset 0 (file), length 832, file length 14480 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 newfstatat 2 fd 3, stat 0x00000000ffde3d60 2 st_ino ffff80c000000e40, st_mode 0x81a4, st_size 3890 2 direct return: 0, rsp 0xffde3cc8 2 mmap 2 mmap: addr 0x0000000000000000, length 0x2000, prot 0x3, flags 0x22, fd -1, offset 0x0 2 returning 0x2516e68000 2 direct return: 159297994752, rsp 0xffde3c48 2 mmap 2 mmap: addr 0x0000000000000000, length 0x4010, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802600 @ offset 0x0 2 returning 0x4e39cb000 2 direct return: 20998565888, rsp 0xffde3a58 2 mmap 2 mmap: addr 0x00000004e39cc000, length 0x1000, prot 0x5, flags 0x812, fd 3, offset 0x1000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802600 @ offset 0x1000 2 vmap_remove_intersection: q [0x4e39cc000 0x4e39cd000), r [0x4e39cb000 0x4e39d0000) 2 returning 0x4e39cc000 2 direct return: 20998569984, rsp 0xffde3a58 2 mmap 2 mmap: addr 0x00000004e39cd000, length 0x1000, prot 0x1, flags 0x812, fd 3, offset 0x2000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802600 @ offset 0x2000 2 vmap_remove_intersection: q [0x4e39cd000 0x4e39ce000), r [0x4e39cd000 0x4e39d0000) 2 returning 0x4e39cd000 2 direct return: 20998574080, rsp 0xffde3a58 2 mmap 2 mmap: addr 0x00000004e39ce000, length 0x2000, prot 0x3, flags 0x812, fd 3, offset 0x2000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000802600 @ offset 0x2000 2 vmap_remove_intersection: q [0x4e39ce000 0x4e39d0000), r [0x4e39cd000 0x4e39d0000) 2 returning 0x4e39ce000 2 direct return: 20998578176, rsp 0xffde3a58 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3cc8 2 openat 2 fd 3, length 1922136, offset 0 2 direct return: 3, rsp 0xffde3c28 2 read 2 file_read: f 0xffffc00000a3e960, dest 0x00000000ffde3ea8, offset 0 (file), length 832, file length 1922136 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 832 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff994 2 pread64 2 file_read: f 0xffffc00000a3e960, dest 0x00000000ffde3910, offset 64 (specified), length 784, file length 1922136 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 784 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff9ba 2 newfstatat 2 fd 3, stat 0x00000000ffde3d40 2 st_ino ffff80c0000008c0, st_mode 0x81a4, st_size 1d5458 2 direct return: 0, rsp 0xffde3ca8 2 pread64 2 file_read: f 0xffffc00000a3e960, dest 0x00000000ffde3990, offset 64 (specified), length 784, file length 1922136 2 sleep uninterruptible 2 file_read_complete: status (none) 2 read count 784 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x14209caff9ba 2 mmap 2 mmap: addr 0x0000000000000000, length 0x1e0f50, prot 0x1, flags 0x802, fd 3, offset 0x0 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803000 @ offset 0x0 2 returning 0x1f3e2a000 2 direct return: 8386682880, rsp 0xffde3678 2 mmap 2 mmap: addr 0x00000001f3e50000, length 0x155000, prot 0x5, flags 0x812, fd 3, offset 0x26000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803000 @ offset 0x26000 2 vmap_remove_intersection: q [0x1f3e50000 0x1f3fa5000), r [0x1f3e2a000 0x1f400b000) 2 returning 0x1f3e50000 2 direct return: 8386838528, rsp 0xffde3678 2 mmap 2 mmap: addr 0x00000001f3fa5000, length 0x53000, prot 0x1, flags 0x812, fd 3, offset 0x17b000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803000 @ offset 0x17b000 2 vmap_remove_intersection: q [0x1f3fa5000 0x1f3ff8000), r [0x1f3fa5000 0x1f400b000) 2 returning 0x1f3fa5000 2 direct return: 8388235264, rsp 0xffde3678 2 mmap 2 mmap: addr 0x00000001f3ff8000, length 0x6000, prot 0x3, flags 0x812, fd 3, offset 0x1ce000 2 fd 3: file-backed (regular) 2 associated with cache node 0xffffc00000803000 @ offset 0x1ce000 2 vmap_remove_intersection: q [0x1f3ff8000 0x1f3ffe000), r [0x1f3fa5000 0x1f400b000) 2 returning 0x1f3ff8000 2 direct return: 8388575232, rsp 0xffde3678 2 mmap 2 mmap: addr 0x00000001f3ffe000, length 0xcf50, prot 0x3, flags 0x32, fd -1, offset 0x0 2 vmap_remove_intersection: q [0x1f3ffe000 0x1f400b000), r [0x1f3ffe000 0x1f400b000) 2 returning 0x1f3ffe000 2 direct return: 8388599808, rsp 0xffde3678 2 close 2 close: fd 3 2 direct return: 0, rsp 0xffde3988 2 mmap 2 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x22, fd -1, offset 0x0 2 returning 0x15ae01000 2 direct return: 5819600896, rsp 0xffde4908 2 arch_prctl 2 arch_prctl: code 0x1002, addr 0x15ae01d40 2 direct return: 0, rsp 0xffde4950 2 set_tid_address 2 direct return: 2, rsp 0xffde4930 2 set_robust_list 2 set_robust_list syscall with head 0x000000015ae02020 2 direct return: 0, rsp 0xffde4930 2 syscall 334 2 nosyscall 334 2 mprotect 2 mprotect: addr 0x00000001f3ff8000, len 0x4000, prot 0x1 2 vmap_update_protections_locked: validate [0x1f3ff8000 0x1f3ffc000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x00000004e39ce000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x4e39ce000 0x4e39cf000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x0000008fcc6c9000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x8fcc6c9000 0x8fcc6ca000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x0000015f675f5000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x15f675f5000 0x15f675f6000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x000001a14c5d3000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x1a14c5d3000 0x1a14c5d4000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x000002246aa3c000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x2246aa3c000 0x2246aa3d000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x0000023881d22000, len 0x1000, prot 0x1 2 vmap_update_protections_locked: validate [0x23881d22000 0x23881d23000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x000000000758c000, len 0x303000, prot 0x1 2 vmap_update_protections_locked: validate [0x758c000 0x788f000) 2 direct return: 0, rsp 0xffde4848 2 mprotect 2 mprotect: addr 0x000014209cb0f000, len 0x2000, prot 0x1 2 vmap_update_protections_locked: validate [0x14209cb0f000 0x14209cb11000) 2 direct return: 0, rsp 0xffde4848 2 prlimit64 2 prlimit64: pid 0, resource 3, new_limit 0x0000000000000000, old_limit 0x00000000ffde4940 2 getrlimit: resource 3, rlim 0x00000000ffde4940 2 direct return: 0, rsp 0xffde4938 2 getrandom 2 direct return: 32, rsp 0xffde4bf8 2 open 2 open: "/proc/sys/vm/overcommit_memory", flags 0, mode 0 2 "/proc/sys/vm/overcommit_memory" - not found 2 direct return: -2, rsp 0xffde4be8 2 poll 2 direct return: 0, rsp 0xffde4ad8 2 rt_sigaction 2 direct return: 0, rsp 0xffde4840 2 rt_sigaction 2 direct return: 0, rsp 0xffde4990 2 rt_sigaction 2 direct return: 0, rsp 0xffde4990 2 rt_sigaction 2 direct return: 0, rsp 0xffde4990 2 rt_sigaction 2 direct return: 0, rsp 0xffde4990 2 sigaltstack 2 direct return: 0, rsp 0xffde4a58 2 mmap 2 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 2 returning 0x14dc7f000 2 direct return: 5599916032, rsp 0xffde4a58 2 mprotect 2 mprotect: addr 0x000000014dc7f000, len 0x1000, prot 0x0 2 vmap_update_protections_locked: validate [0x14dc7f000 0x14dc80000) 2 direct return: 0, rsp 0xffde4a58 2 sigaltstack 2 direct return: 0, rsp 0xffde4a58 2 getrandom 2 direct return: 8, rsp 0xffde4998 2 brk 2 direct return: 129441792, rsp 0xffde48b8 2 brk 2 direct return: 129576960, rsp 0xffde48b8 2 openat 2 spec_open: /proc/self/maps 2 fd 3, length 0, offset 0 2 direct return: 3, rsp 0xffde4920 2 prlimit64 2 prlimit64: pid 0, resource 3, new_limit 0x0000000000000000, old_limit 0x00000000ffde4a80 2 getrlimit: resource 3, rlim 0x00000000ffde4a80 2 direct return: 0, rsp 0xffde4a38 2 newfstatat 2 fd 3, stat 0x00000000ffde48b0 2 st_ino ffff80c000001540, st_mode 0x2000, st_size 0 2 direct return: 0, rsp 0xffde48a8 2 ioctl 2 ioctl: fd 3, request 0x5401 2 direct return: -38, rsp 0xffde4810 2 read 2 spec_read: /proc/self/maps 2 direct return: 2983, rsp 0xffde4988 2 close 2 close: fd 3 2 spec_close: /proc/self/maps 2 direct return: 0, rsp 0xffde49f8 2 sched_getaffinity 2 direct return: 8, rsp 0xffde4a38 2 access 2 access: "/sys/devices/system/node/node1", mode 4 2 direct return: -2, rsp 0xffde46d8 2 mmap 2 mmap: addr 0x000004066a000000, length 0x40000000, prot 0x3, flags 0x4022, fd -1, offset 0x0 2 returning 0x4066a000000 2 direct return: 4425594699776, rsp 0xffde4638 2 mmap 2 mmap: addr 0x0000000000000000, length 0x1000, prot 0x3, flags 0x4022, fd -1, offset 0x0 2 returning 0x127e56000 2 direct return: 4964311040, rsp 0xffde45c8 2 getrandom 2 direct return: -22, rsp 0xffddcff8 2 getrandom 2 direct return: 16, rsp 0xffddcff8 2 openat 2 "/proc/self/cgroup" - not found 2 direct return: -2, rsp 0xffddbfc0 2 sched_getaffinity 2 direct return: 8, rsp 0xffddc3f8 2 epoll_create1 2 direct return: 3, rsp 0xffddb4e8 2 eventfd2 2 direct return: 4, rsp 0xffddb4d8 2 epoll_ctl 2 direct return: 0, rsp 0xffddb4d8 2 fcntl 2 fcntl: fd 3, cmd 1030, arg 3 2 direct return: 5, rsp 0xffddb490 2 socketpair 2 direct return: 0, rsp 0xffddb3e8 2 fcntl 2 fcntl: fd 6, cmd 1030, arg 3 2 direct return: 8, rsp 0xffddb490 2 epoll_ctl 2 direct return: 0, rsp 0xffddb4f8 2 rt_sigaction 2 direct return: 0, rsp 0xffddbfb0 2 rt_sigprocmask 2 direct return: 0, rsp 0xffddc100 2 mmap 2 mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 2 returning 0x122654000 2 direct return: 4872028160, rsp 0xffddc0f8 2 mprotect 2 mprotect: addr 0x0000000122655000, len 0x200000, prot 0x3 2 vmap_update_protections_locked: validate [0x122655000 0x122855000) 2 direct return: 0, rsp 0xffddc0f8 2 rt_sigprocmask 2 direct return: 0, rsp 0xffddc100 2 clone3 2 clone3: args_size: 88, pidfd: 0x0000000122854990, child_tid: 0x0000000122854990, parent_tid: 0x0000000122854990, exit_signal: 0, stack: 0x0000000122654000, stack_size: 0x1ff980, tls: 0x00000001228546c0 2 direct return: 3, rsp 0xffddc028 3 set_robust_list 2 rt_sigprocmask 3 set_robust_list syscall with head 0x00000001228549a0 2 direct return: 0, rsp 0xffddc100 3 direct return: 0, rsp 0x1228538e0 2 mmap 3 rt_sigprocmask 2 mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 3 direct return: 0, rsp 0x1228538e0 2 returning 0x106167000 3 sigaltstack 2 direct return: 4397101056, rsp 0xffddc0f8 3 direct return: 0, rsp 0x122853818 2 mprotect 3 mmap 2 mprotect: addr 0x0000000106168000, len 0x200000, prot 0x3 3 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 2 vmap_update_protections_locked: validate [0x106168000 0x106368000) 2 direct return: 0, rsp 0xffddc0f8 3 returning 0x10465a000 2 rt_sigprocmask 3 direct return: 4368736256, rsp 0x122853818 2 direct return: 0, rsp 0xffddc100 3 mprotect 2 clone3 3 mprotect: addr 0x000000010465a000, len 0x1000, prot 0x0 2 clone3: args_size: 88, pidfd: 0x0000000106367990, child_tid: 0x0000000106367990, parent_tid: 0x0000000106367990, exit_signal: 0, stack: 0x0000000106167000, stack_size: 0x1ff980, tls: 0x00000001063676c0 3 vmap_update_protections_locked: validate [0x10465a000 0x10465b000) 2 direct return: 4, rsp 0xffddc028 3 direct return: 0, rsp 0x122853818 4 set_robust_list 3 sigaltstack 4 set_robust_list syscall with head 0x00000001063679a0 3 direct return: 0, rsp 0x122853818 4 direct return: 0, rsp 0x1063668e0 3 prctl 2 rt_sigprocmask 3 prctl: option 15, arg2 0x122853840, arg3 0x8000, arg4 0x840, arg5 0xffffffff 2 direct return: 0, rsp 0xffddc100 3 [tokio-runtime-w] direct return: 0, rsp 0x122853760 2 getcwd 3 [tokio-runtime-w] mmap 2 direct return: 2, rsp 0xffdd3fe0 3 [tokio-runtime-w] mmap: addr 0x0000000000000000, length 0x8000000, prot 0x0, flags 0x4022, fd -1, offset 0x0 4 rt_sigprocmask 3 [tokio-runtime-w] returning 0x10663b000 4 direct return: 0, rsp 0x1063668e0 3 [tokio-runtime-w] direct return: 4402163712, rsp 0x1228535e8 4 sigaltstack 3 [tokio-runtime-w] munmap 4 direct return: 0, rsp 0x106366818 3 [tokio-runtime-w] munmap: addr 0x000000010663b000, size 0x19c5000 3 [tokio-runtime-w] vmap_remove_intersection: q [0x10663b000 0x108000000), r [0x10663b000 0x10e63b000) 4 mmap 3 [tokio-runtime-w] direct return: 0, rsp 0x1228535e8 4 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 3 [tokio-runtime-w] munmap 4 returning 0x103dd3000 3 [tokio-runtime-w] munmap: addr 0x000000010c000000, size 0x263b000 4 direct return: 4359794688, rsp 0x106366818 3 [tokio-runtime-w] vmap_remove_intersection: q [0x10c000000 0x10e63b000), r [0x108000000 0x10e63b000) 4 mprotect 3 [tokio-runtime-w] direct return: 0, rsp 0x1228535e8 4 mprotect: addr 0x0000000103dd3000, len 0x1000, prot 0x0 3 [tokio-runtime-w] mprotect 4 vmap_update_protections_locked: validate [0x103dd3000 0x103dd4000) 3 [tokio-runtime-w] mprotect: addr 0x0000000108000000, len 0x21000, prot 0x3 4 direct return: 0, rsp 0x106366818 3 [tokio-runtime-w] vmap_update_protections_locked: validate [0x108000000 0x108021000) 4 sigaltstack 3 [tokio-runtime-w] direct return: 0, rsp 0x1228535e8 4 direct return: 0, rsp 0x106366818 3 [tokio-runtime-w] sched_getaffinity 4 prctl 3 [tokio-runtime-w] direct return: 8, rsp 0x1228536c8 4 prctl: option 15, arg2 0x106366840, arg3 0x8000, arg4 0x840, arg5 0xffffffff 3 [tokio-runtime-w] getrandom 4 [tokio-runtime-w] direct return: 0, rsp 0x106366760 3 [tokio-runtime-w] direct return: 16, rsp 0x122853240 4 [tokio-runtime-w] mmap 3 [tokio-runtime-w] epoll_wait 4 [tokio-runtime-w] mmap: addr 0x0000000000000000, length 0x8000000, prot 0x0, flags 0x4022, fd -1, offset 0x0 3 [tokio-runtime-w] sleep interruptible (on "thread") 4 [tokio-runtime-w] returning 0x11829a000 4 [tokio-runtime-w] direct return: 4700348416, rsp 0x1063665e8 4 [tokio-runtime-w] munmap 2 syscall 332 4 [tokio-runtime-w] munmap: addr 0x000000011829a000, size 0x3d66000 2 nosyscall 332 4 [tokio-runtime-w] vmap_remove_intersection: q [0x11829a000 0x11c000000), r [0x11829a000 0x12029a000) 2 newfstatat 4 [tokio-runtime-w] direct return: 0, rsp 0x1063665e8 2 direct return: -2, rsp 0xffdd3a68 4 [tokio-runtime-w] munmap 2 syscall 332 4 [tokio-runtime-w] munmap: addr 0x0000000120000000, size 0x29a000 2 nosyscall 332 4 [tokio-runtime-w] vmap_remove_intersection: q [0x120000000 0x12029a000), r [0x11c000000 0x12029a000) 2 newfstatat 4 [tokio-runtime-w] direct return: 0, rsp 0x1063665e8 2 direct return: -14, rsp 0xffdd3a68 4 [tokio-runtime-w] mprotect 2 openat 4 [tokio-runtime-w] mprotect: addr 0x000000011c000000, len 0x21000, prot 0x3 2 "/sys/fs/cgroup/cpu.max" - not found 4 [tokio-runtime-w] vmap_update_protections_locked: validate [0x11c000000 0x11c021000) 2 direct return: -2, rsp 0xffdd4330 4 [tokio-runtime-w] direct return: 0, rsp 0x1063665e8 2 openat 4 [tokio-runtime-w] sched_getaffinity 2 spec_open: /sys/devices/system/cpu/online 4 [tokio-runtime-w] direct return: 8, rsp 0x1063666c8 2 fd 9, length 0, offset 0 4 [tokio-runtime-w] getrandom 2 direct return: 9, rsp 0xffdd40f0 4 [tokio-runtime-w] direct return: 16, rsp 0x106366240 2 read 4 [tokio-runtime-w] mmap 2 spec_read: /sys/devices/system/cpu/online 4 [tokio-runtime-w] mmap: addr 0x0000000000000000, length 0x2000, prot 0x3, flags 0x4022, fd -1, offset 0x0 2 direct return: 4, rsp 0xffdd40e8 4 [tokio-runtime-w] returning 0x1023b0000 2 close 4 [tokio-runtime-w] direct return: 4332388352, rsp 0x1063660a8 2 close: fd 9 4 [tokio-runtime-w] getrandom 2 spec_close: /sys/devices/system/cpu/online 4 [tokio-runtime-w] direct return: 32, rsp 0x106366108 2 direct return: 0, rsp 0xffdd4148 4 [tokio-runtime-w] futex 2 uname 4 [tokio-runtime-w] futex_wait [4 0x0000000106367488 1] 1 0x0 2 direct return: 0, rsp 0xffdd4438 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32460, blocking 2 openat 4 [tokio-runtime-w] sleep interruptible (on "futex") 2 "/sys/fs/cgroup/memory.max" - not found 2 direct return: -2, rsp 0xffdd4350 2 openat 2 spec_open: /proc/meminfo 2 fd 9, length 0, offset 0 2 direct return: 9, rsp 0xffdd41d0 2 syscall 332 2 nosyscall 332 2 newfstatat 2 fd 9, stat 0x00000000ffdd3ee0 2 st_ino ffff80c0000014c0, st_mode 0x2000, st_size 0 2 direct return: 0, rsp 0xffdd3ed8 2 lseek 2 lseek: fd 9 offset 0 whence SEEK_CUR 2 direct return: 0, rsp 0xffdd41b8 2 read 2 spec_read: /proc/meminfo 2 direct return: 32, rsp 0xffdd4180 2 read 2 spec_read: /proc/meminfo 2 direct return: 32, rsp 0xffdd4180 2 read 2 spec_read: /proc/meminfo 2 direct return: 64, rsp 0xffdd4180 2 read 2 spec_read: /proc/meminfo 2 direct return: 61, rsp 0xffdd4180 2 read 2 spec_read: /proc/meminfo 2 direct return: 0, rsp 0xffdd4180 2 close 2 close: fd 9 2 spec_close: /proc/meminfo 2 direct return: 0, rsp 0xffdd4270 2 ioctl 2 ioctl: fd 2, request 0x5413 2 direct return: -38, rsp 0xffdd55d0 2 write [2023-08-28T16:51:28Z INFO openobserve] Starting OpenObserve v0.5.2 2 direct return: 69, rsp 0xffdd5830 2 write [2023-08-28T16:51:28Z INFO openobserve] System info: CPU cores 2, MEM total 2043 MB 2 direct return: 85, rsp 0xffdd5830 2 getrandom 2 direct return: -22, rsp 0xffdd57b8 2 getrandom 2 direct return: 64, rsp 0xffdd57b8 2 openat 2 "/proc/self/cgroup" - not found 2 direct return: -2, rsp 0xffdd5470 2 sched_getaffinity 2 direct return: 8, rsp 0xffdd5528 2 getrandom 2 direct return: 32, rsp 0xffdd57b8 2 getpid 2 direct return: 2, rsp 0xffdcf768 2 openat 2 "/sys/fs/cgroup/memory/memory.limit_in_bytes" - not found 2 direct return: -2, rsp 0xffdcf4e0 2 prlimit64 2 prlimit64: pid 0, resource 9, new_limit 0x0000000000000000, old_limit 0x00000000ffdcf600 2 getrlimit: resource 9, rlim 0x00000000ffdcf600 2 direct return: 0, rsp 0xffdcf598 2 sysinfo 2 direct return: 0, rsp 0xffdcf4f8 2 syscall 332 2 nosyscall 332 2 newfstatat 2 direct return: -2, rsp 0xffdcf068 2 mkdir 2 mkdir: "/data/openobserve/sled_data/blobs", mode 0x1ff 2 direct return: -2, rsp 0xffdcf148 2 mkdir 2 mkdir: "/data/openobserve/sled_data", mode 0x1ff 2 direct return: -2, rsp 0xffdcef48 2 mkdir 2 mkdir: "/data/openobserve", mode 0x1ff 2 direct return: 0, rsp 0xffdced48 2 mkdir 2 mkdir: "/data/openobserve/sled_data", mode 0x1ff 2 direct return: 0, rsp 0xffdcef48 2 mkdir 2 mkdir: "/data/openobserve/sled_data/blobs", mode 0x1ff 2 direct return: 0, rsp 0xffdcf148 2 openat 2 "/data/openobserve/sled_data/conf" - not found 2 direct return: -2, rsp 0xffdcf290 2 openat 2 fd 9, length 0, offset 0 2 direct return: 9, rsp 0xffdcf290 2 write 2 file_write: f 0xffffc00000a3ea28, src 0x000004066a1901c0, offset 0 (file), length 58, file length 0 2 sleep uninterruptible 2 file_write_complete: f 0xffffc00000a3ea28, sg, 0xffffc00000c314e0, completion fdesc_io_complete, status (none) 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x1f3f2215f 2 write 2 file_write: f 0xffffc00000a3ea28, src 0x00000000ffdcf42c, offset 58 (file), length 4, file length 58 2 sleep uninterruptible 2 file_write_complete: f 0xffffc00000a3ea28, sg, 0xffffc00000c314e0, completion fdesc_io_complete, status (none) 2 thread_wakeup: 2->2 blocked_on uninterruptible, RIP=0x1f3f2215f 2 close 2 close: fd 9 2 direct return: 0, rsp 0xffdcf330 2 openat 2 fd 9, length 0, offset 0 2 direct return: 9, rsp 0xffdcf0e0 2 flock 2 direct return: 0, rsp 0xffdcf338 2 syscall 332 2 nosyscall 332 2 newfstatat 2 st_ino ffff80c000002180, st_mode 0x41ff, st_size 0 2 direct return: 0, rsp 0xffdce5d8 2 openat 2 fd 10, length 0, offset 0 2 direct return: 10, rsp 0xffdce980 2 newfstatat 2 fd 10, stat 0x00000000ffdce930 2 st_ino ffff80c000002180, st_mode 0x41ff, st_size 0 2 direct return: 0, rsp 0xffdce928 2 getdents64 2 direct return: 128, rsp 0xffdcea08 2 getdents64 2 direct return: 0, rsp 0xffdcea08 2 close 2 close: fd 10 2 direct return: 0, rsp 0xffdceb18 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::snapshot] no previous snapshot found 2 direct return: 82, rsp 0xffdcebb0 2 syscall 332 2 nosyscall 332 2 newfstatat 2 fd 9, stat 0x00000000ffdcea90 2 st_ino ffff80c000002340, st_mode 0x81a4, st_size 0 2 direct return: 0, rsp 0xffdcea88 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0 2 direct return: 116, rsp 0xffdcebb0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iterator] in clean_tail_tears, found missing item in tail: None and we'll scan segments {} above lowest lsn 0 2 direct return: 155, rsp 0xffdcebb0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) 2 direct return: 158, rsp 0xffdce8e0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1 2 direct return: 115, rsp 0xffdcebb0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" }) 2 direct return: 158, rsp 0xffdce520 2 syscall 332 2 nosyscall 332 2 newfstatat 2 fd 9, stat 0x00000000ffdce8a0 2 st_ino ffff80c000002340, st_mode 0x81a4, st_size 0 2 direct return: 0, rsp 0xffdce898 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::segment] SA starting with tip 0 stable -1 free {} 2 direct return: 95, rsp 0xffdce9c0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iobuf] starting log for a totally fresh system 2 direct return: 92, rsp 0xffdce930 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {} 2 direct return: 115, rsp 0xffdce7d0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0 2 direct return: 97, rsp 0xffdce9c0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache::iobuf] storing lsn 0 in beginning of buffer 2 direct return: 89, rsp 0xffdce8f0 2 write [2023-08-28T16:51:28Z DEBUG sled::pagecache] load_snapshot loading pages from 0..0 2 direct return: 83, rsp 0xffdcf050 2 mmap 2 mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 2 returning 0x1015a4000 2 direct return: 4317659136, rsp 0xffdcf008 2 mprotect 2 mprotect: addr 0x00000001015a5000, len 0x200000, prot 0x3 2 vmap_update_protections_locked: validate [0x1015a5000 0x1017a5000) 2 direct return: 0, rsp 0xffdcf008 2 rt_sigprocmask 2 direct return: 0, rsp 0xffdcf010 2 clone3 2 clone3: args_size: 88, pidfd: 0x00000001017a4990, child_tid: 0x00000001017a4990, parent_tid: 0x00000001017a4990, exit_signal: 0, stack: 0x00000001015a4000, stack_size: 0x1ff980, tls: 0x00000001017a46c0 2 direct return: 5, rsp 0xffdcef38 5 set_robust_list 2 rt_sigprocmask 5 set_robust_list syscall with head 0x00000001017a49a0 2 direct return: 0, rsp 0xffdcf010 5 direct return: 0, rsp 0x1017a38e0 2 write 5 rt_sigprocmask [2023-08-28T16:51:28Z DEBUG sled::meta] allocated pid 3 for root of new_tree [95, 95, 115, 108, 101, 100, 95, 95, 100, 101, 102, 97, 117, 108, 116] 5 direct return: 0, rsp 0x1017a38e0 2 direct return: 148, rsp 0xffdcf050 5 sigaltstack 2 write 5 direct return: 0, rsp 0x1017a3818 [2023-08-28T16:51:28Z INFO openobserve::service::db::user] get; org_id=Some("default") name="test@test.io" 5 mmap 2 direct return: 108, rsp 0xffdcf0d0 5 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 5 returning 0x100f25000 5 direct return: 4310847488, rsp 0x1017a3818 5 mprotect 5 mprotect: addr 0x0000000100f25000, len 0x1000, prot 0x0 5 vmap_update_protections_locked: validate [0x100f25000 0x100f26000) 5 direct return: 0, rsp 0x1017a3818 5 sigaltstack 5 direct return: 0, rsp 0x1017a3818 5 prctl 5 prctl: option 15, arg2 0x1017a3840, arg3 0xf800, arg4 0x840, arg5 0xffffffff 5 [log flusher] direct return: 0, rsp 0x1017a3760 5 [log flusher] mmap 5 [log flusher] mmap: addr 0x0000000000000000, length 0x8000000, prot 0x0, flags 0x4022, fd -1, offset 0x0 2 write 5 [log flusher] returning 0x110bbe000 [2023-08-28T16:51:28Z INFO tracing::span] set; 5 [log flusher] direct return: 4575715328, rsp 0x1017a35e8 2 direct return: 48, rsp 0xffdcf3e0 5 [log flusher] munmap 2 futex 5 [log flusher] munmap: addr 0x0000000110bbe000, size 0x3442000 2 futex_wake [2 0x0000000106367488 0] 1 5 [log flusher] vmap_remove_intersection: q [0x110bbe000 0x114000000), r [0x110bbe000 0x118bbe000) 2 direct return: 1, rsp 0xffdcfc78 5 [log flusher] direct return: 0, rsp 0x1017a35e8 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32460, flags 0x1, rv 0 5 [log flusher] munmap 4 [tokio-runtime-w] thread_wakeup: 4->4 blocked_on futex, RIP=0x1f3f2b539 5 [log flusher] munmap: addr 0x0000000118000000, size 0xbbe000 4 [tokio-runtime-w] write 5 [log flusher] vmap_remove_intersection: q [0x118000000 0x118bbe000), r [0x114000000 0x118bbe000) 4 [tokio-runtime-w] direct return: 8, rsp 0x1063663b0 5 [log flusher] direct return: 0, rsp 0x1017a35e8 3 [tokio-runtime-w] thread_wakeup: 3->3 blocked_on thread, RIP=0x1f3f32c46 5 [log flusher] mprotect 4 [tokio-runtime-w] write 5 [log flusher] mprotect: addr 0x0000000114000000, len 0x21000, prot 0x3 [2023-08-28T16:51:28Z INFO openobserve::service::db::user] Start watching user 5 [log flusher] vmap_update_protections_locked: validate [0x114000000 0x114021000) 4 [tokio-runtime-w] direct return: 80, rsp 0x106365af0 5 [log flusher] direct return: 0, rsp 0x1017a35e8 2 write 5 [log flusher] sched_getaffinity [2023-08-28T16:51:28Z INFO openobserve::service::db::user] Users Cached 5 [log flusher] direct return: 8, rsp 0x1017a36c8 2 direct return: 73, rsp 0xffdcf5c0 3 [tokio-runtime-w] epoll_wait 2 write 3 [tokio-runtime-w] sleep interruptible (on "thread") 2 direct return: 8, rsp 0xffdcfc10 3 [tokio-runtime-w] thread_wakeup: 3->3 blocked_on thread, RIP=0x1f3f32c46 2 write 3 [tokio-runtime-w] mmap [2023-08-28T16:51:28Z INFO openobserve::service::db::functions] Functions Cached 3 [tokio-runtime-w] mmap: addr 0x0000000000000000, length 0x2000, prot 0x3, flags 0x4022, fd -1, offset 0x0 2 direct return: 82, rsp 0xffdcfb40 3 [tokio-runtime-w] returning 0x100c70000 2 write 3 [tokio-runtime-w] direct return: 4308008960, rsp 0x122852ab8 [2023-08-28T16:51:28Z INFO openobserve::service::db::metrics] Prometheus cluster leaders Cached 3 [tokio-runtime-w] getrandom 2 direct return: 97, rsp 0xffdcfab0 3 [tokio-runtime-w] direct return: 32, rsp 0x122852b18 4 [tokio-runtime-w] futex 5 [log flusher] mmap 4 [tokio-runtime-w] futex_wait_bitset [4 0x000000000789e068 2] 2 0x0 -1 5 [log flusher] mmap: addr 0x0000000000000000, length 0x2000, prot 0x3, flags 0x4022, fd -1, offset 0x0 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, blocking 5 [log flusher] returning 0x10085a000 4 [tokio-runtime-w] sleep interruptible (on "futex") 5 [log flusher] direct return: 4303724544, rsp 0x1017a2fa8 2 futex 3 [tokio-runtime-w] write 2 futex_wake [2 0x000000000789e068 1] 1 [2023-08-28T16:51:28Z INFO openobserve::service::db::functions] Start watching function 2 direct return: 1, rsp 0xffdcfb38 3 [tokio-runtime-w] direct return: 89, rsp 0x122852aa0 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 5 [log flusher] getrandom 4 [tokio-runtime-w] thread_wakeup: 4->4 blocked_on futex, RIP=0x1f3f2b539 5 [log flusher] direct return: 32, rsp 0x1017a3008 2 futex 5 [log flusher] futex 2 futex_wait_bitset [2 0x000000000789e068 2] 2 0x0 -1 5 [log flusher] futex_wait_bitset [5 0x000000000789e068 2] 2 0x0 -1 2 futex_bh: struct futex: 0xffffc00000c32980, blocking 5 [log flusher] futex_bh: struct futex: 0xffffc00000c32980, blocking 5 [log flusher] sleep interruptible (on "futex") 2 sleep interruptible (on "futex") 3 [tokio-runtime-w] futex 3 [tokio-runtime-w] futex_wake [3 0x000000000789e068 2] 1 3 [tokio-runtime-w] direct return: 1, rsp 0x122852b28 4 [tokio-runtime-w] write 2 futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 2 thread_wakeup: 2->2 blocked_on futex, RIP=0x1f3f2b539 [2023-08-28T16:51:28Z INFO openobserve::service::db::metrics] Start watching prometheus cluster leader 3 [tokio-runtime-w] futex 4 [tokio-runtime-w] direct return: 104, rsp 0x1063659a0 3 [tokio-runtime-w] futex_wait_bitset [3 0x000000000789e068 2] 2 0x0 -1 4 [tokio-runtime-w] futex 3 [tokio-runtime-w] direct return: -11, rsp 0x1228528b8 4 [tokio-runtime-w] futex_wake [4 0x000000000789e068 0] 1 3 [tokio-runtime-w] write 4 [tokio-runtime-w] direct return: 1, rsp 0x106365a28 [2023-08-28T16:51:28Z INFO openobserve::service::db::alerts] Start watching alerts 5 [log flusher] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 3 [tokio-runtime-w] direct return: 84, rsp 0x122852880 5 [log flusher] thread_wakeup: 5->5 blocked_on futex, RIP=0x1f3f2b539 3 [tokio-runtime-w] futex 4 [tokio-runtime-w] write 3 [tokio-runtime-w] futex_wake [3 0x000000000789e068 1] 1 3 [tokio-runtime-w] direct return: 0, rsp 0x122852908 [2023-08-28T16:51:28Z INFO openobserve::service::db::schema] Start watching stream schema 3 [tokio-runtime-w] futex 3 [tokio-runtime-w] futex_wait_bitset [3 0x000000000789e068 2] 2 0x0 -1 3 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, blocking 4 [tokio-runtime-w] direct return: 91, rsp 0x106364d40 3 [tokio-runtime-w] sleep interruptible (on "futex") 2 futex 5 [log flusher] futex 2 futex_wait_bitset [2 0x000000000789e068 2] 2 0x0 -1 5 [log flusher] futex_wait_bitset [5 0x000000000789e068 2] 2 0x0 -1 2 futex_bh: struct futex: 0xffffc00000c32980, blocking 5 [log flusher] futex_bh: struct futex: 0xffffc00000c32980, blocking 2 sleep interruptible (on "futex") 5 [log flusher] sleep interruptible (on "futex") 4 [tokio-runtime-w] futex 4 [tokio-runtime-w] futex_wake [4 0x000000000789e068 0] 1 4 [tokio-runtime-w] direct return: 1, rsp 0x106364dc8 3 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 3 [tokio-runtime-w] thread_wakeup: 3->3 blocked_on futex, RIP=0x1f3f2b539 3 [tokio-runtime-w] write 4 [tokio-runtime-w] futex [2023-08-28T16:51:28Z INFO openobserve::service::db::triggers] Start watching Triggers 4 [tokio-runtime-w] futex_wait_bitset [4 0x000000000789e068 2] 2 0x0 -1 3 [tokio-runtime-w] direct return: 88, rsp 0x122852bc0 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, blocking 3 [tokio-runtime-w] futex 4 [tokio-runtime-w] sleep interruptible (on "futex") 3 [tokio-runtime-w] futex_wake [3 0x000000000789e068 0] 1 3 [tokio-runtime-w] direct return: 1, rsp 0x122852c48 2 futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 2 thread_wakeup: 2->2 blocked_on futex, RIP=0x1f3f2b539 3 [tokio-runtime-w] futex 2 write 3 [tokio-runtime-w] futex_wait_bitset [3 0x000000000789e068 2] 2 0x0 -1 [2023-08-28T16:51:28Z INFO openobserve::service::db::alerts] Alerts Cached 3 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, blocking 2 direct return: 76, rsp 0xffdcfb40 3 [tokio-runtime-w] sleep interruptible (on "futex") 2 futex 2 futex_wake [2 0x000000000789e068 0] 1 2 direct return: 1, rsp 0xffdcfbc8 5 [log flusher] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 5 [log flusher] thread_wakeup: 5->5 blocked_on futex, RIP=0x1f3f2b539 5 [log flusher] write 2 futex [2023-08-28T16:51:28Z DEBUG sled::pagecache::iobuf] advancing offset within the current segment from 0 to 613 2 futex_wait_bitset [2 0x000000000789e068 2] 2 0x0 -1 5 [log flusher] direct return: 110, rsp 0x1017a2fc0 2 futex_bh: struct futex: 0xffffc00000c32980, blocking 5 [log flusher] futex 2 sleep interruptible (on "futex") 5 [log flusher] futex_wake [5 0x000000000789e068 0] 1 5 [log flusher] direct return: 1, rsp 0x1017a3048 4 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 4 [tokio-runtime-w] thread_wakeup: 4->4 blocked_on futex, RIP=0x1f3f2b539 4 [tokio-runtime-w] write 5 [log flusher] mmap [2023-08-28T16:51:28Z INFO openobserve::service::db::compact::retention] Start watching stream deleting 5 [log flusher] mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 4 [tokio-runtime-w] direct return: 105, rsp 0x106365f00 5 [log flusher] returning 0x100583000 4 [tokio-runtime-w] futex 5 [log flusher] direct return: 4300746752, rsp 0x1017a2d28 4 [tokio-runtime-w] futex_wake [4 0x000000000789e068 0] 1 5 [log flusher] mprotect 4 [tokio-runtime-w] direct return: 1, rsp 0x106365f88 5 [log flusher] mprotect: addr 0x0000000100584000, len 0x200000, prot 0x3 3 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 5 [log flusher] vmap_update_protections_locked: validate [0x100584000 0x100784000) 3 [tokio-runtime-w] thread_wakeup: 3->3 blocked_on futex, RIP=0x1f3f2b539 5 [log flusher] direct return: 0, rsp 0x1017a2d28 4 [tokio-runtime-w] write 5 [log flusher] rt_sigprocmask [2023-08-28T16:51:28Z INFO openobserve::service::db::syslog] Start watching SyslogServer settings 5 [log flusher] direct return: 0, rsp 0x1017a2d30 4 [tokio-runtime-w] direct return: 99, rsp 0x106365f50 5 [log flusher] clone3 4 [tokio-runtime-w] write 5 [log flusher] clone3: args_size: 88, pidfd: 0x0000000100783990, child_tid: 0x0000000100783990, parent_tid: 0x0000000100783990, exit_signal: 0, stack: 0x0000000100583000, stack_size: 0x1ff980, tls: 0x00000001007836c0 [2023-08-28T16:51:28Z INFO openobserve::service::db::alerts::destinations] Start watching alert destinations 5 [log flusher] direct return: 6, rsp 0x1017a2c58 4 [tokio-runtime-w] direct return: 110, rsp 0x106365a00 6 set_robust_list 4 [tokio-runtime-w] write 6 set_robust_list syscall with head 0x00000001007839a0 [2023-08-28T16:51:28Z INFO openobserve::service::db::syslog] Start watching syslog routes 6 direct return: 0, rsp 0x1007828e0 4 [tokio-runtime-w] direct return: 91, rsp 0x106365c60 5 [log flusher] rt_sigprocmask 4 [tokio-runtime-w] epoll_wait 5 [log flusher] direct return: 0, rsp 0x1017a2d30 4 [tokio-runtime-w] sleep interruptible (on "thread") 5 [log flusher] mmap 5 [log flusher] mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 5 [log flusher] returning 0x1000cb000 5 [log flusher] direct return: 4295798784, rsp 0x1017a2d28 6 rt_sigprocmask 5 [log flusher] mprotect 6 direct return: 0, rsp 0x1007828e0 5 [log flusher] mprotect: addr 0x00000001000cc000, len 0x200000, prot 0x3 6 sigaltstack 5 [log flusher] vmap_update_protections_locked: validate [0x1000cc000 0x1002cc000) 6 direct return: 0, rsp 0x100782818 5 [log flusher] direct return: 0, rsp 0x1017a2d28 6 mmap 5 [log flusher] rt_sigprocmask 6 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 5 [log flusher] direct return: 0, rsp 0x1017a2d30 6 returning 0x100005000 5 [log flusher] clone3 6 direct return: 4294987776, rsp 0x100782818 5 [log flusher] clone3: args_size: 88, pidfd: 0x00000001002cb990, child_tid: 0x00000001002cb990, parent_tid: 0x00000001002cb990, exit_signal: 0, stack: 0x00000001000cb000, stack_size: 0x1ff980, tls: 0x00000001002cb6c0 3 [tokio-runtime-w] write 5 [log flusher] direct return: 7, rsp 0x1017a2c58 [2023-08-28T16:51:28Z INFO openobserve::service::db::alerts::templates] Start watching alert templates 7 set_robust_list 3 [tokio-runtime-w] direct return: 104, rsp 0x122852dd0 7 set_robust_list syscall with head 0x00000001002cb9a0 6 mprotect 7 direct return: 0, rsp 0x1002ca8e0 6 mprotect: addr 0x0000000100005000, len 0x1000, prot 0x0 5 [log flusher] rt_sigprocmask 6 vmap_update_protections_locked: validate [0x100005000 0x100006000) 5 [log flusher] direct return: 0, rsp 0x1017a2d30 6 direct return: 0, rsp 0x100782818 5 [log flusher] mmap 6 sigaltstack 5 [log flusher] mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 6 direct return: 0, rsp 0x100782818 5 [log flusher] returning 0x100337000 6 prctl 5 [log flusher] direct return: 4298338304, rsp 0x1017a2d28 6 prctl: option 15, arg2 0x100782850, arg3 0xfe00, arg4 0x850, arg5 0xffffffff 7 rt_sigprocmask 6 [sled-io-0] direct return: 0, rsp 0x100782770 7 direct return: 0, rsp 0x1002ca8e0 6 [sled-io-0] mmap 7 sigaltstack 6 [sled-io-0] mmap: addr 0x0000000000000000, length 0x8000000, prot 0x0, flags 0x4022, fd -1, offset 0x0 7 direct return: 0, rsp 0x1002ca818 6 [sled-io-0] returning 0x139e62000 7 mmap 6 [sled-io-0] direct return: 5266350080, rsp 0x1007825f8 7 mmap: addr 0x0000000000000000, length 0x3000, prot 0x3, flags 0x20022, fd -1, offset 0x0 6 [sled-io-0] munmap 7 returning 0x100001000 6 [sled-io-0] munmap: addr 0x0000000139e62000, size 0x219e000 7 direct return: 4294971392, rsp 0x1002ca818 6 [sled-io-0] vmap_remove_intersection: q [0x139e62000 0x13c000000), r [0x139e62000 0x141e62000) 5 [log flusher] mprotect 6 [sled-io-0] direct return: 0, rsp 0x1007825f8 5 [log flusher] mprotect: addr 0x0000000100338000, len 0x200000, prot 0x3 6 [sled-io-0] munmap 5 [log flusher] vmap_update_protections_locked: validate [0x100338000 0x100538000) 6 [sled-io-0] munmap: addr 0x0000000140000000, size 0x1e62000 5 [log flusher] direct return: 0, rsp 0x1017a2d28 6 [sled-io-0] vmap_remove_intersection: q [0x140000000 0x141e62000), r [0x13c000000 0x141e62000) 7 mprotect 6 [sled-io-0] direct return: 0, rsp 0x1007825f8 7 mprotect: addr 0x0000000100001000, len 0x1000, prot 0x0 3 [tokio-runtime-w] futex 7 vmap_update_protections_locked: validate [0x100001000 0x100002000) 3 [tokio-runtime-w] futex_wake [3 0x000000000789e068 0] 1 7 direct return: 0, rsp 0x1002ca818 3 [tokio-runtime-w] direct return: 1, rsp 0x122852e58 2 futex_bh: struct futex: 0xffffc00000c32980, flags 0x1, rv 0 3 [tokio-runtime-w] futex 2 thread_wakeup: 2->2 blocked_on futex, RIP=0x1f3f2b539 3 [tokio-runtime-w] futex_wait [3 0x0000000122854488 1] 1 0x0 5 [log flusher] rt_sigprocmask 3 [tokio-runtime-w] futex_bh: struct futex: 0xffffc00000c32a40, blocking 5 [log flusher] direct return: 0, rsp 0x1017a2d30 3 [tokio-runtime-w] sleep interruptible (on "futex") 7 sigaltstack 6 [sled-io-0] mprotect 7 direct return: 0, rsp 0x1002ca818 6 [sled-io-0] mprotect: addr 0x000000013c000000, len 0x21000, prot 0x3 7 prctl 6 [sled-io-0] vmap_update_protections_locked: validate [0x13c000000 0x13c021000) 7 prctl: option 15, arg2 0x1002ca850, arg3 0xfe00, arg4 0x850, arg5 0xffffffff 6 [sled-io-0] direct return: 0, rsp 0x1007825f8 7 [sled-io-1] direct return: 0, rsp 0x1002ca770 6 [sled-io-0] sched_getaffinity 7 [sled-io-1] mmap 6 [sled-io-0] direct return: 8, rsp 0x1007826d8 7 [sled-io-1] mmap: addr 0x0000000000000000, length 0x8000000, prot 0x0, flags 0x4022, fd -1, offset 0x0 7 [sled-io-1] returning 0x12e780000 7 [sled-io-1] direct return: 5074583552, rsp 0x1002ca5f8 7 [sled-io-1] munmap 7 [sled-io-1] munmap: addr 0x000000012e780000, size 0x1880000 7 [sled-io-1] vmap_remove_intersection: q [0x12e780000 0x130000000), r [0x12e780000 0x136780000) 7 [sled-io-1] direct return: 0, rsp 0x1002ca5f8 7 [sled-io-1] munmap 7 [sled-io-1] munmap: addr 0x0000000134000000, size 0x2780000 7 [sled-io-1] vmap_remove_intersection: q [0x134000000 0x136780000), r [0x130000000 0x136780000) 7 [sled-io-1] direct return: 0, rsp 0x1002ca5f8 7 [sled-io-1] mprotect 7 [sled-io-1] mprotect: addr 0x0000000130000000, len 0x21000, prot 0x3 7 [sled-io-1] vmap_update_protections_locked: validate [0x130000000 0x130021000) 7 [sled-io-1] direct return: 0, rsp 0x1002ca5f8 7 [sled-io-1] sched_getaffinity 7 [sled-io-1] direct return: 8, rsp 0x1002ca6d8 5 [log flusher] clone3 5 [log flusher] clone3: args_size: 88, pidfd: 0x0000000100537990, child_tid: 0x0000000100537990, parent_tid: 0x0000000100537990, exit_signal: 0, stack: 0x0000000100337000, stack_size: 0x1ff980, tls: 0x00000001005376c0 5 [log flusher] direct return: 8, rsp 0x1017a2c58 8 set_robust_list 8 set_robust_list syscall with head 0x00000001005379a0 8 direct return: 0, rsp 0x1005368e0 5 [log flusher] rt_sigprocmask 5 [log flusher] direct return: 0, rsp 0x1017a2d30 5 [log flusher] mmap 5 [log flusher] mmap: addr 0x0000000000000000, length 0x201000, prot 0x0, flags 0x20022, fd -1, offset 0x0 5 [log flusher] returning 0x10093d000 5 [log flusher] direct return: 4304654336, rsp 0x1017a2d28 en1: assigned FE80::ACF4:38FF:FE23:D23F ```
rinor commented 1 year ago

Starting with clean storage deadlocks some time, other times not. While restarting/rebooting with an already existing storage deadlocks all the time (at least on my side). I'm starting to think that it might not be related to tokio per se but with sled since I have other issues on some other tests/apps involving sled and tokio (have yet to investigate and gather definitive results but it fails/deadlocks on some stuff related to sled pagecache and /dev/shm on nanos)

rinor commented 1 year ago

On a side note how does nanos handle /dev/shm (i.e: is it auto mounted/mmapped or its just on fs)

eyberg commented 1 year ago

we don't support that today as it typically implies multiple processes which we won't support; there have a been a few cases though where this gets used in a single process env for other reasons, which after a quick grep looks like that's what is going on here looks like it is configurable (just by setting a path?) in https://github.com/spacejam/sled/blob/005c023ca94d424d8e630125e4c21320ed160031/src/config.rs#L414

rinor commented 1 year ago

which after a quick grep looks like that's what is going on here looks like it is configurable (just by setting a path?)

yes it's configurable when needed, but in this case it's not being used at all. The purpose of that path is for temporary inmem sled default db https://github.com/spacejam/sled/blob/005c023ca94d424d8e630125e4c21320ed160031/src/config.rs#L253 and that's not the case.

rinor commented 1 year ago

This is mostly related to sled behavior under nanos. While the sled version used here is old (although that's the latest stable crate released) and known to have some issues with async and thread pools under certain conditions, the idea here was to check that nanos is behaving correctly (not openobserve or sled).

I'll close this issue since I'm unable to provide reproducible code that points to nanos issue and not program issue. I do have some services (unfortunately using this tech stack involving buggy sled) planned to target nanos that fail right now, so I may revisit this topic in the future and provide additional information.

rinor commented 5 months ago

I'll check again now with https://github.com/nanovms/nanos/pull/2024, since I had a couple of services having issues on smp and https://github.com/nanovms/nanos/pull/2024/commits/37053f6e3618e786de36bf08d7ab8e9d754eaabe fixes are relevant