Uploaded image for project: 'Indy Node'
  1. Indy Node
  2. INDY-1949

Node stops working without any services failure

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Complete
    • Priority: High
    • Resolution: Done
    • Affects Version/s: None
    • Fix Version/s: 1.6.83
    • Component/s: None
    • Labels:
    • Documentation Impact:
      Unset
    • Sprint:
      Ev-Node 19.02

      Description

      Environment:
      indy-node 1.6.753, 1.6.759 (w/o freshness)

      Steps to Reproduce:
      1. Setup the pool.
      2. In case of indy-node 1.6.759 set UPDATE_STATE_FRESHNESS = False in config.
      3. Restart pool.
      4. Start production load.

      Actual Results:

      • Two nodes were lagged on ~3K txns in domain ledger.
      • On both of lagged nodes there are no logs and metrics and validator-info updates after lagging:
        ubuntu@tokyoQALive18:~$ date && tail /var/log/indy/sandbox/Node18.log
        Wed Jan 16 14:39:39 UTC 2019
        2019-01-16 13:16:04,968|INFO|replica.py|Node18:3 processing checkpoint CHECKPOINT{'digest': 'd7d7366160e4cafa60a245ec0355cb187a8a07a2539749467592a330284bfa8a', 'instId': 3, 'viewNo': 1, 'seqNoEnd': 1100, 'seqNoStart': 1001} from Node19
        2019-01-16 13:16:04,968|INFO|replica.py|Node18:3 processing checkpoint CHECKPOINT{'digest': 'd7d7366160e4cafa60a245ec0355cb187a8a07a2539749467592a330284bfa8a', 'instId': 3, 'viewNo': 1, 'seqNoEnd': 1100, 'seqNoStart': 1001} from Node24
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 processing checkpoint CHECKPOINT{'digest': 'd7d7366160e4cafa60a245ec0355cb187a8a07a2539749467592a330284bfa8a', 'instId': 3, 'viewNo': 1, 'seqNoEnd': 1100, 'seqNoStart': 1001} from Node4
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 processing checkpoint CHECKPOINT{'digest': 'd7d7366160e4cafa60a245ec0355cb187a8a07a2539749467592a330284bfa8a', 'instId': 3, 'viewNo': 1, 'seqNoEnd': 1100, 'seqNoStart': 1001} from Node21
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 processing checkpoint CHECKPOINT{'digest': 'd7d7366160e4cafa60a245ec0355cb187a8a07a2539749467592a330284bfa8a', 'instId': 3, 'viewNo': 1, 'seqNoEnd': 1100, 'seqNoStart': 1001} from Node7
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 set watermarks as 1100 1400
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 removing stashed checkpoints: viewNo=1, seqNoStart=1001, seqNoEnd=1100
        2019-01-16 13:16:04,969|INFO|replica.py|Node18:3 cleaning up till (1, 1100)
        2019-01-16 13:16:04,979|INFO|replica.py|Node18:3 marked stable checkpoint (1001, 1100)
        2019-01-16 13:16:04,979|INFO|replica.py|Node18:3 processed 16 stashed checkpoints for (1001, 1100), 16 of them were stashed again

         

      • Uptime of indy-node services according to systemctl status is the same as on another nodes.
      • On not lagged nodes following warnings constantly appear:
        2019-01-16 14:09:19,243|WARNING|zstack.py|Node13 could not transmit message to Node3
        2019-01-16 14:09:19,246|WARNING|zstack.py|Node13 could not transmit message to Node18
        2019-01-16 14:09:19,314|WARNING|zstack.py|Node13 could not transmit message to Node3
        2019-01-16 14:09:19,317|WARNING|zstack.py|Node13 could not transmit message to Node18
      • The last message from lagged node in alive node logs:
        2019-01-16 13:16:04,025|INFO|replica.py|Node13:2 processing checkpoint CHECKPOINT{'digest': '9464514b3f4125249233b7c19418a19f1223195e669fc1c6305089cdddbcdcc4', 'seqNoEnd': 1100, 'viewNo': 1, 'instId': 2, 'seqNoStart': 1001} from Node18
      • There are no any errors or warnings in journalctl.

      Expected Results:

      • Node should not lag.
      • Even if node lags, it should continue writing logs and metrics.

      Logs and metrics:
      1) s3://qanodelogs/indy-1876/prod_load_14_01_2019 (Node13 is lagged here)
      To get logs, run following command on log processor machine:
      aws s3 cp --recursive s3://qanodelogs/indy-1876/prod_load_14_01_2019/ /home/ev/logs/indy-1876/prod_load_14_01_2019/
      2) s3://qanodelogs/indy-1949/prod_load_17_01_2019
      At the end of this test following nodes were lagged:
      Node3 3717
      Node13 63086
      Node17 73303
      Node2 56375
      Node25 28932
      Node18 3414
      Node20 69748

        Attachments

        1. 111.png
          111.png
          307 kB
        2. 2_node.PNG
          2_node.PNG
          362 kB
        3. image-2019-01-23-19-31-40-410.png
          image-2019-01-23-19-31-40-410.png
          406 kB
        4. image-2019-01-23-19-34-22-909.png
          image-2019-01-23-19-34-22-909.png
          336 kB

          Issue Links

            Activity

              People

              Assignee:
              Derashe Artem Obruchnikov
              Reporter:
              ozheregelya Olga Zheregelya
              Watchers:
              Alexander Shcherbakov, Artem Obruchnikov, Olga Zheregelya, Sergey Khoroshavin
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: