Post by Scott GiffordI'm running vdccm-0.9.3 fedora package
0.10.0 is available from the SynCE SourceForge page, or you could try
the one from SVN. Maybe it contains some useful bug fixes.
I have now upgraded to latest svn.
Post by Scott Gifford[...]
Post by Scott GiffordAt any rate, the way to debug it is to run vdccm with debugging
cranked up, and see what happens when you plug the device in.
ok.
**********************
vdccm -d 5 -f -i
[static void Utils::runScripts(std::string, std::string):229]
Running script: /home/patrick/.synce/scripts/dccm.sh start
[...]
[void DeviceManager::addConnectedDevice(WindowsCEDeviceBase*):72]
Device connected: 192.168.131.129
[...]
OK, so I see one device connect, but not the other one. That's what
you're seeing in this log, right?
Basically.
Post by Scott GiffordThe second device is bringing its PPP interface up, right?
Yes. For about 3 seconds.
Post by Scott GiffordA few
* See if you can ping the device before the ppp interface goes away.
* Run tcpdump on the ppp interface and see if the device is trying
to connect to vdccm.
* Use netstat or lsof to verify that vdccm is listening on address
"0.0.0.0"
* Run strace on vdccm to see if it's getting the connection request.
Hope this helps,
----Scott.
Thanks for your useful input. Here's the output of the commands you
suggested above.
Everything looks correct to me so I can't see why the device is
disconnecting...
*************************
synce-serial-start /dev/ttyUSB1
Serial connection established.
Using interface ppp1
Connect: ppp1 <--> /dev/ttyUSB1
local IP address 192.168.131.2
remote IP address 192.168.131.130
synce-serial-start is now waiting for your device to connect
*************************
/usr/sbin/tcpdump -i ppp1
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on ppp1, link-type LINUX_SLL (Linux cooked), capture size 96 bytes
15:22:34.486865 IP 192.168.131.130.bootpc > 255.255.255.255.bootps:
BOOTP/DHCP, Request, length 247
15:22:34.737779 IP 192.168.131.130.bootpc > 255.255.255.255.bootps:
BOOTP/DHCP, Request, length 247
15:22:34.994489 IP 192.168.131.130.netbios-ns > 192.168.131.255.netbios-ns:
NBT UDP PACKET(137): REGISTRATION; REQUEST; BROADCAST
15:22:35.058972 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: S
16541321:16541321(0) win 32768 <mss 1460,nop,nop,sackOK>
15:22:35.059030 IP 192.168.131.2.dccm > 192.168.131.130.iad2: S
3358762278:3358762278(0) ack 16541322 win 5840 <mss 1460,nop,nop,sackOK>
15:22:35.060216 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: . ack 1 win
33580
15:22:35.061712 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: P 1:5(4) ack
1 win 33580
15:22:35.061734 IP 192.168.131.2.dccm > 192.168.131.130.iad2: . ack 5 win
5840
15:22:35.066844 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: P 5:9(4) ack
1 win 33580
15:22:35.066874 IP 192.168.131.2.dccm > 192.168.131.130.iad2: . ack 9 win
5840
15:22:35.069100 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: P 9:109(100)
ack 1 win 33580
15:22:35.069137 IP 192.168.131.2.dccm > 192.168.131.130.iad2: . ack 109 win
5840
15:22:35.069253 IP 192.168.131.2.dccm > 192.168.131.130.iad2: F 1:1(0) ack
109 win 5840
15:22:35.071471 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: . ack 2 win
33580
15:22:35.082844 IP 192.168.131.130.iad3 > 192.168.131.2.7438: S
16569966:16569966(0) win 32768 <mss 1460,nop,nop,sackOK>
15:22:35.082883 IP 192.168.131.2.7438 > 192.168.131.130.iad3: R 0:0(0) ack
16569967 win 0
15:22:35.087584 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: F 109:109(0)
ack 2 win 33580
15:22:35.087598 IP 192.168.131.2.dccm > 192.168.131.130.iad2: . ack 110 win
5840
15:22:35.088837 IP 192.168.131.130.iad2 > 192.168.131.2.dccm: R
16541431:16541431(0) win 0
15:22:35.245816 IP 192.168.131.130.netbios-ns > 192.168.131.255.netbios-ns:
NBT UDP PACKET(137): REGISTRATION; REQUEST; BROADCAST
15:22:35.496788 IP 192.168.131.130.netbios-ns > 192.168.131.255.netbios-ns:
NBT UDP PACKET(137): REGISTRATION; REQUEST; BROADCAST
15:22:35.563645 IP 192.168.131.130.iad3 > 192.168.131.2.7438: S
16569966:16569966(0) win 32768 <mss 1460,nop,nop,sackOK>
15:22:35.563683 IP 192.168.131.2.7438 > 192.168.131.130.iad3: R 0:0(0) ack
1 win 0
15:22:35.747751 IP 192.168.131.130.netbios-ns > 192.168.131.255.netbios-ns:
NBT UDP PACKET(137): REGISTRATION; REQUEST; BROADCAST
15:22:36.068450 IP 192.168.131.130.iad3 > 192.168.131.2.7438: S
16569966:16569966(0) win 32768 <mss 1460,nop,nop,sackOK>
15:22:36.068493 IP 192.168.131.2.7438 > 192.168.131.130.iad3: R 0:0(0) ack
1 win 0
tcpdump: pcap_loop: recvfrom: Network is down
26 packets captured
26 packets received by filter
0 packets dropped by kernel
*************************
/usr/sbin/lsof | grep "vdccm"
vdccm 20969 patrick 0u CHR 136,3 5
/dev/pts/3
vdccm 20969 patrick 1u CHR 136,3 5
/dev/pts/3
vdccm 20969 patrick 2u CHR 136,3 5
/dev/pts/3
vdccm 20969 patrick 3u IPv4 106623 TCP
*:ftps (LISTEN)
vdccm 20969 patrick 4u IPv4 106624 TCP
*:dccm (LISTEN)
vdccm 20969 patrick 5u unix 0xf5f5f900 106625
/home/patrick/.synce/csock
vdccm 20969 patrick 6r FIFO 0,6 106627 pipe
vdccm 20969 patrick 7w FIFO 0,6 106627 pipe
vdccm 20969 patrick 8u unix 0xf5f5f580 106628
socket
vdccm 20969 patrick 9u unix 0xf565e200 106630
socket
vdccm 20969 patrick 10u IPv4 107765 TCP
192.168.131.1:dccm->192.168.131.129:1028 (ESTABLISHED)
yum 21837 root cwd DIR 253,0 4096 10193029
/usr/local/src/SynCe/vdccm
*************************
netstat
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address Foreign Address
State
tcp 2383 0 192.168.1.2:50973 ftp.chg.ru:http
CLOSE_WAIT
tcp 2382 0 192.168.1.2:50976 ftp.chg.ru:http
CLOSE_WAIT
tcp 0 0 192.168.131.1:dccm 192.168.131.129:1028
ESTABLISHED
tcp 1 0 192.168.1.2:37498 admin.fedora.redhat.co:http
CLOSE_WAIT
tcp 64639 0 sgmwongnb.dna.dci.dis:49553 download.fedora.redhat:http
ESTABLISHED
tcp 1 0 192.168.1.2:48280 ftp.kddlabs.co.jp:http
CLOSE_WAIT
*************************
strace -p 22556
Process 22556 attached - interrupt to quit
select(6, [3 4 5], NULL, NULL, {4, 346000}) = 0 (Timeout)
gettimeofday({1190969068, 303681}, NULL) = 0
gettimeofday({1190969068, 303730}, NULL) = 0
gettimeofday({1190969068, 303772}, NULL) = 0
select(6, [3 4 5], NULL, NULL, {4, 999333}) = 0 (Timeout)
gettimeofday({1190969073, 303677}, NULL) = 0
gettimeofday({1190969073, 303715}, NULL) = 0
gettimeofday({1190969073, 303742}, NULL) = 0
select(6, [3 4 5], NULL, NULL, {4, 999363}) = 0 (Timeout)
gettimeofday({1190969078, 303679}, NULL) = 0
gettimeofday({1190969078, 303749}, NULL) = 0
gettimeofday({1190969078, 303796}, NULL) = 0
select(6, [3 4 5], NULL, NULL, {4, 999309}) = 1 (in [4], left {4, 334000})
select(5, [4], NULL, NULL, NULL) = 1 (in [4])
accept(4, {sa_family=AF_INET, sin_port=htons(1043), sin_addr=inet_addr("192.168.131.130")}, [16]) = 10
getpeername(10, {sa_family=AF_INET, sin_port=htons(1043),
sin_addr=inet_addr("192.168.131.130")}, [16]) = 0
setsockopt(10, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
getsockname(10, {sa_family=AF_INET, sin_port=htons(5679),
sin_addr=inet_addr("192.168.131.2")}, [16]) = 0
gettimeofday({1190969078, 970473}, NULL) = 0
gettimeofday({1190969078, 970527}, NULL) = 0
select(11, [3 4 5 10], NULL, NULL, {4, 332578}) = 1 (in [10], left {4,
332578})
read(10, "\0\0\0\0", 4) = 4
write(2, "[bool WindowsCEDevice::handleEve"..., 42) = 42
write(2, "Header: 0", 9) = 9
write(2, "\n", 1) = 1
write(2, "[bool WindowsCEDevice::handleEve"..., 42) = 42
write(2, "initialization package", 22) = 22
write(2, "\n", 1) = 1
gettimeofday({1190969078, 971621}, NULL) = 0
gettimeofday({1190969078, 971675}, NULL) = 0
select(11, [3 4 5 10], NULL, NULL, {4, 331430}) = 1 (in [10], left {4,
328000})
read(10, "d\0\0\0", 4) = 4
write(2, "[bool WindowsCEDevice::handleEve"..., 42) = 42
write(2, "Header: 100", 11) = 11
write(2, "\n", 1) = 1
write(2, "[bool WindowsCEDevice::handleInf"..., 55) = 55
write(2, "this is an information message", 30) = 30
write(2, "\n", 1) = 1
read(10, "(\0\0\0\5\0\0\0\21\n\0\0\0\0\0\0)U\211`\0\0\0\0(\0\0\000"...,
100) = 100
open("/usr/lib/gconv/gconv-modules.cache", O_RDONLY) = 11
fstat64(11, {st_mode=S_IFREG|0644, st_size=25486, ...}) = 0
mmap2(NULL, 25486, PROT_READ, MAP_SHARED, 11, 0) = 0xb7f6c000
close(11) = 0
futex(0x4bd27a4c, FUTEX_WAKE, 2147483647) = 0
open("/usr/lib/gconv/ISO8859-1.so", O_RDONLY) = 11
read(11, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0 \3\0\000"...,
512) = 512
fstat64(11, {st_mode=S_IFREG|0755, st_size=5436, ...}) = 0
mmap2(NULL, 8212, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 11, 0) =
0x24f000
mmap2(0x250000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 11, 0) = 0x250000
close(11) = 0
write(7, "A", 1) = 1
futex(0x95fc0dc, FUTEX_WAKE, 1) = 1
getuid32() = 501
open("/etc/passwd", O_RDONLY) = 11
fcntl64(11, F_GETFD) = 0
fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
fstat64(11, {st_mode=S_IFREG|0644, st_size=1938, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7f6b000
read(11, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1938
close(11) = 0
munmap(0xb7f6b000, 4096) = 0
stat64("/home/patrick/.synce", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
write(2, "[bool ConnectionFileManager::_wr"..., 96) = 96
write(2, "Writing client-file: /home/patri"..., 57) = 57
write(2, "\n", 1) = 1
open("/home/patrick/.synce/192.168.131.130", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 11
write(11, "# Modifications to this file wil"..., 78) = 78
write(11, "\n", 1) = 1
write(11, "[dccm]\n", 7) = 7
write(11, "pid=22556\n", 10) = 10
write(11, "\n", 1) = 1
write(11, "[device]\n", 9) = 9
write(11, "os_version=5\n", 13) = 13
write(11, "build_bumber=0\n", 15) = 15
write(11, "processor_type=2577\n", 20) = 20
write(11, "partner_id_1=1619612969\n", 24) = 24
write(11, "partner_id_2=0\n", 15) = 15
<snip>
write(11, "ip=192.168.131.130\n", 19) = 19
write(11, "port=1043\n", 10) = 10
write(11, "\n", 1) = 1
write(11, "[connection]\n", 13) = 13
write(11, "transport=ppp\n", 14) = 14
close(11) = 0
getuid32() = 501
open("/etc/passwd", O_RDONLY) = 11
fcntl64(11, F_GETFD) = 0
fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
fstat64(11, {st_mode=S_IFREG|0644, st_size=1938, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7f6b000
read(11, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1938
close(11) = 0
munmap(0xb7f6b000, 4096) = 0
stat64("/home/patrick/.synce", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
write(2, "[bool ConnectionFileManager::_wr"..., 96) = 96
write(2, "Writing client-file: /home/patri"..., 59) = 59
write(2, "\n", 1) = 1
open("/home/patrick/.synce/active_connection", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 11
write(11, "# Modifications to this file wil"..., 78) = 78
write(11, "\n", 1) = 1
write(11, "[dccm]\n", 7) = 7
write(11, "pid=22556\n", 10) = 10
write(11, "\n", 1) = 1
write(11, "[device]\n", 9) = 9
write(11, "os_version=5\n", 13) = 13
write(11, "build_bumber=0\n", 15) = 15
write(11, "processor_type=2577\n", 20) = 20
write(11, "partner_id_1=1619612969\n", 24) = 24
write(11, "partner_id_2=0\n", 15) = 15
<snip>
write(11, "ip=192.168.131.130\n", 19) = 19
write(11, "port=1043\n", 10) = 10
write(11, "\n", 1) = 1
write(11, "[connection]\n", 13) = 13
write(11, "transport=ppp\n", 14) = 14
close(11) = 0
getuid32() = 501
open("/etc/passwd", O_RDONLY) = 11
fcntl64(11, F_GETFD) = 0
fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
fstat64(11, {st_mode=S_IFREG|0644, st_size=1938, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7f6b000
read(11, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1938
close(11) = 0
munmap(0xb7f6b000, 4096) = 0
stat64("/home/patrick/.synce", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
stat64("/home/patrick/.synce/scripts", {st_mode=S_IFDIR|0700, st_size=4096,
..}) = 0
open("/home/patrick/.synce/scripts", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 11
fstat64(11, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
getdents(11, /* 3 entries */, 4096) = 52
lstat64("/home/patrick/.synce/scripts/.", {st_mode=S_IFDIR|0700,
st_size=4096, ...}) = 0
lstat64("/home/patrick/.synce/scripts/dccm.sh", {st_mode=S_IFREG|0755,
st_size=245, ...}) = 0
write(2, "[static void Utils::runScripts(s"..., 62) = 62
write(2, "Running script: /home/patrick/.s"..., 60) = 60
write(2, "\n", 1) = 1
rt_sigaction(SIGINT, {SIG_IGN}, {0x80516f0, [INT], SA_RESTART}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_IGN}, {0x80516f0, [QUIT], SA_RESTART}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
clone(child_stack=0, flags=CLONE_PARENT_SETTID|SIGCHLD, parent_tidptr=0xbf854294) = 22677
waitpid(22677, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0) = 22677
rt_sigaction(SIGINT, {0x80516f0, [INT], SA_RESTART}, NULL, 8) = 0
rt_sigaction(SIGQUIT, {0x80516f0, [QUIT], SA_RESTART}, NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
lstat64("/home/patrick/.synce/scripts/..", {st_mode=S_IFDIR|0700,
st_size=4096, ...}) = 0
getdents(11, /* 0 entries */, 4096) = 0
close(11) = 0
write(2, "[void DeviceManager::addConnecte"..., 66) = 66
write(2, "Device connected: 192.168.131.13"..., 33) = 33
write(2, "\n", 1) = 1
gettimeofday({1190969078, 992408}, NULL) = 0
gettimeofday({1190969078, 992451}, NULL) = 0
select(11, [3 4 5 10], NULL, NULL, {4, 310654}) = 0 (Timeout)
gettimeofday({1190969083, 302684}, NULL) = 0
gettimeofday({1190969083, 302746}, NULL) = 0
*************************