Skip to content
This repository has been archived by the owner on Nov 6, 2020. It is now read-only.

2.2.2-beta segfaulting in libpthread and corrupting DB when started as daemon #9991

Closed
c0deright opened this issue Nov 29, 2018 · 7 comments · Fixed by #10000
Closed

2.2.2-beta segfaulting in libpthread and corrupting DB when started as daemon #9991

c0deright opened this issue Nov 29, 2018 · 7 comments · Fixed by #10000
Labels
F1-panic 🔨 The client panics and exits without proper error handling. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Milestone

Comments

@c0deright
Copy link

c0deright commented Nov 29, 2018

UPDATE

Please see my comment #9991 (comment) for the cause of this mess. Looks like parity is segfaulting when command line argument daemon is present.


  • Parity Ethereum version: 2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
  • Operating system: Linux / Ubuntu 16.04 LTS
  • Installation: binary-release
  • Fully synchronized: yes
  • Network: ethereum
  • Restarted: yes

I had 2.2.1-beta running on my test machine (where I always test new builds on).

2.2.1 was being shutdown via systemd but it seems came across #9807:

2018-11-29 16:12:15  main INFO parity_ethereum::run  Finishing work, please wait...
2018-11-29 16:13:15  main WARN parity_ethereum::run  Shutdown is taking longer than expected.
2018-11-29 16:17:15  main WARN parity_ethereum::run  Shutdown timeout reached, exiting uncleanly.

2.2.2 was started via systemd and it seems 2.2.2 did error out segfaulted (see #9991 (comment)) immediately (Finishing work, please wait...):

2018-11-29 16:19:56  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:19:56  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:19:56  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:19:56  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:19:56  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:19:56  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:19:57  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:19:59  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:19:59  main INFO parity_ethereum::run  Finishing work, please wait...
2018-11-29 16:19:59  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:19:59  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:19:59  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:19:59  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:19:59  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:19:59  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:19:59  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:20:01  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:20:03  main INFO parity_ethereum::run  Finishing work, please wait...
2018-11-29 16:20:03  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:20:03  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:20:03  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:20:03  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:20:03  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:20:03  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:20:03  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:20:05  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:20:05  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.67 (40468300 wei/gas)
2018-11-29 16:20:06  main INFO parity_ethereum::run  Finishing work, please wait...
2018-11-29 16:20:06  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:20:06  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:20:06  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:20:06  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:20:06  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:20:06  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:20:06  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:20:08  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:20:08  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.67 (40468300 wei/gas)
2018-11-29 16:20:09  main INFO parity_ethereum::run  Finishing work, please wait...
2018-11-29 16:20:10  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:20:10  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:20:10  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:20:10  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:20:10  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:20:10  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:20:10  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:20:11  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:20:11  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.67 (40468300 wei/gas)
2018-11-29 16:20:13  main INFO parity_ethereum::run  Finishing work, please wait...

So systemd gave up because it had restarted parity too often (because parity segfaulted).

I then started parity by hand and after syncing some blocks I stopped it via ctrl+c:

2018-11-29 16:21:07  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:21:07  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:21:07  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:21:07  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:21:07  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:21:07  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:21:07  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:21:08  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 16:21:09  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.70 (40457984 wei/gas)
2018-11-29 16:21:13  IO Worker #2 INFO network  Public node URL: enode://bb4efd98d25a8a5a2ed6a25a60e1cba9e70486f4ad2a93c6dfcfb375dc3f498c895d1f2ea6fbcd19a21e069b861ea88429a87f3a0c967f530bf33efd97e6fffc@10.0.49.140:30303
2018-11-29 16:21:13  IO Worker #2 INFO import  Syncing #6794980 0x4d28…f601     0.20 blk/s   12.2 tx/s    1.5 Mgas/s     35+    1 Qed  #6795017    6/10 peers   199 KiB chain 78 MiB db 3 MiB queue 74 KiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 16:21:18  IO Worker #1 INFO import  Syncing #6794984 0xcc32…b87b     0.80 blk/s  129.7 tx/s    5.4 Mgas/s     32+    1 Qed  #6795018    7/10 peers   263 KiB chain 100 MiB db 3 MiB queue 74 KiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 16:21:23  IO Worker #2 INFO import  Syncing #6794990 0xae3d…3e95     1.20 blk/s  106.3 tx/s    8.3 Mgas/s     26+    1 Qed  #6795018   10/10 peers   336 KiB chain 101 MiB db 2 MiB queue 74 KiB sync  RPC:  0 conn,    0 req/s,   18 µs
2018-11-29 16:21:28  IO Worker #0 INFO import  Syncing #6794995 0x579e…c1a5     1.00 blk/s  121.6 tx/s    8.0 Mgas/s     21+    1 Qed  #6795018   10/10 peers   347 KiB chain 102 MiB db 2 MiB queue 74 KiB sync  RPC:  0 conn,    0 req/s,   18 µs
2018-11-29 16:22:42  main INFO parity_ethereum::run  Finishing work, please wait...

According to #9991 (comment) (see the timestamps) this was not a clean shutdown eighter but a segfault, again.

Upon next start parity complains about block #6794995:

2018-11-29 16:22:53  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:22:53  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:22:53  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:22:53  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:22:53  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:22:53  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:22:54  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:22:56  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.70 (40457984 wei/gas)
2018-11-29 16:22:57  Verifier #0 WARN client  Block import failed for #6794995 (0x579e…c1a5)
Error: Error(Trie(InvalidStateRoot(0xeddfd1b61060703affcaf408450e1a9cec02fd8f989e6bc9c7343d4d1c3494a8)), State { next_error: None, backtrace: InternalBacktrace { backtrace: None } })
2018-11-29 16:22:57  Verifier #0 ERROR client  
Bad block detected: Error(Trie(InvalidStateRoot(0xeddfd1b61060703affcaf408450e1a9cec02fd8f989e6bc9c7343d4d1c3494a8)), State { next_error: None, backtrace: InternalBacktrace { backtrace: None } })
RLP:
[..] very long lines with many debug infos [..]

That's when shit hit the fan.

Upon next start parity is churning on block #6097606 (which is just ~697432 lower than just a couple of seconds before):

2018-11-29 16:26:12  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 16:26:12  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 16:26:12  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 16:26:12  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 16:26:12  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 16:26:12  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 16:26:12  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 16:26:13  main WARN ethcore::client::client  State root not found for block #6097606 (583863c1ed11889b7b9029c780d987e579c03e389e37d6eac390a1652decbe7a)
2018-11-29 16:26:14  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$117.53 (40516504 wei/gas)
2018-11-29 16:26:18  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6097860    9/10 peers   82 KiB chain 63 MiB db 0 bytes queue 15 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 16:26:18  IO Worker #3 INFO network  Public node URL: enode://bb4efd98d25a8a5a2ed6a25a60e1cba9e70486f4ad2a93c6dfcfb375dc3f498c895d1f2ea6fbcd19a21e069b861ea88429a87f3a0c967f530bf33efd97e6fffc@10.0.49.140:30303
2018-11-29 16:26:23  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6098654    9/10 peers   82 KiB chain 63 MiB db 0 bytes queue 23 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:28  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6099639   10/10 peers   343 KiB chain 63 MiB db 0 bytes queue 16 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:33  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6100530   10/10 peers   510 KiB chain 63 MiB db 0 bytes queue 17 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:38  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6101829   10/10 peers   1 MiB chain 63 MiB db 0 bytes queue 12 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:43  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6102964   10/10 peers   1 MiB chain 63 MiB db 0 bytes queue 22 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:48  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6104115   10/10 peers   2 MiB chain 63 MiB db 0 bytes queue 26 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:53  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6105830   10/10 peers   2 MiB chain 63 MiB db 0 bytes queue 16 MiB sync  RPC:  0 conn,    0 req/s,   28 µs
2018-11-29 16:26:58  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6107544   10/10 peers   2 MiB chain 63 MiB db 0 bytes queue 20 MiB sync  RPC:  0 conn,    0 req/s,   28 µs

Even eth_blockNumber is reporting now 6097606 instead of 6794995.

I think my database is f*cked right now.

So is this a regression in 2.2.2 or a result of 2.2.1 not being shutdown cleanly because of #9807?

config.toml

[parity]
no_download = true

[snapshots]
disable_periodic = true

[ui]
disable = true

[websockets]
disable = true

[ipc]
disable = true

[rpc]
disable = false
hosts = ["http://foobar:8545"]
interface = "0.0.0.0"
apis = ["rpc", "web3", "eth", "net", "personal", "parity", "parity_set", "parity_accounts", "traces"]

[network]
min_peers = 10
max_peers = 15

[mining]
tx_queue_per_sender = 1024

[footprint]
tracing = "on"
db_compaction = "ssd"
pruning = "fast"
cache_size = 2000

[misc]
log_file = "/home/foobar/.local/share/io.parity.ethereum/log.txt"
logging  = "own_tx=trace"
@c0deright
Copy link
Author

c0deright commented Nov 29, 2018

I just found the following messages in dmesg/syslog:

Nov 29 16:19:59 eth-test kernel: [3648689.407842] parity-binary[4980]: segfault at 7fc9407fe9d0 ip 00007fc9451438d9 sp 00007ffde29e5ca8 error 4 in libpthread-2.23.so[7fc94513b000+18000]
Nov 29 16:19:59 eth-test kernel: [3648689.626899] parity-binary[4981]: segfault at 7fc9433ff9d0 ip 00007fc945143855 sp 00007ffde29ea198 error 4 in libpthread-2.23.so[7fc94513b000+18000]
Nov 29 16:20:01 eth-test kernel: [3648691.551427] parity-binary[5038]: segfault at 7f7a4edfe9d0 ip 00007f7a536538d9 sp 00007fff7c30e188 error 4 in libpthread-2.23.so[7f7a5364b000+18000]
Nov 29 16:20:03 eth-test kernel: [3648693.174704] parity-binary[5039]: segfault at 7f7a517ff9d0 ip 00007f7a53653855 sp 00007fff7c312678 error 4 in libpthread-2.23.so[7f7a5364b000+18000]
Nov 29 16:20:05 eth-test kernel: [3648695.084759] parity-binary[5076]: segfault at 7f63533fe9d0 ip 00007f63580f48d9 sp 00007ffe35bae678 error 4 in libpthread-2.23.so[7f63580ec000+18000]
Nov 29 16:20:06 eth-test kernel: [3648696.699143] parity-binary[5077]: segfault at 7f63563ff9d0 ip 00007f63580f4855 sp 00007ffe35bb2b68 error 4 in libpthread-2.23.so[7f63580ec000+18000]
Nov 29 16:20:08 eth-test kernel: [3648698.320487] parity-binary[5114]: segfault at 7f560bdfe9d0 ip 00007f56106208d9 sp 00007ffe0baf3e38 error 4 in libpthread-2.23.so[7f5610618000+18000]
Nov 29 16:20:09 eth-test kernel: [3648699.937200] parity-binary[5115]: segfault at 7f560e7ff9d0 ip 00007f5610620855 sp 00007ffe0baf8328 error 4 in libpthread-2.23.so[7f5610618000+18000]
Nov 29 16:20:11 eth-test kernel: [3648701.594056] parity-binary[5153]: segfault at 7f6fffdfe9d0 ip 00007f70049548d9 sp 00007ffffaf71388 error 4 in libpthread-2.23.so[7f700494c000+18000]
Nov 29 16:20:13 eth-test kernel: [3648703.419702] parity-binary[5154]: segfault at 7f7002bff9d0 ip 00007f7004954855 sp 00007ffffaf75878 error 4 in libpthread-2.23.so[7f700494c000+18000]
Nov 29 16:21:08 eth-test kernel: [3648758.765773] parity-binary[5236]: segfault at 7f4ba69fa9d0 ip 00007f4baa2aa8d9 sp 00007ffd1c81a9a8 error 4 in libpthread-2.23.so[7f4baa2a2000+18000]
Nov 29 16:22:42 eth-test kernel: [3648852.642795] parity-binary[5237]: segfault at 7f4ba87fe9d0 ip 00007f4baa2aa855 sp 00007ffd1c81ee98 error 4 in libpthread-2.23.so[7f4baa2a2000+18000]

Just for clarification: parity-binary is a symlink on my machine:

ls -ln parity-binary  parity-releases/
lrwxrwxrwx 1 1000 1000 33 Nov 29 16:19 parity-binary -> parity-releases/parity-2.2.2-beta

parity-releases/:
total 86628
-rwxr-xr-x 1 1000 1000 44254976 Nov 14 23:59 parity-2.2.1-beta
-rwxr-xr-x 1 1000 1000 44447488 Nov 29 15:42 parity-2.2.2-beta

systemd service file

/etc/systemd/system/parity-ethereum.service for reference:

[Unit]
Description=Ethereum Parity daemon
After=network.target

[Service]
User=foobar
Group=foobar

Type=forking
PIDFile=/home/foobar/.local/share/io.parity.ethereum/parity.pid
ExecStart=/usr/bin/eatmydata -- /home/foobar/parity-binary daemon /home/foobar/.local/share/io.parity.ethereum/parity.pid

Restart=always
PrivateTmp=true
TimeoutStopSec=900s
TimeoutStartSec=3s
StartLimitInterval=120s
StartLimitBurst=5

[Install]
WantedBy=multi-user.target

@c0deright c0deright changed the title 2.2.1-beta → 2.2.2-beta corrupting database 2.2.1-beta → 2.2.2-beta corrupting database / segfault in libpthread Nov 29, 2018
@c0deright
Copy link
Author

c0deright commented Nov 29, 2018

Starting 2.2.1 (or 2.2.2 -- same result) again it looks like I'm now stuck at block #6097606

2018-11-29 17:15:23  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.1-beta-5c56fc5-20181114/x86_64-linux-gnu/rustc1.30.1
2018-11-29 17:15:23  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 17:15:23  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 17:15:23  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 17:15:23  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 17:15:23  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 17:15:23  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 17:15:24  main WARN ethcore::client::client  State root not found for block #6097606 (583863c1ed11889b7b9029c780d987e579c03e389e37d6eac390a1652decbe7a)
2018-11-29 17:15:25  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$118.39 (40222188 wei/gas)
2018-11-29 17:15:30  IO Worker #1 INFO network  Public node URL: enode://bb4efd98d25a8a5a2ed6a25a60e1cba9e70486f4ad2a93c6dfcfb375dc3f498c895d1f2ea6fbcd19a21e069b861ea88429a87f3a0c967f530bf33efd97e6fffc@10.0.49.140:30303
2018-11-29 17:15:35  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6098527    8/10 peers    515 KiB chain   63 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:15:45  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6099638   10/10 peers    852 KiB chain   63 MiB db  0 bytes queue   46 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:15:55  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6101416   10/10 peers      1 MiB chain   63 MiB db  0 bytes queue   31 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:16:05  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6103448   10/10 peers      2 MiB chain   63 MiB db  0 bytes queue   18 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:16:10  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6104179   10/10 peers      3 MiB chain   63 MiB db  0 bytes queue   34 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:16:20  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6106433   10/10 peers      3 MiB chain   63 MiB db  0 bytes queue   50 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 17:16:30  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6109767   10/10 peers      4 MiB chain   63 MiB db  0 bytes queue   29 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:16:40  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6112688   10/10 peers      4 MiB chain   63 MiB db  0 bytes queue   29 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:16:50  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6116085    9/10 peers      5 MiB chain   63 MiB db  0 bytes queue    9 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:00  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6119069    9/10 peers      5 MiB chain   63 MiB db  0 bytes queue    9 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:10  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6121801    9/10 peers      7 MiB chain   63 MiB db  0 bytes queue    9 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:20  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6124340    8/10 peers      7 MiB chain   63 MiB db  0 bytes queue   17 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:30  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6126404    8/10 peers      7 MiB chain   63 MiB db  0 bytes queue   41 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:40  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6128880    8/10 peers      7 MiB chain   63 MiB db  0 bytes queue   39 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:17:50  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6130150    9/10 peers      8 MiB chain   63 MiB db  0 bytes queue  111 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:00  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6130150    9/10 peers     10 MiB chain   63 MiB db  0 bytes queue  287 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:10  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6135833    9/10 peers     11 MiB chain   63 MiB db  0 bytes queue   15 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:15  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6136786    9/10 peers     11 MiB chain   63 MiB db  0 bytes queue   39 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:25  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6098812    9/10 peers     11 MiB chain   63 MiB db  0 bytes queue   55 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:35  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6101034    9/10 peers     11 MiB chain   63 MiB db  0 bytes queue   50 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:45  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6103479   10/10 peers     14 MiB chain   63 MiB db  0 bytes queue   43 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:18:55  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6105956    9/10 peers     15 MiB chain   63 MiB db  0 bytes queue   49 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:05  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6109131    9/10 peers     17 MiB chain   63 MiB db  0 bytes queue   20 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:15  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6111067   10/10 peers     18 MiB chain   63 MiB db  0 bytes queue   56 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:25  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6114340   10/10 peers     19 MiB chain   63 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:35  IO Worker #2 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6117132   10/10 peers     19 MiB chain   63 MiB db  0 bytes queue   13 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:45  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6119830   10/10 peers     19 MiB chain   63 MiB db  0 bytes queue   42 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:19:55  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6122435   10/10 peers     20 MiB chain   63 MiB db  0 bytes queue   29 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:20:05  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6125069   10/10 peers     21 MiB chain   63 MiB db  0 bytes queue   32 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:20:15  IO Worker #3 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6127388   10/10 peers     21 MiB chain   63 MiB db  0 bytes queue   27 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:20:25  IO Worker #1 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6130149   10/10 peers     22 MiB chain   63 MiB db  0 bytes queue   12 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs
2018-11-29 17:20:35  IO Worker #0 INFO import  Syncing #6097606 0x5838…be7a     0.00 blk/s    0.0 tx/s    0 Mgas/s      0+    0 Qed  #6132500   10/10 peers     23 MiB chain   63 MiB db  0 bytes queue   20 MiB sync  RPC:  0 conn,    0 req/s, 1000 µs

@c0deright
Copy link
Author

Ended up copying complete blockchain from a 2.1.6-stable client to get out of this mess.

@c0deright
Copy link
Author

c0deright commented Nov 29, 2018

@5chdn

More Segfaults

Dumped a clean copy of ~/.local/share/io.parity.ethereum from a 2.1.6-stable node to my test machine.

No Problems: Running parity in foreground

Running parity via parity-2.2.2-beta without parameters is perfectly fine. No issues, no segfaults, ctrl+c works, parity is shutting down clean. Did repeat that several times, no issues at all.

Segfaults: Running parity as daemon

Running parity via parity-2.2.2-beta daemon /foo/parity.pid results in the following console output:

% parity-2.2.2-beta daemon /home/foobar/.local/share/io.parity.ethereum/parity.pid
Loading config file from /home/foobar/.local/share/io.parity.ethereum/config.toml
2018-11-29 22:35:19  main INFO parity_ethereum::run  Starting Parity-Ethereum/v2.2.2-beta-78ceec6-20181129/x86_64-linux-gnu/rustc1.30.1
2018-11-29 22:35:19  main INFO parity_ethereum::run  Keys path /home/foobar/.local/share/io.parity.ethereum/keys/ethereum
2018-11-29 22:35:19  main INFO parity_ethereum::run  DB path /home/foobar/.local/share/io.parity.ethereum/chains/ethereum/db/906a34e69aec8c0d
2018-11-29 22:35:19  main INFO parity_ethereum::run  State DB configuration: fast +Trace
2018-11-29 22:35:19  main INFO parity_ethereum::run  Operating mode: active
2018-11-29 22:35:19  main WARN parity_ethereum::run  Warning: Warp Sync is disabled because tracing is turned on.
2018-11-29 22:35:20  main INFO ethcore_service::service  Configured for Foundation using Ethash engine
2018-11-29 22:35:21  main INFO parity_ethereum::run  Running as a daemon process!
2018-11-29 22:35:22  tokio-runtime-worker-1 INFO miner  Updated conversion rate to Ξ1 = US$115.56 (41207204 wei/gas)
2018-11-29 22:35:26  IO Worker #0 INFO network  Public node URL: enode://bb4efd98d25a8a5a2ed6a25a60e1cba9e70486f4ad2a93c6dfcfb375dc3f498c895d1f2ea6fbcd19a21e069b861ea88429a87f3a0c967f530bf33efd97e6fffc@10.0.49.140:30303
2018-11-29 22:35:26  IO Worker #1 INFO import  Syncing #6795733 0xeaf1…b10e     0.80 blk/s   47.6 tx/s    4.9 Mgas/s    248+    1 Qed  #6795983    6/10 peers   199 KiB chain 67 MiB db 14 MiB queue 20 MiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 22:35:31  IO Worker #0 INFO import  Syncing #6795744 0xb33d…4e25     2.20 blk/s  166.5 tx/s   15.6 Mgas/s    847+    1 Qed  #6796593    7/10 peers   431 KiB chain 68 MiB db 47 MiB queue 912 KiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 22:35:36  IO Worker #1 INFO import  Syncing #6795753 0x5b5f…d78b     1.80 blk/s  153.0 tx/s   12.8 Mgas/s    838+    1 Qed  #6796593   11/15 peers   1 MiB chain 69 MiB db 47 MiB queue 912 KiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 22:35:41  IO Worker #2 INFO import  Syncing #6795760 0x6981…f926     1.40 blk/s  112.7 tx/s    8.4 Mgas/s    831+    1 Qed  #6796593   11/15 peers   3 MiB chain 70 MiB db 46 MiB queue 912 KiB sync  RPC:  0 conn,    0 req/s,    0 µs
2018-11-29 22:35:46  IO Worker #1 INFO import  Syncing #6795767 0x27dd…0073     1.40 blk/s  129.9 tx/s   10.4 Mgas/s    824+    1 Qed  #6796593   11/15 peers   4 MiB chain 71 MiB db 46 MiB queue 912 KiB sync  RPC:  0 conn,    0 req/s,    0 µs

WTF?

Why is parity printing debug messages to console when it's instructed to fork to background? It didn't do this is 2.2.1.

At 2018-11-29 22:35:21 when parity is logging Running as a daemon process! the kernel logged a segfault:

Nov 29 22:35:21 eth-test kernel: [  598.698006] parity-2.2.2-be[2046]: segfault at 7f73397fe9d0 ip 00007f733e6788d9 sp 00007ffc03f6b888 error 4 in libpthread-2.23.so[7f733e670000+18000]

After that a second parity process (PID 2047) is still running (in background) but does not consume CPU or IO nor is it writing to the logfile.

Sending SIGTERM to that stray process results in another SEGFAULT being logged:

Nov 29 22:44:26 eth-test kernel: [ 1143.977759] parity-2.2.2-be[2047]: segfault at 7f733c7ff9d0 ip 00007f733e678855 sp 00007ffc03f6fd78 error 4 in libpthread-2.23.so[7f733e670000+18000]

Something is f*cked up with threading/forking in 2.2.2

@c0deright c0deright changed the title 2.2.1-beta → 2.2.2-beta corrupting database / segfault in libpthread 2.2.2-beta segfaulting in libpthread and corrupting DB when started as daemon Nov 29, 2018
@5chdn
Copy link
Contributor

5chdn commented Nov 29, 2018

Segfaults: Running parity as daemon

probably from #9946? cc @seunlanlege

@5chdn 5chdn added this to the 2.3 milestone Nov 29, 2018
@5chdn 5chdn added P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible. M4-core ⛓ Core client code / Rust. F1-panic 🔨 The client panics and exits without proper error handling. labels Nov 29, 2018
@ordian ordian mentioned this issue Nov 30, 2018
@c0deright
Copy link
Author

c0deright commented Nov 30, 2018

Thanks for the fix.

I hope this doesn't sound picky but this could have been prevented in the stable release if it wouldn't have been backported to/released in beta and stable at the same time.

Maybe it's better to have some fixes at least in one beta release before they are backported to the stable tree. This way my bug report in the beta release might have prevented the bug in the stable release. Just saying. Don't know whether this is feasible or not.

@5chdn
Copy link
Contributor

5chdn commented Nov 30, 2018

Thanks for your feedback.

Honestly, it's a zero-sum game; we backported it to stable because it was fixing a bug. That this introduced another bug, is unfortunate but can happen anytime.

I'm hesitant if holding back fixes for the stable branch improves stability.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
F1-panic 🔨 The client panics and exits without proper error handling. M4-core ⛓ Core client code / Rust. P2-asap 🌊 No need to stop dead in your tracks, however issue should be addressed as soon as possible.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants