Uploaded image for project: 'Fabric'
  1. Fabric
  2. FAB-18191

Upgrade - peer node upgrade-dbs command fails if entire database directory cannot be deleted

    XMLWordPrintable

Details

    Description

      When running upgrade-dbs command on peer, the command seems to be trying to delete the directory /data/peer/ledgersData/stateLeveldb. When running in production loads for a leveldb peer, the stateleveldb directory would probably be a mounted directory, which means that the directory cannot be deleted but the contents of the directory can be. Can the code be changed to accomodate the mounted directory scenario?

       

      Example error from a run:

      ...
2020-08-26 20:07:57.958 UTC [msp] setupSigningIdentity -> DEBU 019 Signing identity expires at 2030-08-24 19:57:00 +0000 UTC
2020-08-26 20:07:57.976 UTC [kvledger.util] CreateDirIfMissing -> DEBU 01a CreateDirIfMissing [/data/peer/ledgersData/fileLock/]
2020-08-26 20:07:57.976 UTC [kvledger.util] logDirStatus -> DEBU 01b Before creating dir - [/data/peer/ledgersData/fileLock/] exists
2020-08-26 20:07:57.976 UTC [kvledger.util] logDirStatus -> DEBU 01c After creating dir - [/data/peer/ledgersData/fileLock/] exists
2020-08-26 20:07:58.111 UTC [kvledger] UpgradeDBs -> INFO 01d Ledger data folder from config = [/data/peer/ledgersData]
2020-08-26 20:07:58.111 UTC [kvledger] UpgradeIDStoreFormat -> DEBU 01e Attempting to upgrade idStore data format to current format 2.0
2020-08-26 20:07:58.111 UTC [kvledger.util] CreateDirIfMissing -> DEBU 01f CreateDirIfMissing [/data/peer/ledgersData/ledgerProvider/]
2020-08-26 20:07:58.111 UTC [kvledger.util] logDirStatus -> DEBU 020 Before creating dir - [/data/peer/ledgersData/ledgerProvider/] exists
2020-08-26 20:07:58.111 UTC [kvledger.util] logDirStatus -> DEBU 021 After creating dir - [/data/peer/ledgersData/ledgerProvider/] exists
2020-08-26 20:07:58.265 UTC [kvledger] upgradeFormat -> DEBU 022 Format is current, nothing to do
2020-08-26 20:07:58.265 UTC [kvledger] dropStateLevelDB -> INFO 023 Dropping StateLevelDB at location [/data/peer/ledgersData/stateLeveldb] ...if present
Error: unlinkat /data/peer/ledgersData/stateLeveldb: device or resource busy
Usage:
peer node upgrade-dbs [flags]
 
Flags:
-h, --help help for upgrade-dbs

       

      Example docker run to explain the problem:

      $ docker run -it -v ${PWD}/data:/data/peer/ledgersData/stateLeveldb -e CORE_PEER_FILESYSTEMPATH=/data/peer hyperledger/fabric-peer:2.1.1 sh
/ # peer node start
2020-08-26 21:06:15.141 UTC [nodeCmd] serve -> INFO 001 Starting peer:
 Version: 2.1.1
 Commit SHA: 6393adb
 Go version: go1.14.1
 OS/Arch: linux/amd64
 Chaincode:
  Base Docker Label: org.hyperledger.fabric
  Docker Namespace: hyperledger
