MPD Just Stopped Working?
Crist J. Clark
cristclark at comcast.net
Sun May 16 22:09:48 UTC 2010
I'm running mpd5 on 7.2-RELEASE-p5. I just use it to tunnel from
a Windows XP machine to the MPD server over an insecure (wireless)
network. It "just stopped working" Friday. The MPD configuration
hasn't been touched. As far as I know, nothing on the Windows
box has changed.
I'd suspect something stealthily changed on the Windoze box
by Windows Update or the AV (Norton) software, but the more I
look at the problem, it looks like the MPD side. The connection
comes up, I see the two machines talk over the network with
the XP machine the last to talk to the MPD side. Then the MPD
side seems to try to figure some things out with itself for a
few seconds before failing and closing down the connection.
Here's what a packet capture looks like,
14:48:12.322112 IP 192.168.128.253.2255 > 192.168.128.254.1723: S 2131756225:2131756225(0) win 16384 <mss 1260,nop,nop,sackOK>
14:48:12.322310 IP 192.168.128.254.1723 > 192.168.128.253.2255: S 4093488321:4093488321(0) ack 2131756226 win 65535 <mss 1260,sackOK,eol>
14:48:12.325435 IP 192.168.128.253.2255 > 192.168.128.254.1723: P 1:157(156) ack 1 win 17640: pptp CTRL_MSGTYPE=SCCRQ PROTO_VER(1.0) FRAME_CAP(A) BEARER_CAP(A) MAX_CHAN(0) FIRM_REV(2600) [|pptp]
14:48:12.326120 IP 192.168.128.254.1723 > 192.168.128.253.2255: P 1:157(156) ack 157 win 65535: pptp CTRL_MSGTYPE=SCCRP PROTO_VER(1.0) RESULT_CODE(1) ERR_CODE(0) FRAME_CAP(AS) BEARER_CAP(DA) MAX_CHAN(0) FIRM_REV(257) [|pptp]
14:48:12.326863 IP 192.168.128.253.2255 > 192.168.128.254.1723: P 157:325(168) ack 157 win 17484: pptp CTRL_MSGTYPE=OCRQ CALL_ID(49152) CALL_SER_NUM(62587) MIN_BPS(300) MAX_BPS(100000000) BEARER_TYPE(Any) FRAME_TYPE(E) RECV_WIN(64) PROC_DELAY(0) PHONE_NO_LEN(0) [|pptp]
14:48:12.329535 IP 192.168.128.254.1723 > 192.168.128.253.2255: P 157:189(32) ack 325 win 65535: pptp CTRL_MSGTYPE=OCRP CALL_ID(64971) PEER_CALL_ID(49152) RESULT_CODE(1) ERR_CODE(0) CAUSE_CODE(0) CONN_SPEED(64000) RECV_WIN(16) PROC_DELAY(1) PHY_CHAN_ID(0)
14:48:12.337938 IP 192.168.128.253.2255 > 192.168.128.254.1723: P 325:349(24) ack 189 win 17452: pptp CTRL_MSGTYPE=SLI PEER_CALL_ID(64971) SEND_ACCM(0xffffffff) RECV_ACCM(0xffffffff)
14:48:12.437639 IP 192.168.128.254.1723 > 192.168.128.253.2255: . ack 349 win 65535
14:48:29.343757 IP 192.168.128.254.1723 > 192.168.128.253.2255: P 189:337(148) ack 349 win 65535: pptp CTRL_MSGTYPE=CDN CALL_ID(64971) RESULT_CODE(3) ERR_CODE(0) CAUSE_CODE(0) [|pptp]
14:48:29.345175 IP 192.168.128.253.2255 > 192.168.128.254.1723: P 349:365(16) ack 337 win 17304: pptp CTRL_MSGTYPE=StopCCRQ REASON(1)
14:48:29.345629 IP 192.168.128.254.1723 > 192.168.128.253.2255: P 337:353(16) ack 365 win 65535: pptp CTRL_MSGTYPE=StopCCRP RESULT_CODE(1) ERR_CODE(0)
14:48:29.345763 IP 192.168.128.254.1723 > 192.168.128.253.2255: F 353:353(0) ack 365 win 65535
14:48:29.346531 IP 192.168.128.253.2255 > 192.168.128.254.1723: F 365:365(0) ack 354 win 17288
14:48:29.346637 IP 192.168.128.254.1723 > 192.168.128.253.2255: . ack 366 win 65534
And here is are the logs from MPD that correspond to this connection.
Note all of the MPD activity between the hole in the packet capture
from 14:48:12 to 14:48:29. It seems the server is having problems
negotiating with itself?
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] Link: OPEN event
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: Open event
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: state change Initial --> Starting
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: LayerStart
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] PPTP: attaching to peer's outgoing call
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] Link: UP event
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] Link: origination is remote
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: Up event
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: state change Starting --> Req-Sent
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #1
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #0 (Req-Sent)
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigRej #0
May 16 14:48:12 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #2
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #1 (Req-Sent)
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigRej #1
May 16 14:48:14 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #3
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:16 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #2 (Req-Sent)
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigRej #2
May 16 14:48:17 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #4
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:18 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #5
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:20 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #3 (Req-Sent)
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigRej #3
May 16 14:48:21 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #6
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:22 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #7
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:24 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #4 (Req-Sent)
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigRej #4
May 16 14:48:25 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #8
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:26 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] LCP: SendConfigReq #9
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] MRU 1500
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5ae3249c
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] AUTHPROTO CHAP MSOFTv2
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] MP MRRU 2048
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] MP SHORTSEQ
May 16 14:48:28 <daemon.info> net5501 mpd: [L-1] ENDPOINTDISC [802.1] 00 00 24 ca 91 b4
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: rec'd Configure Request #5 (Req-Sent)
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] MRU 1400
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] MAGICNUM 5e8514f4
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] PROTOCOMP
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] ACFCOMP
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] CALLBACK 6
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: not converging
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: parameter negotiation failed
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: state change Req-Sent --> Stopped
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: LayerFinish
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] PPTP call terminated
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] Link: DOWN event
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: Close event
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: state change Stopped --> Closed
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: Down event
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] LCP: state change Closed --> Initial
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] Link: SHUTDOWN event
May 16 14:48:29 <daemon.info> net5501 mpd: [L-1] Link: Shutdown
--
Crist J. Clark | cjclark at alum.mit.edu
More information about the freebsd-net
mailing list