search

droboports / crashplan

CrashPlan DroboApp build scripts
GNU General Public License v2.0
17 stars 1 forks source link

Receiving LogWrapper warning and backups connecting and disconnecting frequently #11

Closed smenzer closed 9 years ago

smenzer commented 9 years ago

Looking through my log.txt file, I'm seeing many instances of the following message. It was happening about twice a day until today, and now I get it every 5 minutes or so followed by what looks like a stop command. I noticed on my remote machine that backs up to the drobo stopped last night (around the timing of these messages appearing frequently). Do these mean there's an issue somewhere or should I just ignore them?

Jul 15, 2015 1:03:41 AM net.sbbi.upnp.LogWrapper warn
WARNING: Discovery message sender IP /10.0.0.1 does not match device description IP /172.16.12.1 skipping device, set the net.sbbi.upnp.ddos.matchip system property to false to avoid this check
2015-07-15 02-06-40: ./CrashPlanEngine stop

I can also no longer access the drobo via the UI on my client machine; although after doing a service.sh restart backups starting running again, but I still get the warning, followed by more messages - here's the full log after the restart I did. Backups stopped about 2 minutes after they were running and just as I've been writing this, have turned on and off a few times (judging by my Crashplan UI on the remote computer saying it's connected to my Drobo or not): https://www.dropbox.com/s/bu8eiafmsf1a07z/log-txt-snippet.txt?dl=0

ricardopadilha commented 9 years ago

Is there a DroboApps/crashplan/app/upgrade/1427864410430.1436272946175 folder (or something like that)? Do you have a file called DroboApps/crashplan/app/lib/com.backup42.desktop.jar?

smenzer commented 9 years ago

No and Yes respectively, see below

$ pwd
/mnt/DroboFS/Shares/DroboApps/crashplan/app/upgrade
$ ls -la
drwxr-xr-x    3 root     root         4096 Jul 13 17:45 .
drwxrwxr-x   11 root     root         4096 Jul 13 17:45 ..
drwxr-xr-x    2 root     root         4096 Jul  8 18:54 UpgradeUI
-rw-r--r--    1 root     root          127 Jul  8 18:54 start.bat
-rwxr-xr-x    1 root     root          247 Jul  8 18:54 start.sh
-rw-r--r--    1 root     root           92 Jul  8 18:54 startDesktop.bat
-rwxr-xr-x    1 root     root          312 Jul  8 18:54 startDesktop.sh
-rwxr-xr-x    1 root     root          135 Jul  8 18:54 startDesktopLinux.sh
-rwxr-xr-x    1 root     root          137 Jul  8 18:54 startDesktopSolaris.sh
-rwxr-xr-x    1 root     root           87 Jul  8 18:54 startFirst.sh
-rwxr-xr-x    1 root     root          211 Jul  8 18:54 startLinux.sh
-rwxr-xr-x    1 root     root          213 Jul  8 18:54 startSolaris.sh
$ pwd
/mnt/DroboFS/Shares/DroboApps/crashplan/app/lib
$ ls -la com.back*
-rw-r--r--    1 root     root      5702755 Jul  8 18:54 com.backup42.desktop.jar
ricardopadilha commented 9 years ago

What about ps w | grep [C]rashPlanService? And netstat -anp | grep 4242?

smenzer commented 9 years ago 
$ ps w | grep [C]rashPlanService
11276 root      254m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr

$ netstat -anp | grep 4242
netstat: /proc/net/tcp6: No such file or directory
netstat: /proc/net/udp6: No such file or directory
netstat: /proc/net/raw6: No such file or directory
tcp        0      0 0.0.0.0:4242            0.0.0.0:*               LISTEN      11276/java
ricardopadilha commented 9 years ago

Everything looks good so far. Last thing: does /mnt/DroboFS/System/crashplan/.ui_info contain 4243,drobo? Does the .ui_info file on your machine contain the same thing?

smenzer commented 9 years ago

client machine:

$ cat /Library/Application\ Support/CrashPlan/.ui_info
4243,drobo

drobo - very strange, when i first looked at the file it showed 4243,drobo, but when I checked it again it showed something different...I literally ran these commands back to back as you can see below

$ cat /mnt/DroboFS/System/crashplan/.ui_info
4243,drobo
$
$
$
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4247,bbd7a69e-a73a-4322-bf06-0a1b39d1af0a
smenzer commented 9 years ago

here are the last 50 lines of the log.text file if it's helpful

# tail -n50 /tmp/DroboApps/crashplan/log.txt
+ [ ! -d /mnt/DroboFS/Shares/DroboApps/crashplan/tmp ]
+ chmod 777 /mnt/DroboFS/Shares/DroboApps/crashplan/tmp
+ export LC_ALL=en_US.UTF-8
+ export LANG=en_US.UTF-8
+ export LD_LIBRARY_PATH=/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:/mnt/DroboFS/Shares/DroboApps/crashplan/lib:/mnt/DroboFS/Shares/DroboApps/crashplan/app:
+ export HOME=/mnt/DroboFS/System/crashplan
+ . /mnt/DroboFS/Shares/DroboApps/crashplan/app/bin/run.conf
+ SRV_JAVA_OPTS=-Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=CrashPlan -Xms20m -Xmx128m -Dsun.net.inetaddr.ttl=300 -Dnetworkaddress.cache.ttl=300 -Dsun.net.inetaddr.negative.ttl=0 -Dnetworkaddress.cache.negative.ttl=0 -Dc42.native.md5.enabled=false
+ GUI_JAVA_OPTS=-Dfile.encoding=UTF-8 -Dapp=CrashPlanDesktop -DappBaseName=CrashPlan -Xms20m -Xmx512m -Dsun.net.inetaddr.ttl=300 -Dnetworkaddress.cache.ttl=300 -Dsun.net.inetaddr.negative.ttl=0 -Dnetworkaddress.cache.negative.ttl=0 -Dc42.native.md5.enabled=false
+ SRV_JAVA_OPTS=-Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=CrashPlan -Xms20m -Xmx128m -Dsun.net.inetaddr.ttl=300 -Dnetworkaddress.cache.ttl=300 -Dsun.net.inetaddr.negative.ttl=0 -Dnetworkaddress.cache.negative.ttl=0 -Dc42.native.md5.enabled=false -Duser.home=/mnt/DroboFS/System/crashplan -Djava.io.tmpdir=/mnt/DroboFS/Shares/DroboApps/crashplan/tmp -Djava.library.path=/mnt/DroboFS/Shares/DroboApps/crashplan/lib -Djava.net.preferIPv4Stack=true
+ cd /mnt/DroboFS/Shares/DroboApps/crashplan/app
+ setsid /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=CrashPlan -Xms20m -Xmx128m -Dsun.net.inetaddr.ttl=300 -Dnetworkaddress.cache.ttl=300 -Dsun.net.inetaddr.negative.ttl=0 -Dnetworkaddress.cache.negative.ttl=0 -Dc42.native.md5.enabled=false -Duser.home=/mnt/DroboFS/System/crashplan -Djava.io.tmpdir=/mnt/DroboFS/Shares/DroboApps/crashplan/tmp -Djava.library.path=/mnt/DroboFS/Shares/DroboApps/crashplan/lib -Djava.net.preferIPv4Stack=true -classpath /mnt/DroboFS/Shares/DroboApps/crashplan/app/lib/com.backup42.desktop.jar:/mnt/DroboFS/Shares/DroboApps/crashplan/app/lang com.backup42.service.CPService
+ [ 11805 -gt 0 ]
+ local pid=11805
+ echo 11805
+ renice 19 11805
[07.15.15 07:49:05.340 INFO    main                 root                                    ] Locale changed to English
[07.15.15 07:49:05.363 INFO    main                 root                                    ] *************************************************************
[07.15.15 07:49:05.365 INFO    main                 root                                    ] *************************************************************
[07.15.15 07:49:05.387 INFO    main                 root                                    ] STARTED CrashPlanService
[07.15.15 07:49:05.420 INFO    main                 root                                    ] CPVERSION = 4.3.0 - 1427864410430 (2015-04-01T05:00:10:430+0000) - Build: 31
[07.15.15 07:49:05.422 INFO    main                 root                                    ] LOCALE = English
[07.15.15 07:49:05.442 INFO    main                 root                                    ] ARGS = [  ]
[07.15.15 07:49:05.443 INFO    main                 root                                    ] *************************************************************
[07.15.15 07:49:09.362 INFO    main                 root                                    ] Adding shutdown hook.
[07.15.15 07:49:09.501 INFO    main                 root                                    ] BEGIN Loading Configuration
[07.15.15 07:49:11.914 INFO    main                 root                                    ] BEGIN Copy Custom
[07.15.15 07:49:11.928 INFO    main                 root                                    ]   Directories: [.Custom, custom, /repository/.Custom, /repository/custom]
[07.15.15 07:49:11.929 INFO    main                 root                                    ]   NOT waiting for custom skin to appear
[07.15.15 07:49:11.931 INFO    main                 root                                    ]   NO customizations found.
[07.15.15 07:49:11.932 INFO    main                 root                                    ] END Copy Custom
[07.15.15 07:49:12.282 INFO    main                 root                                    ]   Loading from default: /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/default.service.xml
[07.15.15 07:49:28.701 INFO    main                 root                                    ]   Loading from my xml file=conf/my.service.xml
[07.15.15 07:49:31.194 INFO    main                 root                                    ]   Loading ServiceConfig, newInstall=false, version=7, configDateMs=1436737144698, installVersion=1427864410430
[07.15.15 07:49:31.207 INFO    main                 root                                    ]   OS = Linux
[07.15.15 07:49:36.161 INFO    main                 root                                    ]   AuthorityLocation@32879903[ location=central.crashplan.com:443, hideAddress=false, isLocked=false ]
[07.15.15 07:49:36.460 INFO    main                 root                                    ]   Checking Java memory heap max.
[07.15.15 07:49:36.518 INFO    main                 root                                    ]     Previous Java memory max heap size was 128
[07.15.15 07:49:36.587 INFO    main                 root                                    ] END Loading Configuration
[07.15.15 07:49:36.934 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity testing localhost, port=4242, connectionTimeout(ms)=100, retryDuration(ms)=100
[07.15.15 07:49:37.178 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity test done. localhost,  false in 226 ms
[07.15.15 07:49:37.181 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity testing localhost, port=4243, connectionTimeout(ms)=100, retryDuration(ms)=100
[07.15.15 07:49:37.239 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity test done. localhost, localhost/127.0.0.1:4243 true in 56 ms
[07.15.15 07:49:37.242 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity testing localhost, port=4246, connectionTimeout(ms)=100, retryDuration(ms)=100
[07.15.15 07:49:37.569 INFO    main                 com.code42.net.ConnectivityTester       ] Failed to connect after duration=324, retryDuration=100, address=localhost, connectTimeout=100, e=Connection refused
[07.15.15 07:49:37.571 INFO    main                 com.code42.net.ConnectivityTester       ] Connectivity testing localhost, port=4247, connectionTimeout(ms)=100, retryDuration(ms)=100
[07.15.15 07:49:37.698 INFO    main                 com.code42.net.ConnectivityTester       ] Failed to connect after duration=125, retryDuration=100, address=localhost, connectTimeout=100, e=Connection refused
[07.15.15 07:49:37.701 INFO    main                 com.backup42.service.CPService          ] Ports have changed, updating config. oldServicePort=4242, newServicePort=4246, newUIPort=4247
[07.15.15 07:49:39.756 INFO    main                 com.backup42.service.ui.UIInfoUtility   ] Wrote port=4247 and token to location=/var/lib/crashplan/.ui_info
jtux Loaded.
ricardopadilha commented 9 years ago

Yeah, this has been happening for other people as well. Crashplan just decides that changing the port is a good idea. The solution is to stop crashplan, edit /mnt/DroboFS/System/crashplan/.ui_info to contain the correct information, then start crashplan again.

smenzer commented 9 years ago

Ok, so I stopped crashplan, re-wrote the file, then started again and it immediately re-wrote the file on me. Check this out, happened two more times in a row:

# current status
$ date
Wed Jul 15 10:52:12 DST 2015
$ ls -la /mnt/DroboFS/System/crashplan/.ui_info
-rw-r--r--    1 root     root           41 Jul 15 10:49 /mnt/DroboFS/System/crashplan/.ui_info
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4247,00d014f3-e8fe-4e77-a4d1-0012297c8d83

# stop crashplan
$ ./service.sh stop
$ ./service.sh status
crashplan is disabled and stopped

# edit .ui_info file

# check that it was properly edited and saved
$ ls -la /mnt/DroboFS/System/crashplan/.ui_info
-rw-r--r--    1 root     root           11 Jul 15 10:53 /mnt/DroboFS/System/crashplan/.ui_info
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4243,drobo

# restart crashplan
$ ./service.sh start
Starting dependency: locale
$ ./service.sh status
crashplan is enabled and running

# initially, the file is fine
$ date
Wed Jul 15 10:54:46 DST 2015
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4243,drobo
$ ls -la /mnt/DroboFS/System/crashplan/.ui_info
-rw-r--r--    1 root     root           11 Jul 15 10:53 /mnt/DroboFS/System/crashplan/.ui_info

# wait a minute or so
$ date
Wed Jul 15 10:56:17 DST 2015
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4247,02f9b191-3a41-4308-858e-3796c803ab23#
$ ls -la /mnt/DroboFS/System/crashplan/.ui_info
-rw-r--r--    1 root     root           41 Jul 15 10:54 /mnt/DroboFS/System/crashplan/.ui_info
ricardopadilha commented 9 years ago

What about ps w | grep [C]rashPlanService after service.sh stop? The only thing I can think of is that crashplan is not bring shutdown properly before you edit the file.

smenzer commented 9 years ago 
$ ./service.sh stop
$ ps w | grep [C]rashPlanService
11276 root      258m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
$ netstat -anp | grep 4242
tcp        0      0 0.0.0.0:4242            0.0.0.0:*               LISTEN      11276/java
tcp        0      1 10.0.0.20:44648         192.168.1.117:4242      SYN_SENT    11276/java
tcp        0      1 10.0.0.20:45681         10.0.1.15:4242          SYN_SENT    11276/java
tcp        0      0 10.0.0.20:60642         10.0.0.10:4242          TIME_WAIT   -
netstat: /proc/net/tcp6: No such file or directory
netstat: /proc/net/udp6: No such file or directory
netstat: /proc/net/raw6: No such file or directory
ricardopadilha commented 9 years ago

Yeah, that might the reason why it is jumping to another port. Wait a little bit, until ps w shows no more processes, then edit the file.

smenzer commented 9 years ago

ok, so i stopped it and have been monitoring ps w and all of a sudden I got two services running instead of one and when I checked the status of crashplan, it was running again. 

$ ./service.sh status
crashplan is disabled and stopped
$ ps w | grep [C]rashPlanService
11276 root      258m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
$ ps w | grep [C]rashPlanService
11276 root      258m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
15193 root      218m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
$
$
$
$
$ ps w | grep [C]rashPlanService
11276 root      258m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
15193 root      221m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
$ ./service.sh status
crashplan is enabled and running
$ ./service.sh stop
$ ./service.sh status
crashplan is disabled and stopped
$ ps w | grep [C]rashPlanService
11276 root      258m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
smenzer commented 9 years ago

I tried a kill 11276 and it seemed to knock that one process out. Once it was off, I tried editing the .ui_info file again...we'll see if it sticks this time.

smenzer commented 9 years ago

...nope, changed the file again.

ricardopadilha commented 9 years ago

What about grep servicePort /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/my.service.xml? It should be <servicePort>4243</servicePort>.

smenzer commented 9 years ago

:-( nope

$ grep servicePort /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/my.service.xml
    <servicePort>4247</servicePort>
ricardopadilha commented 9 years ago

Ok, that is actually good news. Change my.service.xml to 4243, and fix .ui_info to 4243 as well. That should fix it.

smenzer commented 9 years ago

ok will try that now

smenzer commented 9 years ago

still getting changed...

$ grep servicePort /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/my.service.xml
    <servicePort>4243</servicePort>
$ ps w | grep [C]rashPlanService
$ ./service.sh start
Starting dependency: locale
$ grep servicePort /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/my.service.xml
    <servicePort>4243</servicePort>
$ cat /mnt/DroboFS/System/crashplan/.ui_info
4243,drobo

# wait ~13 minutes

$ cat /mnt/DroboFS/System/crashplan/.ui_info
$ grep servicePort /mnt/DroboFS/Shares/DroboApps/crashplan/app/conf/my.service.xml
    <servicePort>4247</servicePort>
$ ps w | grep [C]rashPlanService
16618 root      252m S N  /mnt/DroboFS/Shares/DroboApps/java8/bin/java -Dfile.encoding=UTF-8 -Dapp=CrashPlanService -DappBaseName=Cr
ricardopadilha commented 9 years ago

Well this is frustrating. At this point the only recommendation I have for you is to completely uninstall crashplan (using the Dashboard), reboot the Drobo, then reinstall crashplan. If crashplan insists on not staying on port 4243, then change .ui_info to be 4247,drobo on both Drobo and desktop machine. If you can't beat them...

smenzer commented 9 years ago

alright, i'll give that a shot later tonight.

does that very first warning message I mentioned mean anything?

Jul 15, 2015 1:03:41 AM net.sbbi.upnp.LogWrapper warn
WARNING: Discovery message sender IP /10.0.0.1 does not match device description IP /172.16.12.1 skipping device, set the net.sbbi.upnp.ddos.matchip system property to false to avoid this check
2015-07-15 02-06-40: ./CrashPlanEngine stop
ricardopadilha commented 9 years ago

Not really. I have that warning as well, but it does not seem to prevent crashplan from working fine.

smenzer commented 9 years ago

thanks.

reinstalling seems to work again, but it worked immediately after doing so before. we'll see if this lasts...thanks for all the help!