DUN over bluethoot
eng. Anatoli Marinov
tolisoft at gmail.com
Wed Mar 5 23:09:44 UTC 2008
How I can see what chat command I receive on ppp server?
I enabled ppp debug with
set log All
in my default section. I could not find chat strings here. I am going
to prepare chat script but first have to see what AT command I will
receive (how many AT commands) at the ppp server.
Mar 6 01:05:30 free ppp[30227]: Phase: Using interface: tun1
Mar 6 01:05:30 free ppp[30227]: Phase: deflink: Created in closed state
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set timeout 0
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set lqrperiod 10
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set ifaddr
10.0.0.1 10.0.0.2 255.255.255.0
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: enable lqr
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: accept lqr
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: accept dns
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: disable pap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: deny pap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: disable chap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: deny chap
Mar 6 01:05:30 free ppp[30227]: tun1: ID0: 0x28389e78 =
fopen("/etc/ppp/ppp.conf", "r")
Mar 6 01:05:30 free ppp[30227]: tun1: Debug: ReadSystem: Checking
default (/etc/ppp/ppp.conf).
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set log All
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set timeout 0
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set lqrperiod 10
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: set ifaddr
10.0.0.1 10.0.0.2 255.255.255.0
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: enable lqr
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: accept lqr
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: accept dns
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: disable pap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: deny pap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: disable chap
Mar 6 01:05:30 free ppp[30227]: tun1: Command: default: deny chap
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: PPP Started (direct mode).
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: bundle: Establish
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: deflink: closed -> opening
Mar 6 01:05:30 free ppp[30227]: tun1: Debug: deflink: Link is
SOCK_STREAM, but not inet
Mar 6 01:05:30 free ppp[30227]: tun1: Debug: deflink: stdin is unidentified
Mar 6 01:05:30 free ppp[30227]: tun1: Timer: timer_Start: Inserting
physical throughput timer[0x28419068]
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: deflink: Connected!
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: deflink: opening -> carrier
Mar 6 01:05:30 free ppp[30227]: tun1: Phase: deflink: carrier -> lcp
Mar 6 01:05:30 free ppp[30227]: tun1: LCP: FSM: Using "deflink" as a transport
Mar 6 01:05:30 free ppp[30227]: tun1: LCP: deflink: State change
Initial --> Closed
Mar 6 01:05:30 free ppp[30227]: tun1: LCP: deflink: State change
Closed --> Stopped
Mar 6 01:05:30 free ppp[30227]: tun1: Timer: timer_Start: Inserting
LCP openmode timer[0x2841915c] before physical throughput
timer[0x28419068], delta = 10
Mar 6 01:05:30 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:30 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: Select returns 1
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: read
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: 41 54 26 46 0d
AT&F.
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: deflink: DescriptorRead:
read 5/2048 from 0
Mar 6 01:05:31 free ppp[30227]: tun1: Async: Read
Mar 6 01:05:31 free ppp[30227]: tun1: Async: 41 54 26 46 0d
AT&F.
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: Select returns -1
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: ---- Begin of Timer
Service List---
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: LCP openmode
timer[0x2841915c]: freq = 1.00s, next = 0.00s, state = running
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: physical throughput
timer[0x28419068]: freq = 1.00s, next = 0.00s, state = running
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: ---- End of Timer Service List ---
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: timer_Start: Inserting
physical throughput timer[0x28419068]
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: deflink: LayerStart
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: deflink: SendConfigReq(1)
state = Stopped
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: ACFCOMP[2]
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: PROTOCOMP[2]
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: ACCMAP[6] 0x00000000
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: MRU[4] 1500
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: MAGICNUM[6] 0x1d78c4ce
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: QUALPROTO[8] proto c025,
interval 10000ms
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: fsm_Output
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: 01 01 00 20 08 02 07 02
02 06 00 00 00 00 01 04 ... ............
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: 05 dc 05 06 1d 78 c4 ce
04 08 c0 25 00 00 03 e8 .....x.....%....
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: proto_LayerPush: Using 0xc021
Mar 6 01:05:31 free ppp[30227]: tun1: HDLC: hdlc_Output
Mar 6 01:05:31 free ppp[30227]: tun1: HDLC: ff 03 c0 21 01 01 00 20
08 02 07 02 02 06 00 00 ...!... ........
Mar 6 01:05:31 free ppp[30227]: tun1: HDLC: 00 00 01 04 05 dc 05 06
1d 78 c4 ce 04 08 c0 25 .........x.....%
Mar 6 01:05:31 free ppp[30227]: tun1: HDLC: 00 00 03 e8 e6 cd
......
Mar 6 01:05:31 free ppp[30227]: tun1: Async: Write
Mar 6 01:05:31 free ppp[30227]: tun1: Async: 7e ff 7d 23 c0 21 7d 21
7d 21 7d 20 20 7d 28 7d ~.}#.!}!}!} }(}
Mar 6 01:05:31 free ppp[30227]: tun1: Async: 22 7d 27 7d 22 7d 22 7d
26 7d 20 7d 20 7d 20 7d "}'}"}"}&} } } }
Mar 6 01:05:31 free ppp[30227]: tun1: Async: 20 7d 21 7d 24 7d 25 dc
7d 25 7d 26 7d 3d 78 c4 }!}$}%.}%}&}=x.
Mar 6 01:05:31 free ppp[30227]: tun1: Async: ce 7d 24 7d 28 c0 25 7d
20 7d 20 7d 23 e8 e6 cd .}$}(.%} } }#...
Mar 6 01:05:31 free ppp[30227]: tun1: Async: 7e
~
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: link_PushPacket:
Transmit proto 0xc021
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: m_enqueue: len = 1
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: timer_Start: Inserting
LCP restart timer[0x2841913c]
Mar 6 01:05:31 free ppp[30227]: tun1: LCP: deflink: State change
Stopped --> Req-Sent
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(w) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: Select returns 1
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: m_dequeue: queue len = 1
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: link_Dequeue: Dequeued
from queue 1, containing 0 more packets
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: write
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: 7e ff 7d 23 c0 21 7d
21 7d 21 7d 20 20 7d 28 7d ~.}#.!}!}!} }(}
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: 22 7d 27 7d 22 7d 22
7d 26 7d 20 7d 20 7d 20 7d "}'}"}"}&} } } }
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: 20 7d 21 7d 24 7d 25
dc 7d 25 7d 26 7d 3d 78 c4 }!}$}%.}%}&}=x.
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: ce 7d 24 7d 28 c0 25
7d 20 7d 20 7d 23 e8 e6 cd .}$}(.%} } }#...
Mar 6 01:05:31 free ppp[30227]: tun1: Physical: 7e
~
Mar 6 01:05:31 free ppp[30227]: tun1: Debug: deflink:
DescriptorWrite: wrote 65(65) to 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:31 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: Select returns -1
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: ---- Begin of Timer
Service List---
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: physical throughput
timer[0x28419068]: freq = 1.00s, next = 0.00s, state = running
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: LCP restart
timer[0x2841913c]: freq = 3.00s, next = 2.00s, state = running
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: ---- End of Timer Service List ---
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: timer_Start: Inserting
physical throughput timer[0x28419068] before LCP restart
timer[0x2841913c], delta = 10
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:32 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: Select returns -1
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: ---- Begin of Timer
Service List---
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: physical throughput
timer[0x28419068]: freq = 1.00s, next = 0.00s, state = running
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: LCP restart
timer[0x2841913c]: freq = 3.00s, next = 1.00s, state = running
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: ---- End of Timer Service List ---
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: timer_Start: Inserting
physical throughput timer[0x28419068] before LCP restart
timer[0x2841913c], delta = 10
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:33 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: Select returns -1
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: ---- Begin of Timer
Service List---
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: physical throughput
timer[0x28419068]: freq = 1.00s, next = 0.00s, state = running
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: LCP restart
timer[0x2841913c]: freq = 3.00s, next = 0.00s, state = running
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: ---- End of Timer Service List ---
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: deflink: SendConfigReq(1)
state = Req-Sent
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: ACFCOMP[2]
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: PROTOCOMP[2]
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: ACCMAP[6] 0x00000000
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: MRU[4] 1500
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: MAGICNUM[6] 0x1d78c4ce
Mar 6 01:05:34 free ppp[30227]: tun1: LCP: QUALPROTO[8] proto c025,
interval 10000ms
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: fsm_Output
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: 01 01 00 20 08 02 07 02
02 06 00 00 00 00 01 04 ... ............
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: 05 dc 05 06 1d 78 c4 ce
04 08 c0 25 00 00 03 e8 .....x.....%....
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: proto_LayerPush: Using 0xc021
Mar 6 01:05:34 free ppp[30227]: tun1: HDLC: hdlc_Output
Mar 6 01:05:34 free ppp[30227]: tun1: HDLC: ff 03 c0 21 01 01 00 20
08 02 07 02 02 06 00 00 ...!... ........
Mar 6 01:05:34 free ppp[30227]: tun1: HDLC: 00 00 01 04 05 dc 05 06
1d 78 c4 ce 04 08 c0 25 .........x.....%
Mar 6 01:05:34 free ppp[30227]: tun1: HDLC: 00 00 03 e8 e6 cd
......
Mar 6 01:05:34 free ppp[30227]: tun1: Async: Write
Mar 6 01:05:34 free ppp[30227]: tun1: Async: 7e ff 7d 23 c0 21 7d 21
7d 21 7d 20 20 7d 28 7d ~.}#.!}!}!} }(}
Mar 6 01:05:34 free ppp[30227]: tun1: Async: 22 7d 27 7d 22 7d 22 7d
26 7d 20 7d 20 7d 20 7d "}'}"}"}&} } } }
Mar 6 01:05:34 free ppp[30227]: tun1: Async: 20 7d 21 7d 24 7d 25 dc
7d 25 7d 26 7d 3d 78 c4 }!}$}%.}%}&}=x.
Mar 6 01:05:34 free ppp[30227]: tun1: Async: ce 7d 24 7d 28 c0 25 7d
20 7d 20 7d 23 e8 e6 cd .}$}(.%} } }#...
Mar 6 01:05:34 free ppp[30227]: tun1: Async: 7e
~
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: link_PushPacket:
Transmit proto 0xc021
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: m_enqueue: len = 1
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: timer_Start: Inserting
LCP restart timer[0x2841913c]
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: timer_Start: Inserting
LCP restart timer[0x2841913c]
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: timer_Start: Inserting
physical throughput timer[0x28419068] before LCP restart
timer[0x2841913c], delta = 10
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: deflink: fdset(w) 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: Select returns 1
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: m_dequeue: queue len = 1
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: link_Dequeue: Dequeued
from queue 1, containing 0 more packets
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: write
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: 7e ff 7d 23 c0 21 7d
21 7d 21 7d 20 20 7d 28 7d ~.}#.!}!}!} }(}
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: 22 7d 27 7d 22 7d 22
7d 26 7d 20 7d 20 7d 20 7d "}'}"}"}&} } } }
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: 20 7d 21 7d 24 7d 25
dc 7d 25 7d 26 7d 3d 78 c4 }!}$}%.}%}&}=x.
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: ce 7d 24 7d 28 c0 25
7d 20 7d 20 7d 23 e8 e6 cd .}$}(.%} } }#...
Mar 6 01:05:34 free ppp[30227]: tun1: Physical: 7e
~
Mar 6 01:05:34 free ppp[30227]: tun1: Debug: deflink:
DescriptorWrite: wrote 65(65) to 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: deflink: fdset(r) 0
Mar 6 01:05:34 free ppp[30227]: tun1: Timer: deflink: fdset(e) 0
Mar 6 01:05:35 free ppp[30227]: tun1: Timer: Select returns 1
Mar 6 01:05:35 free ppp[30227]: tun1: Physical: read
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: deflink: DescriptorRead:
read 0/2048 from 0
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: deflink: read (0): Got zero bytes
Mar 6 01:05:35 free ppp[30227]: tun1: LCP: deflink: State change
Req-Sent --> Starting
Mar 6 01:05:35 free ppp[30227]: tun1: LCP: deflink: LayerFinish
Mar 6 01:05:35 free ppp[30227]: tun1: LCP: deflink: State change
Starting --> Initial
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: deflink: Disconnected!
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: deflink: Close
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: deflink: Connect time: 5
secs: 5 octets in, 130 octets out
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: deflink: 1 packets in, 2
packets out
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: total 27 bytes/sec,
peak 27 bytes/sec on Thu Mar 6 01:05:34 2008
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: deflink: lcp -> closed
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: route_IfDelete (8)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = socket(2, 2, 0)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = ioctl(0, 3223349521, 0xbfbfdddc)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = ioctl(0, 2149607696, 0xbfbfdddc)
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: bundle: Dead
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = ioctl(8, 2148037723, 0xbfbfe6f0)
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: route_UpdateMTU (8)
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: DoLoop done.
Mar 6 01:05:35 free ppp[30227]: tun1: Phase: PPP Terminated (normal).
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: route_IfDelete (8)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = socket(2, 2, 0)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = ioctl(0, 3223349521, 0xbfbfe2ac)
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = ioctl(0, 2149607696, 0xbfbfe2ac)
Mar 6 01:05:35 free ppp[30227]: tun1: Debug: Radius: radius_Destroy
Mar 6 01:05:35 free ppp[30227]: tun1: ID0: 0 = unlink("/var/run/tun1.pid")
More information about the freebsd-bluetooth
mailing list