2020-08-26 21:06:15.141 UTC [peer] getLocalAddress -> INFO 002 Auto-detected peer address: 172.17.0.3:7051
2020-08-26 21:06:15.141 UTC [peer] getLocalAddress -> INFO 003 Host is 0.0.0.0 , falling back to auto-detected address: 172.17.0.3:7051
2020-08-26 21:06:15.152 UTC [nodeCmd] initGrpcSemaphores -> INFO 004 concurrency limit for endorser service is 2500
2020-08-26 21:06:15.152 UTC [nodeCmd] initGrpcSemaphores -> INFO 005 concurrency limit for deliver service is 2500
2020-08-26 21:06:15.166 UTC [ledgermgmt] NewLedgerMgr -> INFO 006 Initializing LedgerMgr
2020-08-26 21:06:15.183 UTC [leveldbhelper] openDBAndCheckFormat -> INFO 007 DB is empty Setting db format as 2.0
2020-08-26 21:06:15.184 UTC [fsblkstorage] NewProvider -> INFO 008 Creating new file ledger directory at /data/peer/ledgersData/chains/chains
2020-08-26 21:06:15.194 UTC [leveldbhelper] openDBAndCheckFormat -> INFO 009 DB is empty Setting db format as 2.0
2020-08-26 21:06:15.225 UTC [leveldbhelper] openDBAndCheckFormat -> INFO 00a DB is empty Setting db format as 2.0
2020-08-26 21:06:15.225 UTC [ledgermgmt] NewLedgerMgr -> INFO 00b Initialized LedgerMgr
2020-08-26 21:06:15.236 UTC [gossip.service] New -> INFO 00c Initialize gossip with endpoint 172.17.0.3:7051
2020-08-26 21:06:15.239 UTC [gossip.gossip] New -> INFO 00d Creating gossip service with self membership of Endpoint: , InternalEndpoint: 172.17.0.3:7051, PKI-ID: 0d46737a45894d123895671221dbaddf8480fb0364f404be3aed491df442945f, Metadata: 
2020-08-26 21:06:15.239 UTC [gossip.gossip] New -> WARN 00e External endpoint is empty, peer will not be accessible outside of its organization
2020-08-26 21:06:15.240 UTC [gossip.gossip] start -> INFO 00f Gossip instance 172.17.0.3:7051 started
2020-08-26 21:06:15.240 UTC [lifecycle] InitializeLocalChaincodes -> INFO 010 Initialized lifecycle cache with 0 already installed chaincodes
2020-08-26 21:06:15.240 UTC [nodeCmd] computeChaincodeEndpoint -> INFO 011 Entering computeChaincodeEndpoint with peerHostname: 172.17.0.3
2020-08-26 21:06:15.241 UTC [nodeCmd] computeChaincodeEndpoint -> INFO 012 Exit with ccEndpoint: 172.17.0.3:7052
2020-08-26 21:06:15.241 UTC [nodeCmd] createChaincodeServer -> WARN 013 peer.chaincodeListenAddress is not set, using 172.17.0.3:7052
2020-08-26 21:06:15.247 UTC [sccapi] DeploySysCC -> INFO 014 deploying system chaincode 'lscc'
2020-08-26 21:06:15.247 UTC [sccapi] DeploySysCC -> INFO 015 deploying system chaincode 'cscc'
2020-08-26 21:06:15.247 UTC [sccapi] DeploySysCC -> INFO 016 deploying system chaincode 'qscc'
2020-08-26 21:06:15.247 UTC [sccapi] DeploySysCC -> INFO 017 deploying system chaincode '_lifecycle'
2020-08-26 21:06:15.248 UTC [nodeCmd] serve -> INFO 018 Deployed system chaincodes
2020-08-26 21:06:15.248 UTC [discovery] NewService -> INFO 019 Created with config TLS: false, authCacheMaxSize: 1000, authCachePurgeRatio: 0.750000
2020-08-26 21:06:15.248 UTC [nodeCmd] registerDiscoveryService -> INFO 01a Discovery service activated
2020-08-26 21:06:15.248 UTC [nodeCmd] serve -> INFO 01b Starting peer with ID=[jdoe], network ID=[dev], address=[172.17.0.3:7051]
2020-08-26 21:06:15.248 UTC [nodeCmd] serve -> INFO 01c Started peer with ID=[jdoe], network ID=[dev], address=[172.17.0.3:7051]
2020-08-26 21:06:15.248 UTC [kvledger] LoadPreResetHeight -> INFO 01d Loading prereset height from path [/data/peer/ledgersData/chains]
2020-08-26 21:06:15.248 UTC [fsblkstorage] preResetHtFiles -> INFO 01e No active channels passed
^C2020-08-26 21:06:17.563 UTC [nodeCmd] func1 -> INFO 01f Received signal: 2 (interrupt)
2020-08-26 21:06:17.563 UTC [gossip.gossip] Stop -> INFO 020 Stopping gossip
2020-08-26 21:06:17.563 UTC [gossip.discovery] Stop -> INFO 021 Stopping
2020-08-26 21:06:17.563 UTC [gossip.discovery] Stop -> INFO 022 Stopped
2020-08-26 21:06:17.563 UTC [gossip.comm] Stop -> INFO 023 Stopping
2020-08-26 21:06:17.564 UTC [gossip.comm] Stop -> INFO 024 Stopped
/ # rm -rf /data/peer/ledgersData/
bookkeeper/      configHistory/   historyLeveldb/  pvtdataStore/
chains/          fileLock/        ledgerProvider/  stateLeveldb/
/ # rm -rf /data/peer/ledgersData/stateLeveldb
rm: can't remove '/data/peer/ledgersData/stateLeveldb': Resource busy
/ # 
/ # rm -rf /data/peer/ledgersData/stateLeveldb/*

      Attachments

        Activity

          People

            wenjian Wenjian Qiao
            dbshah Dhyey Shah
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: