jonspieg

Can someone please help with this 🙏 I'm still unable to start crashplan

Thanks for the tip. I think I copied the interesting part of the log file, if anyone can help me figure out what's stopping the service: [01.29.24 01:23:06.973 INFO main com.backup42.service.CPService] ***************************************************************************************** [01.29.24 01:23:06.973 INFO main com.backup42.service.CPService] READY! Authorized Listening ports are HTTP=4244 in 2.952 s [01.29.24 01:23:06.974 INFO main com.backup42.service.CPService] ***************************************************************************************** [01.29.24 01:23:06.981 INFO vice RUNNING .service.auth.AccessTokenService] ACCESS_TOKEN:: Access token retrieved and stored successfully. [01.29.24 01:23:06.982 INFO vice RUNNING .service.auth.AccessTokenService] ACCESS_TOKEN:: New access token has been retrieved. Reconnecting all storage nodes. [01.29.24 01:23:06.982 INFO vice RUNNING .common.peer.PeerAgentController] Attempt connect to guid=694528144554080257 [01.29.24 01:23:06.982 INFO vice RUNNING .common.peer.PeerAgentController] Attempt connect to guid=4200 [01.29.24 01:23:06.982 INFO vice RUNNING .common.peer.PeerAgentController] Attempt connect to guid=42 [01.29.24 01:23:07.366 INFO EventBus 0 42.manifest.ManifestJarValidator] Validated certificate path [01.29.24 01:23:07.366 WARN EventBus 0 42.manifest.ManifestJarValidator] Unable to validate certificate revocation status., [java.security.cert.CertPathValidatorException: Could not determine revocation status] [01.29.24 01:23:07.366 INFO EventBus 0 42.manifest.ManifestJarValidator] Validated certificate chain [01.29.24 01:23:07.367 INFO EventBus 0 2.manifest.InstallationValidator] Validated Manifest JAR [01.29.24 01:23:07.931 INFO EventBus 0 2.manifest.InstallationValidator] Completed file validation: Success{payload=null} [01.29.24 01:23:07.931 INFO EventBus 0 2.manifest.InstallationValidator] Installation validation result: Success{payload=null} [01.29.24 01:23:07.932 INFO EventBus 0 ction.TamperDetectionServiceImpl] TAMPER:: Finished after 986.2 ms with result: Success{payload=null} [01.29.24 01:23:08.709 WARN DefaultGroup .code42.messaging.peer.PeerGroup] PG::DefaultGroup PeerException attempting to connect. RemotePeer-[guid=694528144554080257, state=NEW]; Session-[localID=1150475083128518290, remoteID=1150475083128518290, closed=false, expiration=null, remoteIdentity=ENDPOINT, DIRECT] e=com.code42.peer.exception.InvalidConnectStateException: RP:: Illegal DISCONNECTED state attempt, session is open RemotePeer-[guid=694528144554080257, state=NEW]; Session-[localID=1150475083128518290, remoteID=1150475083128518290, closed=false, expiration=null, remoteIdentity=ENDPOINT, DIRECT] [01.29.24 01:23:08.711 INFO DefaultGroup ging.direct.DirectNetworkChannel] Channel became inactive. closedBy=THIS_SIDE, reason='Session close', channel=DIRECT [01.29.24 01:23:08.714 INFO DefaultGroup tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>694528144554080257, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:08.714 INFO DefaultGroup tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:08.714 INFO DefaultGroup tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:08.715 INFO DefaultGroup com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BC[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=null, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 2sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:08.716 INFO DefaultGroup com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: 694528144554080257>694528144554080257 DISCONNECTED. UNKNOWN RemotePeer-[guid=694528144554080257, state=DISCONNECTED]; Session-[localID=1150475083128518290, remoteID=1150475083128518290, closed=true, expiration=null, remoteIdentity=ENDPOINT, DIRECT]; BC[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=null, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 2sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:08.716 INFO DefaultGroup com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BS[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=null, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:08.717 INFO DefaultGroup com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: 694528144554080257>694528144554080257 DISCONNECTED. UNKNOWN RemotePeer-[guid=694528144554080257, state=DISCONNECTED]; Session-[localID=1150475083128518290, remoteID=1150475083128518290, closed=true, expiration=null, remoteIdentity=ENDPOINT, DIRECT]; BS[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=null, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:09.192 INFO re-event-2-3 SabreLogger] TLS connection established. initiator=true, provider=SSLEngineImpl, version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, channel=[id: 0xb3b816a7, L:/172.17.0.2:43410 - R:/64.207.222.139:443 via /64.207.222.139:443] [01.29.24 01:23:09.396 INFO re-event-2-2 SabreLogger] TLS connection established. initiator=true, provider=SSLEngineImpl, version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, channel=[id: 0xe1a596bb, L:/172.17.0.2:52090 - R:/162.222.41.221:4287 via /162.222.41.221:4287] [01.29.24 01:23:09.544 INFO er1WeDftWkr0 ackup42.service.peer.CPCReceiver] UPGRADE:: Authority gave us AN upgrade. ourVersion=15252000061111, remoteVersion=2000002200090001, version: 2000002200090001\npatch_required: false\npatches {\n version: 15252000061121\n url: "https://download.crashplan.com/installs/agent/cloud/11.2.1/23/upgrade/linux/upgrade5/crashplansmb/15252000061121_23.jar"\n md5: "\273{\210d\274\301\350\212{f\030+>tTc\351\332~\347\244s\272kQ_-%\226C\243\373"\n use_messaging: false\n}\nproperties {\n key: "minimumVersion"\n value: "1393567200411"\n}\nweb_app_base_url: "https://console.us2.crashplan.com"\n [01.29.24 01:23:09.545 INFO er1WeDftWkr0 42.service.history.HistoryLogger] HISTORY:: Downloading a new version of CrashPlan. [01.29.24 01:23:09.549 INFO er1WeDftWkr0 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43731 bytes to UDB in 2.914 ms. [01.29.24 01:23:09.550 INFO er1WeDftWkr0 .service.upgrade.DownloadManager] UPGRADE:: DownloadManager stopped. [01.29.24 01:23:09.551 INFO 9768_DwldMgr .service.upgrade.DownloadManager] UPGRADE:: Downloading patch from https://download.crashplan.com/installs/agent/cloud/11.2.1/23/upgrade/linux/upgrade5/crashplansmb/15252000061121_23.jar?guid=694528144554080257 to upgrade/upgrade.tmp [01.29.24 01:23:09.553 INFO er1WeDftWkr0 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43731 bytes to UDB in 2.685 ms. [01.29.24 01:23:09.554 INFO er1WeDftWkr0 ackup42.service.peer.CPCReceiver] REAUTHORIZE after connect to CPC... [01.29.24 01:23:09.554 INFO er1WeDftWkr0 backup42.service.peer.Authorizer] AUTH:: REAUTH - [email protected] [01.29.24 01:23:09.554 INFO er1WeDftWkr0 backup42.service.peer.Authorizer] AUTH:: REAUTH, [email protected], passwordExists=false, requestMessage=null, register=false, firstName=null, lastName=null, registrationKey=null, waitTimeMillis=120000 [01.29.24 01:23:09.555 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: *** START *** with Authorizer@2096567509[ REAUTH, [email protected]] [01.29.24 01:23:09.556 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: Authority address: clients.us5.crashplanpro.com/64.207.222.139 [01.29.24 01:23:09.556 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: Beginning authorization with Authorizer@2096567509[ REAUTH, [email protected]] [01.29.24 01:23:09.557 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: KEYS:: Sending to authority for reauthorize: securityKeyType=AccountPassword, dataKeyChecksum=a2ac4eef90faa17890bcc2987af139a6 [01.29.24 01:23:09.564 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: CPCLoginMessage@1703360397[ guid=694528144554080257, productVersion=11.1.1, authDate=1676498932653, [email protected], loginKey=9c431e7127efa388398b4ac05b5872a8a7cca4207ff8841b928b78875aaf19cae7df13e9a9166aba09746d47ffdf6945f572c131ef215c21, configDate=1677569280221, socialNetworkDate=1700111911905, securityKeyType=AccountPassword, dataKey[checksum]=none, dataKeyChecksum=a2ac4eef90faa17890bcc2987af139a6, secureDataKey[checksum]=none, orgType=BUSINESS, computerType=COMPUTER, address=172.17.0.2:4247, computerName = 4abc5e81d51f, challengeResponse=false, externalAuthenticatorSessionId=null, duplicateGuidDetectionCounter=2776, guidGenerated=false, securityMode=NOT_SPECIFIED ] [01.29.24 01:23:09.754 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: CPCLoginResponseMessage@256837856[ authDate=1676498932653, passwordExists=false, configDate=1677569280221, hasConfigXml=false, dataKey[checksum]=a2ac4eef90faa17890bcc2987af139a6, secureDataKey[checksum]=30d80884bd8368f29d6c5c5e57820b9c, secureDataKeyQA[checksum]=none, keepDataKeyThroughReassign=false, secureDataKeyUpdateRequired=false, userId=262275, orgName=rad-head, reauthorizeInterval=86400000, externalAuthenticatorSessionKey=null, stsUrl=https://sts-default.us5.cpg.crashplan.com, cloudType=FULLY_HOSTED, clientPublicAddress=93.173.107.213, license=CPLicense@1542179544[ PRO, key=pm9usw7hk7w4uhtr, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.backup, admin.backup.hosted, admin.backup.high_encryption, admin.backup.advanced_settings, admin.backup.realtime, admin.cpd.restore, admin.backup.restore], expireDate=2024-02-27T08:00:00:000, continueDate=2024-03-05T08:00:00:000, baseLicense=License@1268957706[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ]; CPLicense@1636413824[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ] ], social=CPCSocialNetworkChangedMessage@1637758733[ clusterGuid=4200, socialNetworkDate=1705609422131, users=[User@1637517062[ userId=1, userUid=ADMIN, name=admin, username=admin ], User@1842500805[ userId=262275, userUid=ab43f4fa5256f507, name=Jonathan, [email protected] ]], computers=[Computer@-748808450[guid=694528144554080257, name=4abc5e81d51f, osHostname=3ae51ea16cd1, fullAddress=172.17.0.2:4247, publicAddress=93.173.107.213:4499, userId=262275, self, own, connected, dataKeyChecksum=a2ac4eef90faa17890bcc2987af139a6, defaultArchiveType=ARCHIVE_V1 ], Computer@-1965404236[guid=4200, name=CrashPlan Friend, authorityGuid=4200, fullAddress=clients.us5.crashplanpro.com:443, publicAddress=clients.us5.crashplanpro.com:4282, userId=1, cpc, host, disconnected, transportPbKRequestable, transportPbK=X509.checksum(be4b2a71961d23dabb77ea3851a2fc8d), defaultArchiveType=ARCHIVE_V1 ], Computer@47867094[guid=42, name=CrashPlan Central, nodeGuid=695565187726920361, destinationGuid=42, fullAddress=dsd-sea.crashplan.com:4282, publicAddress=dsd-sea.crashplan.com:443, userId=1, host, storageServer, target, availableTarget, disconnected, transportPbK=X509.checksum(c55c2dbc9bec0ec688f7e1bb430b906c), defaultArchiveType=ARCHIVE_V1 ]], targetComputerUsages=[TargetComputerUsage@2096031103[ 694528144554080257>42, destinationGuid=42, mountVersionTx=MountVersionTx [archiveVersion=694546271858469948, mountPointId=6173, mountVersion=2], planUids=[], plans=[], archiveType=ARCHIVE_V1, archiveBytes=3000671579734, selectedBytes=508959374726, selectedFiles=305956, todoBytes=13061922896, todoFiles=1, lastActivity=Thu Jan 11 20:48:03 IST 2024, lastCompletedBackup=Thu Jan 11 05:28:43 IST 2024, lastConnected=Thu Jan 11 20:51:33 IST 2024, percentComplete=97.4]], reset=true, backupSetIdPlanUids={1=694546271841692732, 1100305632724497181=1100305633666059374}, planUidDestinationIds={1100305633666059374=[42], 694546271841692732=[42]} ], super=CPCLoginResponseMessage@256837856[remoteId=136962048763636368, session=1150475087373153938, remoteGuid=4200] ] [01.29.24 01:23:09.755 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: KEYS:: Received from authority: ArchiveDataKeys@-1779859254[ securityKeyType=AccountPassword, dataKey-checksum=a2ac4eef90faa17890bcc2987af139a6, secureDataKey-checksum=30d80884bd8368f29d6c5c5e57820b9c, secureDataKeyQA-checksum=null ] [01.29.24 01:23:09.755 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: CPC session is LOGGED_IN [01.29.24 01:23:09.755 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: Begin resolving config - ourConfigDate=1677569280221, cpcConfigDate=1677569280221 [01.29.24 01:23:09.755 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: Configs match. [01.29.24 01:23:09.755 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: Done resolving config after 0ms [01.29.24 01:23:09.843 INFO EventBus 0 .service.plan.PlanNetworkManager] No PlanPeer found for ready peer ComputerAdapter [computer=Computer@490130607[guid=42, name=CrashPlan Central, nodeGuid=695565187726920361, destinationGuid=42, fullAddress=dsd-sea.crashplan.com:4282, publicAddress=dsd-sea.crashplan.com:443, userId=1, host, storageServer, target, availableTarget, disconnected, transportPbK=X509.checksum(c55c2dbc9bec0ec688f7e1bb430b906c), defaultArchiveType=ARCHIVE_V1 ]], skipping storage validation [01.29.24 01:23:10.072 INFO 87737_AUTH-1 .storage.UniversalStorageService] SM:: Saved ServiceModel of 17353 bytes to UDB in 1.859 ms. [01.29.24 01:23:10.076 INFO 87737_AUTH-1 .storage.UniversalStorageService] SM:: Saved ServiceModel of 44004 bytes to UDB in 2.083 ms. [01.29.24 01:23:10.078 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] updateSource=authority, users=[User@1637517062[ userId=1, userUid=ADMIN, name=admin, username=admin ],User@1842500805[ userId=262275, userUid=ab43f4fa5256f507, name=Jonathan, [email protected] ]], computers=[Computer@-748808450[guid=694528144554080257, name=4abc5e81d51f, osHostname=3ae51ea16cd1, fullAddress=172.17.0.2:4247, publicAddress=93.173.107.213:4499, userId=262275, self, own, connected, dataKeyChecksum=a2ac4eef90faa17890bcc2987af139a6, defaultArchiveType=ARCHIVE_V1 ],Computer@-1965404236[guid=4200, name=CrashPlan Friend, authorityGuid=4200, fullAddress=clients.us5.crashplanpro.com:443, publicAddress=clients.us5.crashplanpro.com:4282, userId=1, cpc, host, disconnected, transportPbKRequestable, transportPbK=X509.checksum(be4b2a71961d23dabb77ea3851a2fc8d), defaultArchiveType=ARCHIVE_V1 ],Computer@47867094[guid=42, name=CrashPlan Central, nodeGuid=695565187726920361, destinationGuid=42, fullAddress=dsd-sea.crashplan.com:4282, publicAddress=dsd-sea.crashplan.com:443, userId=1, host, storageServer, target, availableTarget, disconnected, transportPbK=X509.checksum(c55c2dbc9bec0ec688f7e1bb430b906c), defaultArchiveType=ARCHIVE_V1 ]], targetComputerUsages=[TargetComputerUsage@2096031103[ 694528144554080257>42, destinationGuid=42, mountVersionTx=MountVersionTx [archiveVersion=694546271858469948, mountPointId=6173, mountVersion=2], planUids=[], plans=[], archiveType=ARCHIVE_V1, archiveBytes=3000671579734, selectedBytes=508959374726, selectedFiles=305956, todoBytes=13061922896, todoFiles=1, lastActivity=Thu Jan 11 20:48:03 IST 2024, lastCompletedBackup=Thu Jan 11 05:28:43 IST 2024, lastConnected=Thu Jan 11 20:51:33 IST 2024, percentComplete=97.4]] [01.29.24 01:23:10.079 INFO EventBus 0 .service.backup.BackupController] UAW:: User is PRESENT... DTR=unlimited, cpuThrottleRate=20 [01.29.24 01:23:10.079 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] BackupSetMapping:: updateSource=authority, backupSetIdPlanUids=[{1=694546271841692732},{1100305632724497181=1100305633666059374}], planUidDesinationIds=[{1100305633666059374=[42]},{694546271841692732=[42]}] [01.29.24 01:23:10.079 INFO EventBus 0 .service.backup.BackupController] UAW:: User is PRESENT... DTR=unlimited, cpuThrottleRate=20 [01.29.24 01:23:10.079 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] Using authority provided addresses. primaryAddress=clients.us5.crashplanpro.com:443, secondaryAddress=clients.us5.crashplanpro.com:4282 [01.29.24 01:23:10.081 INFO 87737_AUTH-1 service.model.VerifyMountInfoCmd] VerifyMountInfoCmd:: START [01.29.24 01:23:10.081 INFO 87737_AUTH-1 service.model.VerifyMountInfoCmd] VerifyMountInfoCmd:: DONE [01.29.24 01:23:10.081 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] Setting social network date. socialNetworkDate=1705609422131 [01.29.24 01:23:10.081 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] BackupSetMapping:: updated backupSetIdPlanUids=[{1=694546271841692732},{1100305632724497181=1100305633666059374}] [01.29.24 01:23:10.081 INFO 87737_AUTH-1 p42.service.SocialNetworkUpdater] BackupSetMapping:: updated planUidDestinationIds=[{1100305633666059374=[42]},{694546271841692732=[42]}] [01.29.24 01:23:10.084 INFO 87737_AUTH-1 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43938 bytes to UDB in 2.025 ms. [01.29.24 01:23:10.085 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.socialNetworkDate=1705609422131 [01.29.24 01:23:10.085 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.computer(ME)=Computer@-748808450[guid=694528144554080257, name=4abc5e81d51f, osHostname=3ae51ea16cd1, fullAddress=172.17.0.2:4247, publicAddress=93.173.107.213:4499, userId=262275, self, own, connected, dataKeyChecksum=a2ac4eef90faa17890bcc2987af139a6, defaultArchiveType=ARCHIVE_V1 ] [01.29.24 01:23:10.085 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.computer(CPC)=Computer@-1965404236[guid=4200, name=CrashPlan Friend, authorityGuid=4200, fullAddress=clients.us5.crashplanpro.com:443, publicAddress=clients.us5.crashplanpro.com:4282, userId=1, cpc, host, disconnected, transportPbKRequestable, transportPbK=X509.checksum(be4b2a71961d23dabb77ea3851a2fc8d), defaultArchiveType=ARCHIVE_V1 ] [01.29.24 01:23:10.085 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.computer=Computer@47867094[guid=42, name=CrashPlan Central, nodeGuid=695565187726920361, destinationGuid=42, fullAddress=dsd-sea.crashplan.com:4282, publicAddress=dsd-sea.crashplan.com:443, userId=1, host, storageServer, target, availableTarget, disconnected, transportPbK=X509.checksum(c55c2dbc9bec0ec688f7e1bb430b906c), defaultArchiveType=ARCHIVE_V1 ] [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.user=User@1637517062[ userId=1, userUid=ADMIN, name=admin, username=admin ] [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.user=User@1842500805[ userId=262275, userUid=ab43f4fa5256f507, name=Jonathan, [email protected] ] [01.29.24 01:23:10.086 INFO 87737_AUTH-1 kup42.common.TargetComputerUsage] SocialNetworkModel.targetComputerUsage=TargetComputerUsage@2096031103[ 694528144554080257>42, destinationGuid=42, mountVersionTx=MountVersionTx [archiveVersion=694546271858469948, mountPointId=6173, mountVersion=2], planUids=[], archiveType=ARCHIVE_V1, archiveBytes=3000671579734, selectedBytes=508959374726, selectedFiles=305956, todoBytes=13061922896, todoFiles=1, lastActivity=Thu Jan 11 20:48:03 IST 2024, lastCompletedBackup=Thu Jan 11 05:28:43 IST 2024, lastConnected=Thu Jan 11 20:51:33 IST 2024, percentComplete=97.4] [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.backupSetPlanUid: 1=694546271841692732 [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.backupSetPlanUid: 1100305632724497181=1100305633666059374 [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.planUidTargetComputerGuid: 1100305633666059374=42 [01.29.24 01:23:10.086 INFO 87737_AUTH-1 service.model.SocialNetworkModel] SocialNetworkModel.planUidTargetComputerGuid: 694546271841692732=42 [01.29.24 01:23:10.088 INFO 87737_AUTH-1 .service.backup.BackupController] UAW:: User is PRESENT... DTR=unlimited, cpuThrottleRate=20 [01.29.24 01:23:10.088 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: AppState.reauthorizeInterval=86400000 [01.29.24 01:23:10.091 INFO 87737_AUTH-1 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43933 bytes to UDB in 2.482 ms. [01.29.24 01:23:10.094 INFO 87737_AUTH-1 com.backup42.service.CPService] AUTHORIZE with CPC - CPLicense@1542179544[ PRO, key=pm9usw7hk7w4uhtr, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.backup, admin.backup.hosted, admin.backup.high_encryption, admin.backup.advanced_settings, admin.backup.realtime, admin.cpd.restore, admin.backup.restore], expireDate=2024-02-27T08:00:00:000, continueDate=2024-03-05T08:00:00:000, baseLicense=License@1268957706[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ]; CPLicense@1636413824[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ] ] [01.29.24 01:23:10.096 INFO 87737_AUTH-1 om.backup42.service.IdentityInfo] IdentityInfo.guid=694528144554080257 [01.29.24 01:23:10.096 INFO 87737_AUTH-1 om.backup42.service.IdentityInfo] IdentityInfo.authDate=1676498932653 [01.29.24 01:23:10.096 INFO 87737_AUTH-1 om.backup42.service.IdentityInfo] IdentityInfo.orgType=BUSINESS [01.29.24 01:23:10.096 INFO 87737_AUTH-1 om.backup42.service.IdentityInfo] IdentityInfo.generated=false [01.29.24 01:23:10.097 INFO 87737_AUTH-1 om.backup42.service.IdentityInfo] IdentityInfo.origin=file: /var/lib/crashplan/.identity [01.29.24 01:23:10.101 INFO 87737_AUTH-1 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43933 bytes to UDB in 2.836 ms. [01.29.24 01:23:10.102 INFO 87737_AUTH-1 .service.backup.BackupController] License change: CPLicense@1542179544[ PRO, key=pm9usw7hk7w4uhtr, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.backup, admin.backup.hosted, admin.backup.high_encryption, admin.backup.advanced_settings, admin.backup.realtime, admin.cpd.restore, admin.backup.restore], expireDate=2024-02-27T08:00:00:000, continueDate=2024-03-05T08:00:00:000, baseLicense=License@1268957706[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ]; CPLicense@1636413824[ PRO, permissions=[admin.backup.sets, admin.cpd.adfree, admin.backup.high_encryption, admin.backup.realtime, admin.backup.advanced_settings] ] ] [01.29.24 01:23:10.103 INFO 87737_AUTH-1 up42.service.peer.PeerController] PeerNetwork has changed, updating peers. [01.29.24 01:23:10.108 INFO EventBus 0 ettings.V3ExcludesChangeDetector] V3E::Change in system excludes detected. Previous checksum=c03e49ca8dc4380cc35848f43494f2dae5135ef9ce5e95a13f3e167c658f83af updated checksum=d9ebf392f5eb2941e5a91e0f1fded65edb07c79671df9db50906214da170994a [01.29.24 01:23:10.120 INFO EventBus 0 .storage.UniversalStorageService] SM:: Saved ServiceModel of 43933 bytes to UDB in 6.177 ms. [01.29.24 01:23:10.120 INFO EventBus 0 .code42.service.peer.PeerService] Successfully connected to authority with primaryAddress = clients.us5.crashplanpro.com:443, SecondaryAddress = clients.us5.crashplanpro.com:4282, Adding addresses to the authority fallback list. [01.29.24 01:23:10.125 INFO 87737_AUTH-1 backup42.service.peer.Authorizer] AUTH:: *** END *** Success after 570ms [01.29.24 01:23:10.126 INFO ackupConnWrk rvice.backup.BackupConnectWorker] BCW:: Connecting 694528144554080257>42 - peer to backup client. [01.29.24 01:23:10.126 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:10.127 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:10.127 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:10.127 INFO ackupConnWrk com.code42.backup.BackupEntityV1] BC[694528144554080257>42:: Setting keepBlockState=0 during reset(); BC[694528144554080257>42, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=t, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>42: openCount=0, initialized = true, dataFiles.open = true, /usr/local/crashplan/cache/42], session=null, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 3sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = false, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = false, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:10.131 INFO ackupConnWrk rvice.backup.BackupConnectWorker] BCW:: Connecting 694528144554080257>4200 - peer to backup client. [01.29.24 01:23:10.131 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>4200, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:10.131 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:10.131 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:10.132 INFO ackupConnWrk com.code42.backup.BackupEntityV1] BC[694528144554080257>4200:: Setting keepBlockState=0 during reset(); BC[694528144554080257>4200, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>4200: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/4200], session=null, authority=t, hosted=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 4200, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 3sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>4200, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@1146265391[ threadName = BQTodoWkr-4200, stopped = true], taskw=TaskWorker@1083321971[ threadName = BQTaskWrk-4200, stopped = true], lastTask=null] ]; [01.29.24 01:23:10.258 INFO er1WeDftWkr1 com.code42.messaging.SessionImpl] **** No receiver assigned for message for type com.code42.protos.shared.authority.PlanAdministrationMessages$DestinationsGetResponse, remoteGuid=4200, RemotePeer-[guid=4200, state=CONNECTED]; Session-[localID=1150475087373153938, remoteID=1150475087228414608, layer=Peer::Sabre, closed=false, expiration=null, remoteIdentity=AUTHORITY, local=172.17.0.2:43410, remote=64.207.222.139:443] [01.29.24 01:23:10.348 INFO er1WeDftWkr0 .service.backup.BackupController] BACKUP TARGET CONNECTED! 694528144554080257>42 [01.29.24 01:23:10.397 INFO er1WeDftWkr1 .service.backup.BackupController] Backup connected to authority in non-target mode. authorityGuid=4200, targetGuid=42 [01.29.24 01:23:10.397 INFO er1WeDftWkr1 .service.backup.BackupController] BACKUP TARGET CONNECTED! 694528144554080257>4200 [01.29.24 01:23:10.566 INFO er1WeDftWkr0 com.code42.backup.BackupEntityV1] BC[694528144554080257>42:: = Backup ready! (Previously not ready: null) BackupClientStats@1774952255[ BT 694528144554080257>42, backupSystemStarted=true, backupNotReadyCode=null, outOfSpace=null, outOfSpaceTimestamp=0, validating=false, backingUp=false, numFilesBackedUp=607981, manifestSize=1606655859, receiveRateInBytesPerSec(B/s)=0.000, sendRateInBytesPerSec(B/s)=0.000, lastBackupTimestamp=Thu Jan 11 21:25:05 IST 2024, lastCompletedBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, archiveMaintenanceStats=null, compactStats=CompactStats[lastCompactTimestamp = 0, numBlocks = 0, numBlocksCompleted = 0, numBlocksToCompact = 0, numBlocksCompacted = 0, numBlocksFailedChecksum = 0, bytesRemoved = 0, totalBytes = 0, avgBlockSize = 1, scrapPercent = 100.0%, approxScrapSize = 0, scrapPercentAllowed = 0.0, currentInitialBlockNumber = 0, outOfOrderBlocksDetected = false], Session: , sessionSourceBytesCompleted=0 (0.00%), sessionLastSourceBytesCompletedTimestamp=1706484186205, sessionActualBytesSent=0, sessionFilesCompleted=0, sessionStopwatch=4sec, sessionCompletedRateInBytesPerSec(B/s)=0.0, remoteManifestSize=3000389119301, readDuration=0 ms; 0MB (0Mbps), deltaDuration=0 ms; 0MB (0Mbps), compressDuration=0 ms; 0MB (0Mbps), encryptDuration=0 ms; 0MB (0Mbps), sessionDeltaBlockStats=DeltaBlockStats [numNewBlocks=0, numExistingBlocks=0, numNewBytes=0, onTrackCount=0, offTrackCount=0, weakCacheHit=0, weakCacheMiss=0], cacheMaintenanceStats=null, [FileTodoStats@-1171337482[ sourceGuid = 694528144554080257, targetGuid = 42, nextBackupTimestamp=-1, lastBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, lastCompletedBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, scanning = false, numFilesScanned = 0, numBytesScanned = 0, numRemainingFiles = 0, numRemainingBytes = 0, numRetries = 0, fileCheck = false, numScheduledFiles = 0, numScheduledBytes = 0, nextScheduledTime = 0, backupSetId=1, selectedForBackup=false, resumeTime=-1], FileTodoStats@2030121368[ sourceGuid = 694528144554080257, targetGuid = 42, nextBackupTimestamp=Mon Jan 01 07:40:44 IST 2024, lastBackupTimestamp=Thu Jan 11 21:25:05 IST 2024, lastCompletedBackupTimestamp=Tue Jan 02 01:12:26 IST 2024, scanning = false, numFilesScanned = 305956, numBytesScanned = 508959374726, numRemainingFiles = 1, numRemainingBytes = 13061922896, numRetries = 0, fileCheck = false, numScheduledFiles = 0, numScheduledBytes = 0, nextScheduledTime = 0, backupSetId=1100305632724497181, selectedForBackup=false, resumeTime=-1]]]; BC[694528144554080257>42, sameOwner=f, backupConnected=t, authorized=t, usingForBackup=t, backupNotReadyCode=null, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:128, val=0, readyCheckTime=2024-01-29T01:23:10:128, MM[BT 694528144554080257>42: openCount=0, initialized = true, dataFiles.open = false, /usr/local/crashplan/cache/42], session=1150475087708698258, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=t, backupUsageTime=2024-01-29T01:23:10:349, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 4sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = false, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = false, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:10.567 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:10.567 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:10.567 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:10.582 INFO 7964_BckpSel 2.backup.selector.BackupSelector] BSEL:: select() SELECTED - guid=42, setId=1100305632724497181; BackupSelector@2010283722[ threadName = BckpSel, stopped = false, running = true, thread.isDaemon = true, thread.isAlive = true, thread = Thread[W229147964_BckpSel,5,main]], wakeup = false, wakeupCode = BackupReady, nextBackupWakeupInterval = 0, selectedTarget = TargetSet [targetGuid=42, backupSetId=1100305632724497181, FileTodoStats@2030121368[ sourceGuid = 694528144554080257, targetGuid = 42, nextBackupTimestamp=Mon Jan 01 07:40:44 IST 2024, lastBackupTimestamp=Thu Jan 11 21:25:05 IST 2024, lastCompletedBackupTimestamp=Tue Jan 02 01:12:26 IST 2024, scanning = false, numFilesScanned = 305956, numBytesScanned = 508959374726, numRemainingFiles = 1, numRemainingBytes = 13061922896, numRetries = 0, fileCheck = false, numScheduledFiles = 0, numScheduledBytes = 0, nextScheduledTime = 0, backupSetId=1100305632724497181, selectedForBackup=false, resumeTime=-1], BC[694528144554080257>42, sameOwner=f, backupConnected=t, authorized=t, usingForBackup=t, backupNotReadyCode=null, backingUp=f, validating=t, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:128, val=2024-01-29T01:23:10:571, readyCheckTime=2024-01-29T01:23:10:128, MM[BT 694528144554080257>42: openCount=0, initialized = true, dataFiles.open = true, /usr/local/crashplan/cache/42], session=1150475087708698258, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=2024-01-29T01:23:10:349, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 4sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = false, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = false, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]], requestedTarget = null] [01.29.24 01:23:10.583 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:10.583 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:10.583 INFO 7964_BckpSel tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:10.714 INFO ackupConnWrk rvice.backup.BackupConnectWorker] BCW:: Connecting 694528144554080257>694528144554080257 - peer to backup client. [01.29.24 01:23:10.714 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>694528144554080257, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:10.714 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:10.714 INFO ackupConnWrk tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:10.715 INFO ackupConnWrk com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BC[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=null, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 4sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:10.715 INFO er1WeDftWkr0 com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BS[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=null, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:10.717 INFO er1WeDftWkr0 de42.backup.ClientBackupServerV1] BS[694528144554080257>694528144554080257:: Informing of backup readiness - ready=true, notReadyCode=NOT_AVAILABLE; BS[694528144554080257>694528144554080257, DIRECT SAME, sameOwner=t, backupConnected=t, authorized=t, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=1150475089923290770, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:10.718 INFO er1WeDftWkr0 com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: = Backup ready! (Previously not ready: NOT_AVAILABLE) BackupServerStats@639872291[ BS 694528144554080257>694528144554080257, backupSystemStarted=true, backupNotReadyCode=null, outOfSpace=null, outOfSpaceTimestamp=0, validating=false, backingUp=false, numFilesBackedUp=0, manifestSize=0, receiveRateInBytesPerSec(B/s)=0.000, sendRateInBytesPerSec(B/s)=0.000, lastBackupTimestamp=-1, lastCompletedBackupTimestamp=-1, archiveMaintenanceStats=null, compactStats=null, Session: , sessionSourceBytesCompleted=0 (0.00%), sessionLastSourceBytesCompletedTimestamp=1706484186181, sessionActualBytesSent=0, sessionFilesCompleted=0, sessionStopwatch=4sec, sessionCompletedRateInBytesPerSec(B/s)=0.0, dataSize=0, overhead=0, estimatedFreeSpace=-1, minimumFreeSpace=-1, receiveDuration=0 ms; 0MB (0Mbps)]; BS[694528144554080257>694528144554080257, DIRECT SAME, sameOwner=t, backupConnected=t, authorized=t, usingForBackup=f, backupNotReadyCode=null, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=1150475089923290770, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:10.719 INFO er1WeDftWkr0 .service.backup.BackupController] BACKUP SOURCE CONNECTED! 694528144554080257 to source 694528144554080257 [01.29.24 01:23:10.719 INFO er1WeDftWkr1 .service.backup.BackupController] BACKUP TARGET CONNECTED! 694528144554080257>694528144554080257 [01.29.24 01:23:10.720 INFO er1WeDftWkr0 com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: = Backup ready! (Previously not ready: NOT_AVAILABLE) BackupClientStats@140364572[ BT 694528144554080257>694528144554080257, backupSystemStarted=true, backupNotReadyCode=null, outOfSpace=null, outOfSpaceTimestamp=0, validating=false, backingUp=false, numFilesBackedUp=0, manifestSize=0, receiveRateInBytesPerSec(B/s)=0.000, sendRateInBytesPerSec(B/s)=0.000, lastBackupTimestamp=-1, lastCompletedBackupTimestamp=-1, archiveMaintenanceStats=null, compactStats=null, Session: , sessionSourceBytesCompleted=0 (0.00%), sessionLastSourceBytesCompletedTimestamp=1706484186186, sessionActualBytesSent=0, sessionFilesCompleted=0, sessionStopwatch=4sec, sessionCompletedRateInBytesPerSec(B/s)=0.0, remoteManifestSize=0, readDuration=0 ms; 0MB (0Mbps), deltaDuration=0 ms; 0MB (0Mbps), compressDuration=0 ms; 0MB (0Mbps), encryptDuration=0 ms; 0MB (0Mbps), sessionDeltaBlockStats=DeltaBlockStats [numNewBlocks=0, numExistingBlocks=0, numNewBytes=0, onTrackCount=0, offTrackCount=0, weakCacheHit=0, weakCacheMiss=0], cacheMaintenanceStats=null, []]; BC[694528144554080257>694528144554080257, DIRECT SAME, sameOwner=t, backupConnected=t, authorized=t, usingForBackup=f, backupNotReadyCode=null, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=1150475089923290770, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 4sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:10.840 INFO er1WeDftWkr1 com.code42.backup.BackupEntityV1] BC[694528144554080257>42:: = Backup ready! (Previously not ready: null) BackupClientStats@1774952255[ BT 694528144554080257>42, backupSystemStarted=true, backupNotReadyCode=null, outOfSpace=null, outOfSpaceTimestamp=0, validating=true, backingUp=false, numFilesBackedUp=607981, manifestSize=1606655859, receiveRateInBytesPerSec(B/s)=0.000, sendRateInBytesPerSec(B/s)=0.000, lastBackupTimestamp=Thu Jan 11 21:25:05 IST 2024, lastCompletedBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, archiveMaintenanceStats=null, compactStats=CompactStats[lastCompactTimestamp = 0, numBlocks = 0, numBlocksCompleted = 0, numBlocksToCompact = 0, numBlocksCompacted = 0, numBlocksFailedChecksum = 0, bytesRemoved = 0, totalBytes = 0, avgBlockSize = 1, scrapPercent = 100.0%, approxScrapSize = 0, scrapPercentAllowed = 0.0, currentInitialBlockNumber = 0, outOfOrderBlocksDetected = false], Session: , sessionSourceBytesCompleted=0 (0.00%), sessionLastSourceBytesCompletedTimestamp=1706484186205, sessionActualBytesSent=0, sessionFilesCompleted=0, sessionStopwatch=4sec, sessionCompletedRateInBytesPerSec(B/s)=0.0, remoteManifestSize=3000389119301, readDuration=0 ms; 0MB (0Mbps), deltaDuration=0 ms; 0MB (0Mbps), compressDuration=0 ms; 0MB (0Mbps), encryptDuration=0 ms; 0MB (0Mbps), sessionDeltaBlockStats=DeltaBlockStats [numNewBlocks=0, numExistingBlocks=0, numNewBytes=0, onTrackCount=0, offTrackCount=0, weakCacheHit=0, weakCacheMiss=0], cacheMaintenanceStats=null, [FileTodoStats@-1171337482[ sourceGuid = 694528144554080257, targetGuid = 42, nextBackupTimestamp=-1, lastBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, lastCompletedBackupTimestamp=Thu Jan 11 05:28:43 IST 2024, scanning = false, numFilesScanned = 0, numBytesScanned = 0, numRemainingFiles = 0, numRemainingBytes = 0, numRetries = 0, fileCheck = false, numScheduledFiles = 0, numScheduledBytes = 0, nextScheduledTime = 0, backupSetId=1, selectedForBackup=false, resumeTime=-1], FileTodoStats@2030121368[ sourceGuid = 694528144554080257, targetGuid = 42, nextBackupTimestamp=Mon Jan 01 07:40:44 IST 2024, lastBackupTimestamp=Thu Jan 11 21:25:05 IST 2024, lastCompletedBackupTimestamp=Tue Jan 02 01:12:26 IST 2024, scanning = false, numFilesScanned = 305956, numBytesScanned = 508959374726, numRemainingFiles = 1, numRemainingBytes = 13061922896, numRetries = 0, fileCheck = false, numScheduledFiles = 0, numScheduledBytes = 0, nextScheduledTime = 0, backupSetId=1100305632724497181, selectedForBackup=true, resumeTime=-1]]]; BC[694528144554080257>42, sameOwner=f, backupConnected=t, authorized=t, usingForBackup=t, backupNotReadyCode=null, backingUp=f, validating=t, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:128, val=2024-01-29T01:23:10:571, readyCheckTime=2024-01-29T01:23:10:128, MM[BT 694528144554080257>42: openCount=0, initialized = true, dataFiles.open = true, /usr/local/crashplan/cache/42], session=1150475087708698258, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=t, selectedForRestore=f, validationNeeded=f, backupUsageTime=2024-01-29T01:23:10:349, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 4sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = false, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = false, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:22.731 INFO er1WeDftWkr0 com.code42.backup.BackupClientV1] BC[694528144554080257>42:: SYNC:: Manifest validation failed. txValid=false, bmfValid=true, propsValid=true, pathsValid=false, replace=false; Synchronizing... syncCount=1, validationCount=1, currentBackupSetId=1100305632724497181; BC[694528144554080257>42, sameOwner=f, backupConnected=t, authorized=t, usingForBackup=t, backupNotReadyCode=null, backingUp=f, validating=t, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:128, val=2024-01-29T01:23:22:727, readyCheckTime=2024-01-29T01:23:10:128, MM[BT 694528144554080257>42: openCount=1, initialized = true, dataFiles.open = true, /usr/local/crashplan/cache/42], session=1150475087708698258, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=t, selectedForRestore=f, validationNeeded=f, backupUsageTime=2024-01-29T01:23:10:349, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 16sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = false, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = false, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:22.732 INFO er1WeDftWkr0 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::Initialized - numWorkers=1 [01.29.24 01:23:23.358 INFO er1WeDftWkr0 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::time=1706484203358, queueSize=0, itemType=class com.code42.backup.manifest.SyncTransactionLogOnSourceWork, overflowFlag=false, sessionID=694528144554080257>42 [01.29.24 01:23:23.358 INFO 84202561::-1 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::time=1706484203358, queueSize=0, itemType=class com.code42.backup.manifest.SyncTransactionLogOnSourceWork, durationQueued=0, sessionID=694528144554080257>42 [01.29.24 01:23:23.358 INFO 84202561::-1 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::time=1706484203358, itemType=class com.code42.backup.manifest.SyncTransactionLogOnSourceWork, sessionID=694528144554080257>42 [01.29.24 01:23:24.163 INFO 554080257>42 ackup.manifest.ClientSyncHandler] SYNC::BT-694528144554080257>42: TX-CLIENT: VersionReductionStarted - VersionReductionStarted@1914320472[ VersionReductionStarted@1914320472[ txType= 9, txChecksum = 5b86ff47068c1feedff075d54db88b98, timestamp = 1706009335646, fileId = 00000000000000000000000000000000], keepBlockState = 2, verifyBlockstrue, executeTimestampInHours = 473891]; ClientSyncHandler@2069407576[ timestamp=1706484202561, txValid=false, bmfValid=true, propsValid=true, pathsValid=true, throttler=200/1000] [01.29.24 01:23:24.167 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BS[sourceId=694528144554080257]: Creating new maint stats.; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, verifyRestore = false, verifySourceLength = false, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, null] [01.29.24 01:23:24.168 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: Applying VR STARTED - VersionReductionStarted@1914320472[ VersionReductionStarted@1914320472[ txType= 9, txChecksum = 5b86ff47068c1feedff075d54db88b98, timestamp = 1706009335646, fileId = 00000000000000000000000000000000], keepBlockState = 2, verifyBlockstrue, executeTimestampInHours = 473891]; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 0, lastFileId = null, confirmLastFileId = null, lastReduceTxTimestamp = 0, checksumBlocks = true, verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, running = false, deepMaintenance = false, reduceState = null, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.169 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: VR STARTED: Setting reduce state to QUEUED. keepBlockState=2, verifyBlocks=true; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 0, lastFileId = null, confirmLastFileId = null, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionStarted@1914320472[ VersionReductionStarted@1914320472[ txType= 9, txChecksum = 5b86ff47068c1feedff075d54db88b98, timestamp = 1706009335646, fileId = 00000000000000000000000000000000], keepBlockState = 2, verifyBlockstrue, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, running = false, deepMaintenance = false, reduceState = null, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.169 INFO 554080257>42 .manifest.BackupClientProperties] Setting MAINT VERIFY BLOCKS to true, /usr/local/crashplan/cache/42/cp.properties [01.29.24 01:23:24.169 INFO 554080257>42 manifest.BackupArchiveProperties] Setting REDUCE state to QUEUED, /usr/local/crashplan/cache/42/cp.properties [01.29.24 01:23:24.170 INFO 554080257>42 manifest.BackupArchiveProperties] Setting KEEP BLOCK STATE to 2, /usr/local/crashplan/cache/42/cp.properties [01.29.24 01:23:24.171 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: Setting to STEP_1, keepBlockState=2 & clearing resume point.; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 0, lastFileId = null, confirmLastFileId = null, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionStarted@1914320472[ VersionReductionStarted@1914320472[ txType= 9, txChecksum = 5b86ff47068c1feedff075d54db88b98, timestamp = 1706009335646, fileId = 00000000000000000000000000000000], keepBlockState = 2, verifyBlockstrue, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = QUEUED, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.171 INFO 554080257>42 manifest.BackupArchiveProperties] Setting REDUCE state to STEP_1_PRUNE_FILES, /usr/local/crashplan/cache/42/cp.properties [01.29.24 01:23:24.171 INFO 554080257>42 manifest.BackupArchiveProperties] Setting KEEP BLOCK STATE to 2, /usr/local/crashplan/cache/42/cp.properties [01.29.24 01:23:24.172 INFO 554080257>42 ackup.manifest.ClientSyncHandler] SYNC::BT-694528144554080257>42: TX-CLIENT: VersionReductionPoint - VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891]; ClientSyncHandler@2069407576[ timestamp=1706484202561, txValid=false, bmfValid=true, propsValid=true, pathsValid=true, throttler=200/1000] [01.29.24 01:23:24.173 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: Applying VR POINT - VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891]; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 0, lastFileId = null, confirmLastFileId = null, lastReduceTxTimestamp = 0, checksumBlocks = true, verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = QUEUED, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.175 INFO 554080257>42 LimitVersionOverTimeCalculatorV1] LVOT:: :: LimitVersionOverTimeCalculator(): date=Tue Jan 23 13:00:00 IST 2024, endOfDayDate=Wed Jan 24 08:00:00 IST 2024, timeZone=Central Standard Time (America/Chicago); LimitVersionOverTimeCalculatorV1[ policy=LimitVersionOverTimeRetentionPolicy5@104872712[ timeZone=Central Standard Time (America/Chicago), lastModified=1676580864824, keepDeleted=false, keepDeletedInterval=129600, last90DaysInterval=1440, lastWeekInterval=30, lastYearInterval=10080, prevYearInterval=43200, backupFrequency=1800000], endOfDay=Wed Jan 24 08:00:00 IST 2024, ranges=(4)[Range[ beginningOfRange=Tue Jan 16 08:00:00 IST 2024, interval=1800000, numVersionsToKeep=384, numVersionsKept=0, numExtraVersions=0, startOfSlice=NA, #slices=0], Range[ beginningOfRange=Thu Oct 26 09:00:00 IDT 2023, interval=86400000, numVersionsToKeep=82, numVersionsKept=0, numExtraVersions=0, startOfSlice=NA, #slices=0], Range[ beginningOfRange=Tue Jan 24 08:00:00 IST 2023, interval=604800000, numVersionsToKeep=40, numVersionsKept=0, numExtraVersions=0, startOfSlice=NA, #slices=0], Range[ beginningOfRange=Mon Jan 24 08:00:00 IST 2022, interval=2592000000, numVersionsToKeep=13, numVersionsKept=0, numExtraVersions=0, startOfSlice=NA, #slices=0]]] [01.29.24 01:23:24.175 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: setExecuteDate(): retentionPolicy=LimitVersionOverTimeRetentionPolicy5@104872712[ timeZone=Central Standard Time (America/Chicago), lastModified=1676580864824, keepDeleted=false, keepDeletedInterval=129600, last90DaysInterval=1440, lastWeekInterval=30, lastYearInterval=10080, prevYearInterval=43200, backupFrequency=1800000]; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = QUEUED, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.175 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: START EXECUTING executeDate=Tue Jan 23 13:00:00 IST 2024; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = QUEUED, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.176 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: init(): Reduce is enabled - reduceState=STEP_1_PRUNE_FILES; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 0, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.176 INFO 554080257>42 .maintenance.MaintenanceJobState] Resuming reduction, keepBlockState=2, archiveGuid=42 [01.29.24 01:23:24.176 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: init(): pathSets=[SecurePathSet[paths = [+885bf69dc0168f3624435346d7bf4836/7ee91039b7b1a206e41cf531379d2f0c/b10bf569787577e8c0c959f826b74ba6/, +885bf69dc0168f3624435346d7bf4836/7ee91039b7b1a206e41cf531379d2f0c/8ad726bbf52296df38b8b9846097c5a1/, +885bf69dc0168f3624435346d7bf4836/7ee91039b7b1a206e41cf531379d2f0c/7c3759a0a9a7f5195920b249745525e7/, +885bf69dc0168f3624435346d7bf4836/7ee91039b7b1a206e41cf531379d2f0c/1db51a05f7306c722ffc21d62b98d012/]], SecurePathSet[paths = [-3136d0837fa44f0dbd535a8ba91977f1/f1bc9c92b66b51f9fe6530d3640744a9/, -3136d0837fa44f0dbd535a8ba91977f1/78b9b605549ad2915885b10353c0d918/, -3136d0837fa44f0dbd535a8ba91977f1/5349f5c53e2a2d7a9a56f89bf16fef2e/, -3136d0837fa44f0dbd535a8ba91977f1/2f3d62f71540e11227351c3be999caf9/, -3136d0837fa44f0dbd535a8ba91977f1/17ffd819046f87be45db24e39759a7e7/, +3136d0837fa44f0dbd535a8ba91977f1/, +304d10bba1a690dae373c44ffbda8b57/da07ae423dcf6df65a725bff9de11b2a/, +304d10bba1a690dae373c44ffbda8b57/7d9250e7148207b1bcc06767d37056f7/, +304d10bba1a690dae373c44ffbda8b57/120097fbade7c28308b22c0865e9d33b/, +22a102e35a1fb70007e3a4b653619be4/]]]; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.176 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: REDUCE: init(): retentionPolicy=LimitVersionOverTimeRetentionPolicy5@104872712[ timeZone=Central Standard Time (America/Chicago), lastModified=1676580864824, keepDeleted=false, keepDeletedInterval=129600, last90DaysInterval=1440, lastWeekInterval=30, lastYearInterval=10080, prevYearInterval=43200, backupFrequency=1800000]; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 0, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.177 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: init(): verifyBlocks=true; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 1706484204176, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = false, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.177 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: init(): verifyBlocksLoadFactor=0.8; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 1706484204176, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = true, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.182 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: Running BMF verify. numRecords=33929633, required=false; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 1706484204176, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = true, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:24.182 INFO 554080257>42 kup.manifest.ManifestSiloManager] MBA: ===== Verifying blocks...ManifestSiloManager@352351389[ manifestPath = /usr/local/crashplan/cache/42, open = true, #pointers = 1] [01.29.24 01:23:24.183 INFO 554080257>42 kup.manifest.BlockManifestVerify] Start verifying BMF. /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:24.183 INFO 554080257>42 kup.manifest.BlockManifestVerify] verify: numRecords=33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:24.338 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 100000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:25.241 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 200000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:25.312 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 300000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:26.167 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 400000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:26.227 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 500000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:27.168 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 600000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:27.231 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 700000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:27.283 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 800000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:27.340 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 900000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:28.197 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1000000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:28.255 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1100000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:28.350 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1200000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:29.229 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1300000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:29.354 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1400000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:30.267 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1500000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:30.319 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1600000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:31.177 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1700000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:31.232 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1800000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:31.286 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 1900000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:31.342 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2000000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:31.487 INFO Thread-0 com.backup42.service.CPService] ShutdownHook...calling cleanup [01.29.24 01:23:31.489 INFO STOPPING com.backup42.service.CPService] SHUTDOWN:: Stopping service... [01.29.24 01:23:31.489 INFO STOPPING om.backup42.service.ui.UIService] UI:: Stop PING [01.29.24 01:23:31.489 INFO STOPPING de42.service.ui.http.JettyServer] UI:: Stopping Jetty... [01.29.24 01:23:31.508 INFO STOPPING de42.service.ui.http.JettyServer] UI:: Jetty is NO longer listening [01.29.24 01:23:31.508 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:31.508 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:31.508 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:31.508 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Shutdown of background executor took 0ms [01.29.24 01:23:31.508 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>694528144554080257, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Shutdown of background executor took 0ms [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>4200, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:31.509 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Shutdown of background executor took 0ms [01.29.24 01:23:31.510 INFO STOPPING .common.peer.PeerAgentController] Closing peer=PeerLayer@47817997[[email protected]:4242] [01.29.24 01:23:31.510 INFO STOPPING .code42.messaging.peer.PeerGroup] PG::DefaultGroup Shutting down peer group: #peers=3, location=[[email protected]:4242] [01.29.24 01:23:31.510 INFO STOPPING .code42.messaging.peer.PeerGroup] PG::DefaultGroup cancelListen() location=[[email protected]:4242] [01.29.24 01:23:31.711 INFO STOPPING aging.mde.MdeMessageQueueManager] MDE::MdePeer1Mqm->Shutting down message queues... [01.29.24 01:23:31.711 INFO er1WeDftWkr0 ging.direct.DirectNetworkChannel] Channel became inactive. closedBy=THIS_SIDE, reason='Session close', channel=DIRECT [01.29.24 01:23:31.714 INFO STOPPING aging.mde.MdeMessageQueueManager] MDE::MdePeer1Mqm->Message queues shut down. [01.29.24 01:23:31.714 INFO STOPPING ode42.messaging.mde.WorkExecutor] MDE::MdePeer1WeDft->Shutting down executors... [01.29.24 01:23:31.714 INFO STOPPING ode42.messaging.mde.WorkExecutor] MDE::MdePeer1WeDft->Shut down of workers was successful. [01.29.24 01:23:31.714 INFO STOPPING essaging.mde.WorkExecutorManager] MDE::MdePeer1WeDft->Work executor shut down. [01.29.24 01:23:31.714 INFO STOPPING ng.mde.MessageDistributionEngine] MDE::MdePeer1->Shutting down main thread... [01.29.24 01:23:31.714 INFO MdePeer1 om.code42.messaging.mde.MdeState] MDE::MdePeer1 is Shutdown [01.29.24 01:23:31.716 INFO STOPPING ng.mde.MessageDistributionEngine] MDE::MdePeer1->Main thread shut down [01.29.24 01:23:31.716 INFO STOPPING ng.mde.MessageDistributionEngine] MDE::MdePeer1->Shutdown ran for 5ms. Success: true. Internal Report: >>>>Message Distribution Engine<<<< Name: Peer State: STOPPED Last Task: STOPPED Started: 2024-01-29T01:23:05.619 Stopped: 2024-01-29T01:23:31.714 Last Round: 2024-01-29T01:23:31.713 Report Time: 2024-01-29T01:23:31.716 NewWork: MessageQueuesCollector{Set1 Size: 0, Set2 Size: 0 (current)} [01.29.24 01:23:31.716 INFO STOPPING e42.messaging.peer.PeerConnector] PC:: PeerConnector closed for Peer::Sabre [01.29.24 01:23:31.716 INFO erTimeoutWrk e42.messaging.peer.PeerConnector] PC:: PeerConnector.TimeoutWorker stopped. [01.29.24 01:23:31.717 INFO DefaultGroup .code42.messaging.peer.PeerGroup] PG::DefaultGroup Connect Worker Has Stopped [01.29.24 01:23:31.718 INFO re-event-2-2 .handler.ChannelLifecycleHandler] SABRE:: Channel became inactive. closedBy=THIS_SIDE, reason='Session close', channel=[id: 0xe1a596bb, L:/172.17.0.2:52090 ! R:/162.222.41.221:4287], sessionState=RemotePeer-[guid=42, state=DISCONNECTED]; Session-[localID=1150475087708698258, remoteID=1150475087532926479, layer=Peer::Sabre, closed=true, expiration=null, remoteIdentity=STORAGE, local=172.17.0.2:52090, remote=162.222.41.221:4287] [01.29.24 01:23:31.718 INFO re-event-2-3 .handler.ChannelLifecycleHandler] SABRE:: Channel became inactive. closedBy=THIS_SIDE, reason='Session close', channel=[id: 0xb3b816a7, L:/172.17.0.2:43410 ! R:/64.207.222.139:443], sessionState=RemotePeer-[guid=4200, state=DISCONNECTED]; Session-[localID=1150475087373153938, remoteID=1150475087228414608, layer=Peer::Sabre, closed=true, expiration=null, remoteIdentity=AUTHORITY, local=172.17.0.2:43410, remote=64.207.222.139:443] [01.29.24 01:23:31.720 INFO STOPPING .code42.messaging.peer.PeerGroup] Refusing attempt to disconnect direct peer. uid=694528144554080257. peer=RemotePeer-[guid=694528144554080257]; PeerConnectionState-[state=DISCONNECTED, DIRECT, connecting=2024-01-29T01:23:10:712, connected=0, disconnected=2024-01-29T01:23:31:711, attempts=0, connectActivity=2024-01-29T01:23:31:711, keepAliveSent=0, minRetry=27467, reconnectable, addressGenerator=PeerAddressGenerator [locationPairs=[(direct) [=> [email protected]:4247]], currentAddressIndex=0, unresolvedPrimary=[[[email protected]:4247]], unresolvedSecondary=Optional.empty, pacReader=com.code42.messaging.proxy.pac.ProxyAutoConfigReader@45e47cd5, Reset(2024-01-29T01:23:31.712)]]; Session-null [01.29.24 01:23:31.720 INFO DefaultGroup .code42.messaging.peer.PeerGroup] PG::DefaultGroup ReconnectWorker stopped for peer 694528144554080257 [01.29.24 01:23:31.721 INFO STOPPING .code42.messaging.peer.PeerGroup] PG::DefaultGroup Requested disconnect for 3 remote peers. [01.29.24 01:23:31.721 INFO STOPPING .network.sabre.SabreNetworkLayer] SABRE:: Shutting down Sabre Network Layer for Peer [01.29.24 01:23:31.721 INFO STOPPING .code42.messaging.SessionManager] Closing 0 sessions... [01.29.24 01:23:31.721 INFO 706484185614 .code42.messaging.SessionManager] SessionManagerWorker Shutdown for: SMW-1706484185614 [01.29.24 01:23:31.721 INFO STOPPING .network.sabre.SabreNetworkLayer] SABRE:: Shutting down sabre network listen loop for Peer, Timeout set for 15000ms [01.29.24 01:23:32.194 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2100000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:32.246 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2200000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:32.305 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2300000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:32.357 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2400000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:33.209 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2500000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:33.258 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2600000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:33.313 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2700000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:33.725 INFO STOPPING .network.sabre.SabreNetworkLayer] SABRE:: Shutting down sabre network client loop for Peer, Timeout set for 15000ms [01.29.24 01:23:34.167 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2800000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:34.220 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 2900000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:35.169 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 3000000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:35.222 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 3100000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:35.274 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 3200000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:35.322 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 3300000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:35.728 INFO STOPPING .network.sabre.SabreNetworkLayer] SABRE:: Shutting down sabre global traffic shaper for Peer [01.29.24 01:23:35.728 INFO STOPPING .network.sabre.SabreNetworkLayer] SABRE:: Completed shut down of Sabre Network Layer for Peer [01.29.24 01:23:35.728 INFO STOPPING .code42.messaging.peer.PeerGroup] PG::DefaultGroup Completed asking peer group to shut down: location=[[email protected]:4242] [01.29.24 01:23:35.729 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::Shutting down: size=0, #busy=0, #workers=1 [01.29.24 01:23:35.729 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::time=1706484215729, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:35.729 INFO ultGroup::-1 code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::time=1706484215729, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=0, sessionID=StopWork [01.29.24 01:23:35.729 INFO ultGroup::-1 code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::time=1706484215729, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:35.730 INFO ultGroup::-1 code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::time=1706484215729, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:35.730 INFO ultGroup::-1 code42.queue.BackgroundWorkQueue] BWQ-DefaultGroup::All background workers have shutdown [01.29.24 01:23:35.829 INFO STOPPING .common.peer.PeerAgentController] PeerController stopped. [01.29.24 01:23:35.829 INFO STOPPING com.code42.watcher.SystemWatcher] SystemWatcher stopped. [01.29.24 01:23:35.829 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------ [01.29.24 01:23:35.829 INFO STOPPING p42.service.ClientServiceManager] CSM:: Stopping authorized services. [01.29.24 01:23:35.833 INFO ice STOPPING ervice.storage.AuthorizedService] STOPPED AuthorizedService [01.29.24 01:23:35.833 INFO ice STOPPING extraction.DataExtractionService] V3E::STOPPED DataExtractionService in 269.0 μs [01.29.24 01:23:35.834 INFO ice STOPPING n.BackupSessionControllerService] V3E::STOPPED BackupSessionControllerService in 279.8 μs [01.29.24 01:23:35.833 INFO ice STOPPING OnNetworkInterfaceChangesService] STOPPED BackupTargetReconnectOnNetworkInterfaceChangesService in 41.48 μs [01.29.24 01:23:35.833 INFO ine STOPPING om.code42.engine.v3.V3PushEngine] V3E::STOPPED V3PushEngine [01.29.24 01:23:35.834 INFO ice STOPPING ession.BackupSessionStateService] V3E::STOPPED BackupSessionStateService in 41.34 μs [01.29.24 01:23:35.835 INFO ice STOPPING storage.AuthorizedStorageService] ADB:: STOPPED Authorized Database (ADB) in 767.9 μs [01.29.24 01:23:35.835 INFO ice STOPPING 2.engine.v3.V3PlanNetworkService] V3E::STOPPED V3PlanNetworkService in 35.91 μs [01.29.24 01:23:35.836 INFO ice STOPPING .v3.PlanNetworkEventProxyService] V3E::STOPPED PlanNetworkEventProxyService in 27.85 μs [01.29.24 01:23:35.837 INFO ice STOPPING igration.MigrationRestoreService] USMT:: Stopping service... [01.29.24 01:23:35.837 INFO ice STOPPING fileactivity.FileActivityMonitor] V3E::All scan-related futures have been cancelled [01.29.24 01:23:35.837 INFO ice STOPPING iagnostic.AgentDiagnosticService] STOPPED AgentDiagnosticService in 554.4 μs [01.29.24 01:23:35.840 INFO ice STOPPING v3.exclusions.ExcludedFileTagger] V3E::All v3 exclusions futures have been cancelled [01.29.24 01:23:35.840 INFO ice STOPPING e.uiinfo.AuthorizedUIInfoService] STOPPED AuthorizedUIInfoService [01.29.24 01:23:35.840 INFO ice STOPPING ckupSessionPostValidationService] V3E::STOPPED BackupSessionPostValidationService in 12.02 μs [01.29.24 01:23:35.840 INFO ice STOPPING n.BackupSessionControllerService] STOPPED SystemCheckService [01.29.24 01:23:35.840 INFO ice STOPPING ackupSessionPreValidationService] V3E::STOPPED BackupSessionPreValidationService in 7.901 μs [01.29.24 01:23:35.840 INFO ice STOPPING ynctask.AsyncTaskTrackingService] STOPPED AsyncTaskTrackingService in 151.8 μs [01.29.24 01:23:35.841 INFO ice STOPPING .code42.jna.inotify.ReaderThread] Killing reader thread [01.29.24 01:23:35.841 INFO ice STOPPING rvice.migration.MigrationService] USMT:: STOPPED Migration Service in 203.0 μs [01.29.24 01:23:35.841 INFO ice STOPPING code42.throttle.ThrottlerService] STOPPED ThrottlerService in 61.51 μs [01.29.24 01:23:35.842 INFO ice STOPPING settings.V3EngineSettingsService] V3E::STOPPED V3EngineSettingsService in 1.785 ms [01.29.24 01:23:35.844 INFO ice STOPPING .service.auth.AccessTokenService] ACCESS_TOKEN:: STOPPED AccessTokenService in 75.50 μs [01.29.24 01:23:35.844 INFO ice STOPPING gine.v3.datapipe.DataPipeService] V3E::SHUTDOWN:: STOPPED DataPipeService in 114.1 μs [01.29.24 01:23:35.855 INFO mpl STOPPING y.UserActivityWatcherServiceImpl] UAW:: STOPPED UserActivityWatcherServiceImpl in 20.92 ms [01.29.24 01:23:35.856 INFO ice STOPPING igration.MigrationRestoreService] USMT:: STOPPED Migration Restore Service in 20.29 ms [01.29.24 01:23:35.892 INFO inot-read-1 .code42.jna.inotify.ReaderThread] Reader thread stopped [01.29.24 01:23:35.892 INFO ice STOPPING code42.jna.inotify.HandlerThread] Handler thread killed [01.29.24 01:23:35.892 INFO inot-hand-1 code42.jna.inotify.HandlerThread] Interruption while waiting on inotify event queue [01.29.24 01:23:35.893 INFO ice STOPPING tify.JNAInotifyFileWatcherDriver] All threads dead [01.29.24 01:23:35.893 INFO ice STOPPING fileactivity.FileActivityService] V3E::STOPPED FileActivityService in 57.65 ms [01.29.24 01:23:35.894 INFO ice STOPPING localstorage.LocalStorageService] V3E::SHUTDOWN:: STOPPED LocalStorageService in 228.4 μs [01.29.24 01:23:35.894 INFO STOPPING p42.service.ClientServiceManager] CSM:: Finished stopping authorized services in 65.04 ms (stopDepTime=64ms). [01.29.24 01:23:35.894 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------ [01.29.24 01:23:35.895 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------------------------------------- [01.29.24 01:23:35.895 INFO STOPPING p42.service.ClientServiceManager] CSM:: Stopping universal services. [01.29.24 01:23:35.895 INFO ice STOPPING service.coredump.CoreDumpService] CoreDumpService:: STOPPED in 56.97 μs [01.29.24 01:23:35.895 INFO STOPPING kup42.service.GuiceClientRuntime] CMD:: STOPPED client runtime in 21.88 μs. [01.29.24 01:23:35.896 INFO PAC STOPPING proxy.ProxyAutoConfigServiceImpl] PROXY:: STOPPED proxy PAC service. [01.29.24 01:23:35.896 INFO ice STOPPING .code42.service.peer.PeerService] STOPPED PeerService [01.29.24 01:23:35.896 INFO ice STOPPING e42.service.backup.BackupService] BACKUP:: STOPPED in 18.94 μs [01.29.24 01:23:35.896 INFO ice STOPPING e42.service.uiinfo.UIInfoService] STOPPED UIInfoService [01.29.24 01:23:35.897 INFO ice STOPPING .service.ui.http.KeystoreService] STOPPED KeystoreService [01.29.24 01:23:35.897 INFO STOPPING p42.service.ClientServiceManager] CSM:: Finished stopping universal services in 4.409 s (deauthTime=4sec, stopDepTime=2ms). [01.29.24 01:23:35.897 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------------------------------------- [01.29.24 01:23:35.898 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::Shutting down: size=0, #busy=0, #workers=1 [01.29.24 01:23:35.898 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::time=1706484215898, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:35.898 INFO Transfer::-1 code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::time=1706484215898, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=0, sessionID=StopWork [01.29.24 01:23:35.898 INFO Transfer::-1 code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::time=1706484215898, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:35.898 INFO Transfer::-1 code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::time=1706484215898, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:35.898 INFO Transfer::-1 code42.queue.BackgroundWorkQueue] BWQ-FileTransfer::All background workers have shutdown [01.29.24 01:23:36.101 INFO STOPPING atcher.ScheduledFileQueueManager] SFQM: Stop watching all paths [X:, /storage/Pictures, Z:, /storage/VHS, Y:/Jonathan, Y:/Inbar, /storage/Videos, Y:/Old Computer 1992, /storage/Docs] [01.29.24 01:23:36.101 INFO STOPPING .code42.jna.inotify.ReaderThread] Killing reader thread [01.29.24 01:23:36.113 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.114 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.115 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.115 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.115 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.115 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.115 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.116 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.116 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.116 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.116 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.116 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.117 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.117 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.117 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.117 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.117 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.118 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.118 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.118 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.118 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.118 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.119 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.120 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.120 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.120 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.120 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.120 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.121 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.122 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.122 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.122 INFO Thread-29 e42.jna.inotify.JNAInotifyWorker] This run has been cancelled, stopping traversal [01.29.24 01:23:36.151 INFO inot-read-3 .code42.jna.inotify.ReaderThread] Reader thread stopped [01.29.24 01:23:36.153 INFO STOPPING tify.JNAInotifyFileWatcherDriver] Starting reader thread [01.29.24 01:23:36.153 INFO STOPPING ackup.watcher.ScheduledFileQueue] SFQ:1100305632724497181: Stop schedule; ScheduledFileQueue[1100305632724497181, scheduledDelay = 1800000, nextScheduledTime = Mon Jan 29 01:53:35 IST 2024, flushing = false, stats = ScheduledFileStats[numFiles = 0, numBytes = 0, nextScheduledTime = Thu Jan 01 02:00:00 IST 1970], #actions = 0] [01.29.24 01:23:36.153 INFO inot-read-4 .code42.jna.inotify.ReaderThread] Reader thread started [01.29.24 01:23:36.153 INFO STOPPING ackup.watcher.ScheduledFileQueue] SFQ:1: Stop schedule; ScheduledFileQueue[1, scheduledDelay = 1800000, nextScheduledTime = Mon Jan 29 01:53:35 IST 2024, flushing = false, stats = ScheduledFileStats[numFiles = 0, numBytes = 0, nextScheduledTime = Thu Jan 01 02:00:00 IST 1970], #actions = 0] [01.29.24 01:23:36.153 INFO STOPPING .code42.jna.inotify.ReaderThread] Killing reader thread [01.29.24 01:23:36.173 INFO 554080257>42 kup.manifest.BlockManifestVerify] ... verifying BMF 3400000/33929633; /usr/local/crashplan/cache/42/cpbf0000000000000000000/cpbmf [01.29.24 01:23:36.204 INFO inot-read-4 .code42.jna.inotify.ReaderThread] Reader thread stopped [01.29.24 01:23:36.204 INFO STOPPING code42.jna.inotify.HandlerThread] Handler thread killed [01.29.24 01:23:36.204 INFO inot-hand-2 code42.jna.inotify.HandlerThread] Interruption while waiting on inotify event queue [01.29.24 01:23:36.205 INFO STOPPING tify.JNAInotifyFileWatcherDriver] All threads dead [01.29.24 01:23:36.205 INFO dWorker-User ntenance.ArchiveMaintenanceQueue] MAINT: MaintLoadWorker-User: starting... [01.29.24 01:23:36.205 INFO orker-System ntenance.ArchiveMaintenanceQueue] MAINT: MaintLoadWorker-System: starting... [01.29.24 01:23:36.206 INFO STOPPING de42.backup.ClientBackupServerV1] BS[694528144554080257>694528144554080257:: Informing of backup readiness - ready=false, notReadyCode=NOT_AVAILABLE; BS[694528144554080257>694528144554080257, DIRECT SAME, sameOwner=t, backupConnected=f, authorized=t, usingForBackup=f, backupNotReadyCode=null, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=1150475089923290770, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:36.206 INFO STOPPING com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: = Backup NOT ready! BackupServerStats@639872291[ BS 694528144554080257>694528144554080257, backupSystemStarted=false, backupNotReadyCode=NOT_AVAILABLE, outOfSpace=null, outOfSpaceTimestamp=0, validating=false, backingUp=false, numFilesBackedUp=0, manifestSize=0, receiveRateInBytesPerSec(B/s)=0.000, sendRateInBytesPerSec(B/s)=0.000, lastBackupTimestamp=-1, lastCompletedBackupTimestamp=-1, archiveMaintenanceStats=null, compactStats=null, Session: , sessionSourceBytesCompleted=0 (0.00%), sessionLastSourceBytesCompletedTimestamp=1706484186181, sessionActualBytesSent=0, sessionFilesCompleted=0, sessionStopwatch=30sec, sessionCompletedRateInBytesPerSec(B/s)=0.0, dataSize=0, overhead=0, estimatedFreeSpace=-1, minimumFreeSpace=-1, receiveDuration=0 ms; 0MB (0Mbps)]; BS[694528144554080257>694528144554080257, DIRECT SAME, sameOwner=t, backupConnected=f, authorized=t, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=1150475089923290770, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:36.209 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.209 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.209 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.211 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>42, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.211 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.211 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.211 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>42:: Setting keepBlockState=0 during reset(); BC[694528144554080257>42, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=t, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=t, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:128, val=2024-01-29T01:23:23:358, readyCheckTime=2024-01-29T01:23:10:128, MM[BT 694528144554080257>42: openCount=2, initialized = true, dataFiles.open = true, /usr/local/crashplan/cache/42], session=null, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=2024-01-29T01:23:36:208, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = true, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = true, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.211 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::Shutting down: size=0, #busy=1, #workers=1 [01.29.24 01:23:36.211 INFO 554080257>42 de42.backup.manifest.SyncHandler] SYNC::BT-694528144554080257>42: SyncHandler is CLOSED.; ClientSyncHandler@2069407576[ timestamp=1706484202561, txValid=false, bmfValid=true, propsValid=true, pathsValid=true, throttler=200/1000] [01.29.24 01:23:36.211 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::time=1706484216211, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=true, sessionID=StopWork [01.29.24 01:23:36.212 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: INTERRUPTED; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 1706484204176, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = true, deepMaintenance = true, verify = StepStats[startTime = 1706484204182, progress = 3472709/33929633], reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 0, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:36.217 INFO 554080257>42 ce.ClientArchiveV1MaintenanceJob] MAINTJOB: BT[targetId=42]: DONE EXECUTING - completed=false, time(ms)=12039, bmfCacheCleared=false; ArchiveMaintenanceJob[694528144554080257>42, startEntryNum = 0, numInPoint = 0, verifyBlocks = true, reduceEnabled = true, keepBlockState = 2, numToProcess = 21824, lastFileId = null, confirmLastFileId = 9a49c50da96bc6c59e2bbebb7b39cc8d, lastReduceTxTimestamp = 1706484204176, checksumBlocks = true, remoteTransaction = VersionReductionPoint[VersionReductionPoint@1153930959[ txType= 2, txChecksum = caac2a85a99573b8241f6ebd62a2421d, timestamp = 1706009335646, fileId = 9a49c50da96bc6c59e2bbebb7b39cc8d], startingEntryNumber = 0, numberOfEntries = 21824, keepBlockState = 2, executeTimestampInHours = 473891], verifyRestore = false, verifySourceLength = false, numBadFiles = 0, numNotSelected = 0, numDeleted = 0, numWithVersionsRemoved = 0, numMissingParentIds = 0, ArchiveMaintenanceStats[sourceGuid = 694528144554080257, targetGuid = 42, cache = true, running = false, deepMaintenance = true, reduceState = STEP_1_PRUNE_FILES, reduceStateChanged = false, reductionCompleted = false, duration = 12039, step1 = StepStats[startTime = 0, progress = 0/0], step2 = StepStats[startTime = 0, progress = 0/0], step3 = StepStats[startTime = 0, progress = 0/0], step4 = StepStats[startTime = 0, progress = 0/0], compactStats = null]] [01.29.24 01:23:36.218 INFO 554080257>42 de42.backup.manifest.SyncHandler] SYNC::BT-694528144554080257>42: SyncHandler is CLOSED.; ClientSyncHandler@2069407576[ timestamp=1706484202561, txValid=false, bmfValid=true, propsValid=true, pathsValid=true, throttler=200/1000] [01.29.24 01:23:36.218 INFO 554080257>42 t.SyncTransactionLogOnSourceWork] SYNC::BT-694528144554080257>42: TX-CLIENT: STOPPED; ClientSyncHandler@2069407576[ timestamp=1706484202561, txValid=false, bmfValid=true, propsValid=true, pathsValid=true, throttler=200/1000] [01.29.24 01:23:36.218 INFO 84202561::-1 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::time=1706484216218, result=RESULT_NOT_SET, duration=12860, sessionID=694528144554080257>42 [01.29.24 01:23:36.218 INFO 84202561::-1 code42.queue.BackgroundWorkQueue] BWQ-Sync-1706484202561::All background workers have shutdown [01.29.24 01:23:36.313 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>42:: 694528144554080257>42 DISCONNECTED. SHUTDOWN null; BC[694528144554080257>42, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=t, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>42: openCount=0, initialized = true, dataFiles.open = false, /usr/local/crashplan/cache/42], session=null, hosted=t, hostedCloud=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 42, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>42, running=f, #tasks=0, sets=[BackupFileTodoSet[backupSetId=1, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@1833247407[ path = /usr/local/crashplan/cache/cpft1_42, closed = true, dataSize = 12, headerSize = 0], numTodos = 0, numBytes = 0]], BackupFileTodoSet[backupSetId=1100305632724497181, guid=42, doneLoadingFiles=t, doneLoadingTasks=f, FileTodoSet@244070430[ path = /usr/local/crashplan/cache/cpft1100305632724497181_42, closed = true, dataSize = 103, headerSize = 0], numTodos = 1, numBytes = 13061922896]]], env=null, todow=TodoWorker@712723225[ threadName = BQTodoWkr-42, stopped = true], taskw=TaskWorker@641817438[ threadName = BQTaskWrk-42, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.314 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>694528144554080257, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.314 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.314 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.315 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>694528144554080257, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.315 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.315 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.315 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BC[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=t, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=null, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.315 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>694528144554080257:: 694528144554080257>694528144554080257 DISCONNECTED. SHUTDOWN null; BC[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/694528144554080257], session=null, hosted=f, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 694528144554080257, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>694528144554080257, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@258499391[ threadName = BQTodoWkr-694528144554080257, stopped = true], taskw=TaskWorker@1274832935[ threadName = BQTaskWrk-694528144554080257, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>4200, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::stopRestore(): idPair=694528144554080257>4200, selectedForRestore=false, event=STOP_REQUESTED canceled=false [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::Not selected for restore [01.29.24 01:23:36.316 INFO STOPPING tore.BackupClientRestoreDelegate] BC::0 pending restore canceled [01.29.24 01:23:36.316 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>4200:: Setting keepBlockState=0 during reset(); BC[694528144554080257>4200, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=2024-01-29T01:23:10:132, val=0, readyCheckTime=2024-01-29T01:23:10:132, MM[BT 694528144554080257>4200: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/4200], session=null, authority=t, hosted=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 4200, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>4200, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@1146265391[ threadName = BQTodoWkr-4200, stopped = true], taskw=TaskWorker@1083321971[ threadName = BQTaskWrk-4200, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.317 INFO STOPPING com.code42.backup.BackupEntityV1] BC[694528144554080257>4200:: 694528144554080257>4200 DISCONNECTED. SHUTDOWN null; BC[694528144554080257>4200, sameOwner=f, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BT 694528144554080257>4200: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/cache/4200], session=null, authority=t, hosted=t, replacing=f, selectedForBackup=f, selectedForRestore=f, validationNeeded=f, backupUsageTime=0, cacheMaintenanceState=null, restoreUtil=BackupClientRestoreDelegate [restoreEnv=null, selectedForRestore=false, remoteRestoreStats=RestoreStats[BT sourceId = 694528144554080257, targetId = 4200, restoreId = 0, selectedForRestore = false, restoring = false, completed = false, completedTimeInMillis = null, stopwatch = 30sec, numFilesToRestore = 0, numBytesToRestore = 0, numFilesRestored = 0, numBytesRestored = 0, %complete = 100.00%, receiveRateInBytesPerSec(B/s) = 0.000, sendRateInBytesPerSec(B/s) = 0.000, estimatedTimeRemaining = 0.000, fileNumBytesToRestore = 0, fileNumBytesRestored = 0, %completeCurrentFile = 100.00%, numSessionFilesRestored = 0, numSessionBytesRestored = 0, problemCount = 0], pendingRestoresCount=0], BackupQueue[694528144554080257>4200, running=f, #tasks=0, sets=[], env=null, todow=TodoWorker@1146265391[ threadName = BQTodoWkr-4200, stopped = true], taskw=TaskWorker@1083321971[ threadName = BQTaskWrk-4200, stopped = true], lastTask=null] ]; [01.29.24 01:23:36.317 INFO STOPPING com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: Setting keepBlockState=0 during reset(); BS[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=t, keepBlockState=0, con=2024-01-29T01:23:10:715, val=0, readyCheckTime=2024-01-29T01:23:10:715, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=null, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:36.317 INFO STOPPING com.code42.backup.BackupEntityV1] BS[694528144554080257>694528144554080257:: 694528144554080257>694528144554080257 DISCONNECTED. SHUTDOWN null; BS[694528144554080257>694528144554080257, SAME, sameOwner=t, backupConnected=f, authorized=f, usingForBackup=f, backupNotReadyCode=NOT_AVAILABLE, backingUp=f, validating=f, closing=f, keepBlockState=0, con=0, val=0, readyCheckTime=0, MM[BS 694528144554080257>694528144554080257: openCount=0, initialized = false, dataFiles.open = false, /usr/local/crashplan/manifest/694528144554080257], session=null, capacityManager=CapacityManager[694528144554080257>694528144554080257, hostedDestination = false, allotted = -1, allottedForAllRelated = false, lastReset = 0]]; [01.29.24 01:23:36.317 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Backup::Shutting down: size=0, #busy=0, #workers=4 [01.29.24 01:23:36.317 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216317, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.317 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216317, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.318 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216317, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.317 INFO Q-Backup::-1 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216317, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=0, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-2 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216317, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=-1, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-2 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-4 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=-2, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-1 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-3 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=-1, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-4 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.318 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-2 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-3 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-3 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-1 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-4 code42.queue.BackgroundWorkQueue] BWQ-Backup::time=1706484216318, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.318 INFO Q-Backup::-4 code42.queue.BackgroundWorkQueue] BWQ-Backup::All background workers have shutdown [01.29.24 01:23:36.318 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Replace::Shutting down: size=0, #busy=0, #workers=2 [01.29.24 01:23:36.319 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, queueSize=1, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-1 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=0, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-2 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, durationQueued=-1, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-1 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.319 INFO STOPPING code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, queueSize=0, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, overflowFlag=false, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-2 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, itemType=class com.code42.queue.BackgroundWorkQueue$StopWork, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-1 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-2 code42.queue.BackgroundWorkQueue] BWQ-Replace::time=1706484216319, result=RESULT_NOT_SET, duration=0, sessionID=StopWork [01.29.24 01:23:36.319 INFO -Replace::-2 code42.queue.BackgroundWorkQueue] BWQ-Replace::All background workers have shutdown [01.29.24 01:23:36.319 INFO STOPPING com.code42.backup.BackupManager] Backup torn down. [01.29.24 01:23:36.321 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------------------------------------- [01.29.24 01:23:36.321 INFO STOPPING p42.service.ClientServiceManager] CSM:: Stopping platform services. [01.29.24 01:23:36.322 INFO mpl STOPPING ction.TamperDetectionServiceImpl] TAMPER:: STOPPED [01.29.24 01:23:36.325 INFO ice STOPPING .storage.UniversalStorageService] SM:: Saved ServiceModel of 43933 bytes to UDB in 2.462 ms. [01.29.24 01:23:36.333 INFO ice STOPPING .storage.UniversalStorageService] UDB:: STOPPED Universal Database (UDB) in 10.93 ms [01.29.24 01:23:36.333 INFO STOPPING p42.service.ClientServiceManager] CSM:: Finished stopping platform services in 4.844 s. [01.29.24 01:23:36.333 INFO STOPPING p42.service.ClientServiceManager] CSM:: ------------------------------------------------------------- [01.29.24 01:23:36.333 INFO STOPPING com.backup42.service.CPService] SHUTDOWN:: Finished cleanup after 4.845 s. Thanks!

Suddenly my crashplan docker refuses to start properly. It initially seems to start but after a short while it's marked as stopped. It happened once before with no apparent cause, but upgrading unraid to the latest version solved the issue, until it suddenly happened again. restarting the server doesn't help. Any help will be much appreciated! Here's the log: ╭――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――╮ │ │ │ Application: CrashPlan for Small Business │ │ Application Version: 11.1.1 │ │ Docker Image Version: 23.06.2 │ │ Docker Image Platform: linux/amd64 │ │ │ ╰――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――╯ [cont-init ] 89-info.sh: terminated successfully. [cont-init ] all container initialization scripts executed. [init ] giving control to process supervisor. [supervisor ] loading services... [supervisor ] loading service 'default'... [supervisor ] loading service 'app'... [supervisor ] loading service 'gui'... [supervisor ] loading service 'certsmonitor'... [supervisor ] service 'certsmonitor' is disabled. [supervisor ] loading service 'nginx'... [supervisor ] loading service 'xvnc'... [supervisor ] loading service 'openbox'... [supervisor ] loading service 'CrashPlanEngine'... [supervisor ] loading service 'logmonitor'... [supervisor ] loading service 'logrotate'... [supervisor ] all services loaded. [supervisor ] starting services... [supervisor ] starting service 'xvnc'... [xvnc ] Xvnc TigerVNC 1.13.1 - built May 16 2023 17:43:49 [xvnc ] Copyright (C) 1999-2022 TigerVNC Team and many others (see README.rst) [xvnc ] See https://www.tigervnc.org for information on TigerVNC. [xvnc ] Underlying X server release 12014000 [xvnc ] Thu Jan 11 21:24:25 2024 [xvnc ] vncext: VNC extension running! [xvnc ] vncext: Listening for VNC connections on /tmp/vnc.sock (mode 0660) [xvnc ] vncext: Listening for VNC connections on all interface(s), port 5900 [xvnc ] vncext: created VNC server for screen 0 [supervisor ] starting service 'nginx'... [nginx ] Listening for HTTP connections on port 5800. [supervisor ] starting service 'openbox'... [supervisor ] starting service 'CrashPlanEngine'... [supervisor ] starting service 'app'... [app ] Bus error [supervisor ] starting service 'logmonitor'... [logmonitor ] Monitoring log file: /config/log/service.log.0 [logmonitor ] Monitoring status file: /config/log/app.log [supervisor ] all services started. [supervisor ] service 'app' exited (with status 135). [supervisor ] service 'app' exited, shutting down... [supervisor ] stopping service 'logmonitor'... [supervisor ] service 'logmonitor' exited (got signal SIGTERM). [supervisor ] stopping service 'CrashPlanEngine'... [supervisor ] stopping service 'openbox'... [supervisor ] service 'openbox' exited (with status 0). [supervisor ] stopping service 'nginx'... [supervisor ] service 'nginx' exited (with status 0). [supervisor ] stopping service 'xvnc'... [xvnc ] Thu Jan 11 21:25:00 2024 [xvnc ] ComparingUpdateTracker: 0 pixels in / 0 pixels out [xvnc ] ComparingUpdateTracker: (1:-nan ratio) [supervisor ] service 'xvnc' exited (with status 0). [supervisor ] sending SIGTERM to all processes... [supervisor ] sending SIGKILL to all processes... [supervisor ] service 'CrashPlanEngine' exited (got signal SIGKILL). [finish ] executing container finish scripts... [finish ] all container finish scripts executed.