mpd 4.3 & freebsd 6.3 prerelease & 1000 int

Help
draga
2007-12-12
2013-03-27
  • draga
    draga
    2007-12-12

      Собрали тестовый стенд для проверки работы mpd4 c 1000 интерфейсами.
    Сервер:

    FreeBSD 6.3-PRERELEASE #2: Tue Dec 11 17:10:14 SAMT 2007
    Timecounter "i8254" frequency 1193182 Hz quality 0
    CPU: Intel(R) Pentium(R) 4 CPU 3.00GHz (3000.12-MHz 686-class CPU)
      Origin = "GenuineIntel"  Id = 0xf41  Stepping = 1
    Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
      Features2=0x641d<SSE3,RSVD2,MON,DS_CPL,CNXT-ID,CX16,xTPR>
      AMD Features=0x20100000<NX,LM>
      Logical CPUs per core: 2
    real memory  = 527368192 (502 MB)
    avail memory = 505544704 (482 MB)
    ACPI APIC Table: <PTLTD          APIC  >
    FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
    cpu0 (BSP): APIC ID:  0
    cpu1 (AP): APIC ID:  1

    sysctl:
      machdep.hyperthreading_allowed: 1

      mpd4 из портов mpd 4.3

    клиент практически идентичный.

    с клиента на сервер поднимается 1000 туннелей вида
    начиная с
    ng0: 172.40.0.1 --> 172.30.0.1
    до
    ng999: 172.43.151.1 --> 172.33.151.1

    172.4... - сторона сервера

    на клиенте запускается трафикогенерилка, отсылает на случайные адреса из диапазона 172.40...
    до 4000pps все работает железно, около 4.5к pps некоторые туннели начинают отваливаться по echo packet lost

    убираешь трафикогенерилку - восстанавливаются.
    запускаем снова на 5к pps, туннели отваливаются массово.
    убираем - поднимаются, но не все, остается порядка 1-3 туннелей, которые не могут переподцепиться.

    на стороне сервера в логах следующее:

    Dec 12 10:10:58 mpd mpd: [pptp265] Accepting PPTP connection
    Dec 12 10:10:58 mpd mpd: [p265] opening link "pptp265"...
    Dec 12 10:10:58 mpd mpd: [pptp265] link: OPEN event
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: Open event
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: state change Initial --> Starting
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: LayerStart
    Dec 12 10:10:58 mpd mpd: [pptp265] PPTP: attaching to peer's outgoing call
    Dec 12 10:10:58 mpd mpd: [pptp265] PPTP: can't attach pptpgre node: File exists
    Dec 12 10:10:58 mpd mpd: [pptp265] PPTP call cancelled in state CONNECTING
    Dec 12 10:10:58 mpd mpd: [pptp265] link: DOWN event
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: Close event
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: state change Starting --> Initial
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: LayerFinish
    Dec 12 10:10:58 mpd mpd: [pptp265] LCP: Down event

    куда копать?

     
    • Я подозреваю, что в системе закончились mbuf'ы, так как каждое соединение - это отдельный GRE сокет, в котором могут накапливаться пакеты. Из-за этого могли и соединения отпадать и при продолжительной нехватке при обрыве линка могли не удаляться ноды. Матюки в логах об этом должны быть весьма интенсивные.

      Из рекомендаций могу предложить выключить pptp windowing и увеличить период link keep-alive.
      Также можете поэкспериментировать с mpd5.0b4, масштабируемость должна быть заметно лучше, во всяком случае для PPPoE это ощущается сильно.

       
    • draga
      draga
      2007-12-12

      конфиг сервера:

      pptp-generic:
              set iface disable on-demand
              set iface disable proxy-arp
              set iface idle 0
              set iface enable tcpmssfix
              set bundle disable multilink
              set link yes acfcomp protocomp
              set link no pap chap
              set link enable chap
              set link keep-alive 10 60
              set link mtu 1460
              set pptp disable windowing
              set pptp disable delayed-ack
              set ipcp yes vjcomp
              set ipcp dns x.x.x.x

      в логах нет никакой ругани.

      # netstat -mn
      1687/5363/7050 mbufs in use (current/cache/total)
      1168/2432/3600/32768 mbuf clusters in use (current/cache/total/max)
      1168/2416 mbuf+clusters out of packet secondary zone in use (current/cache)
      0/0/0/0 4k (page size) jumbo clusters in use (current/cache/total/max)
      0/0/0/0 9k jumbo clusters in use (current/cache/total/max)
      0/0/0/0 16k jumbo clusters in use (current/cache/total/max)
      2757K/6204K/8962K bytes allocated to network (current/cache/total)
      0/0/0 requests for mbufs denied (mbufs/clusters/mbuf+clusters)
      0/0/0 requests for jumbo clusters denied (4k/9k/16k)
      0/5/16896 sfbufs in use (current/peak/max)
      0 requests for sfbufs denied
      0 requests for sfbufs delayed
      0 requests for I/O initiated by sendfile
      0 calls to protocol drain routines

      Насколько обоснован выбор mpd5 по сравнению с mpd4 в плане установки его в production?

       
      • > Насколько обоснован выбор mpd5 по сравнению с mpd4 в плане установки его в production?

        Работа над ним еще продолжается, потому он пока и бета. Но несколько нагруженных PPPoE серверов у меня под ним уже стоят. PPTP я у себя в produnction использую мало, так что тестировал меньше, но отзывы положительные есть. Как разработчику отзывы и багрепорты мне всегда приятны, ну а уж на чем ездить в production, каждый пусть решает сам.

         
      • > в логах нет никакой ругани.

        В логах mpd сообщение вида 'can't shutdown ...' вида не появлялось?
        Приведите лог по одному из тех линков, что залип.

         
        • draga
          draga
          2007-12-13

          Dec 13 09:19:41 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:19:42 mpd2 mpd: pptp873: connecting to 172.21.234.1 1723
          Dec 13 09:19:43 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:19:44 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:19:44 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:19:44 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:19:44 mpd2 mpd: [p873] IPCP: SendConfigReq #1
          Dec 13 09:19:45 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #1 (Req-Sent)
          Dec 13 09:19:45 mpd2 mpd: [p873] IPCP: SendConfigReq #2
          Dec 13 09:19:45 mpd2 mpd: [p873] IPCP: rec'd Configure Request #2 (Req-Sent)
          Dec 13 09:19:45 mpd2 mpd: [p873] IPCP: SendConfigAck #2
          Dec 13 09:19:45 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Sent
          Dec 13 09:19:46 mpd2 mpd: pptp873: connected to 172.21.234.1 1723
          Dec 13 09:19:46 mpd2 mpd: pptp873: attached to connection with 172.21.234.1 1723
          Dec 13 09:19:46 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #2 (Ack-Sent)
          Dec 13 09:19:46 mpd2 mpd: [p873] IPCP: state change Ack-Sent --> Opened
          Dec 13 09:19:46 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:19:46 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:19:48 mpd2 mpd: pptp873-0: outgoing call failed: res=admin prohib err=none
          Dec 13 09:19:48 mpd2 mpd: pptp873-0: killing channel
          Dec 13 09:19:48 mpd2 mpd: pptp873: closing connection with 172.21.234.1 1723
          Dec 13 09:19:49 mpd2 mpd: pptp873: killing connection with 172.21.234.1 1723
          Dec 13 09:19:51 mpd2 mpd: pptp873: connecting to 172.21.145.1 1723
          Dec 13 09:19:52 mpd2 mpd: pptp873: connected to 172.21.145.1 1723
          Dec 13 09:19:52 mpd2 mpd: pptp873: attached to connection with 172.21.145.1 1723
          Dec 13 09:19:53 mpd2 mpd: pptp873-0: outgoing call connected at 64000 bps
          Dec 13 09:23:01 mpd2 mpd: [pptp873] LCP: rec'd Terminate Request #4 (Opened)
          Dec 13 09:23:01 mpd2 mpd: [pptp873] LCP: state change Opened --> Stopping
          Dec 13 09:23:01 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 237 seconds, 348 octets in, 1309584 octets out
          Dec 13 09:23:01 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: SendTerminateReq #3
          Dec 13 09:23:01 mpd2 mpd: [p873] error writing len 8 frame to bypass: Network is down
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:23:01 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:23:01 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:23:01 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:23:01 mpd2 mpd: [p873] IPCP: state change Closing --> Initial
          Dec 13 09:23:01 mpd2 mpd: [p873] Last link has gone and no noretry option, will reopen in 4 seconds
          Dec 13 09:23:01 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:23:01 mpd2 mpd: [pptp873] LCP: SendTerminateAck #2
          Dec 13 09:23:01 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:23:03 mpd2 mpd: [pptp873] LCP: state change Stopping --> Stopped
          Dec 13 09:23:03 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:23:03 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:23:03 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:23:03 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:23:03 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:23:03 mpd2 mpd: [pptp873] LCP: state change Stopped --> Starting
          Dec 13 09:23:03 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:23:05 mpd2 mpd: [p873] Last link has gone and no noretry option, reopening in 3 seconds
          Dec 13 09:23:05 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:23:08 mpd2 mpd: [p873] opening link "pptp873"...
          Dec 13 09:23:13 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:23:13 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:23:13 mpd2 mpd: [pptp873] LCP: state change Starting --> Initial
          Dec 13 09:23:13 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:23:13 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:23:13 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:23:14 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:23:14 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:23:14 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: state change Initial --> Closed
          Dec 13 09:23:14 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: state change Closed --> Req-Sent
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: SendConfigReq #3
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #3 (Req-Sent)
          Dec 13 09:23:14 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:23:15 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:23:15 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:23:15 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:23:15 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:23:15 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Starting
          Dec 13 09:23:15 mpd2 mpd: [pptp873] pausing 6 seconds before open
          Dec 13 09:23:21 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:23:21 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:23:21 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:23:21 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:23:21 mpd2 mpd: [pptp873] LCP: state change Starting --> Req-Sent
          Dec 13 09:23:21 mpd2 mpd: [pptp873] LCP: SendConfigReq #4
          Dec 13 09:23:22 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #4 (Req-Sent)
          Dec 13 09:23:22 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Req-Sent
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: SendConfigReq #5
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #5 (Req-Sent)
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #8 (Ack-Rcvd)
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: SendConfigAck #8
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Opened
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: auth: peer wants CHAP, I want nothing
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: LayerUp
          Dec 13 09:23:24 mpd2 mpd: [pptp873] CHAP: rec'd CHALLENGE #1
          Dec 13 09:23:24 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:23:24 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:23:24 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:23:24 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: SendConfigReq #4
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: rec'd Configure Request #4 (Req-Sent)
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: SendConfigAck #4
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Sent
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #4 (Ack-Sent)
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: SendConfigReq #5
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #5 (Ack-Sent)
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: state change Ack-Sent --> Opened
          Dec 13 09:23:24 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:23:24 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:25:54 mpd2 mpd: [pptp873] LCP: no reply to 1 echo request(s)
          Dec 13 09:26:04 mpd2 mpd: [pptp873] LCP: no reply to 2 echo request(s)
          Dec 13 09:26:05 mpd2 mpd: pptp873: read: Connection reset by peer
          Dec 13 09:26:05 mpd2 mpd: pptp873: killing connection with 172.21.145.1 1723
          Dec 13 09:26:05 mpd2 mpd: pptp873-0: killing channel
          Dec 13 09:26:13 mpd2 mpd: pptp873: connecting to 172.21.202.1 1723
          Dec 13 09:26:13 mpd2 mpd: pptp873: connected to 172.21.202.1 1723
          Dec 13 09:26:13 mpd2 mpd: pptp873: attached to connection with 172.21.202.1 1723
          Dec 13 09:26:13 mpd2 mpd: pptp873-0: outgoing call connected at 64000 bps
          Dec 13 09:26:14 mpd2 mpd: [pptp873] LCP: no reply to 3 echo request(s)
          Dec 13 09:33:46 mpd2 mpd: [pptp873] LCP: no reply to 1 echo request(s)
          Dec 13 09:34:17 mpd2 mpd: [pptp873] LCP: no reply to 1 echo request(s)
          Dec 13 09:34:27 mpd2 mpd: [pptp873] LCP: no reply to 2 echo request(s)
          Dec 13 09:34:37 mpd2 mpd: [pptp873] LCP: no reply to 3 echo request(s)
          Dec 13 09:35:07 mpd2 mpd: [pptp873] LCP: no reply to 1 echo request(s)
          Dec 13 09:38:47 mpd2 mpd: [p873] IFACE: Close event
          Dec 13 09:38:47 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:38:47 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:38:47 mpd2 mpd: [p873] IPCP: SendTerminateReq #6
          Dec 13 09:38:47 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:38:47 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:38:48 mpd2 mpd: [p873] IPCP: rec'd Terminate Ack #5 (Closing)
          Dec 13 09:38:48 mpd2 mpd: [p873] IPCP: state change Closing --> Closed
          Dec 13 09:38:48 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:38:48 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:38:48 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:38:52 mpd2 mpd: [pptp873] LCP: rec'd Terminate Request #9 (Opened)
          Dec 13 09:38:52 mpd2 mpd: [pptp873] LCP: state change Opened --> Stopping
          Dec 13 09:38:52 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 938 seconds, 804 octets in, 4328614 octets out
          Dec 13 09:38:52 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:38:52 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:38:52 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:38:52 mpd2 mpd: [p873] IPCP: state change Closed --> Initial
          Dec 13 09:38:52 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:38:52 mpd2 mpd: [pptp873] LCP: SendTerminateAck #6
          Dec 13 09:38:52 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:38:53 mpd2 mpd: pptp873: got StopCtrlConnRequest: reason=local shutdown
          Dec 13 09:38:53 mpd2 mpd: pptp873: killing connection with 172.21.202.1 1723
          Dec 13 09:38:53 mpd2 mpd: pptp873-0: killing channel
          Dec 13 09:38:54 mpd2 mpd: [pptp873] LCP: state change Stopping --> Stopped
          Dec 13 09:38:54 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:38:54 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:38:54 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:38:54 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:38:54 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:38:54 mpd2 mpd: [pptp873] LCP: state change Stopped --> Starting
          Dec 13 09:38:54 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:38:56 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:38:56 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:38:56 mpd2 mpd: [pptp873] LCP: state change Starting --> Initial
          Dec 13 09:38:56 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:39:02 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:39:02 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:39:02 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:39:02 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:39:02 mpd2 mpd: [pptp873] LCP: state change Initial --> Closed
          Dec 13 09:39:04 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #21 (Closed)
          Dec 13 09:39:04 mpd2 mpd: [pptp873] LCP: SendTerminateAck #7
          Dec 13 09:39:05 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:39:05 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:39:05 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:39:05 mpd2 mpd: [pptp873] LCP: state change Closed --> Initial
          Dec 13 09:39:16 mpd2 mpd: [p873] using interface ng873
          Dec 13 09:39:18 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:39:18 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:39:18 mpd2 mpd: [pptp873] LCP: state change Initial --> Starting
          Dec 13 09:39:18 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:39:53 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:39:53 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:39:53 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:39:53 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:39:53 mpd2 mpd: [pptp873] LCP: state change Starting --> Req-Sent
          Dec 13 09:39:53 mpd2 mpd: [pptp873] LCP: SendConfigReq #1
          Dec 13 09:39:53 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #1 (Req-Sent)
          Dec 13 09:39:53 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:39:55 mpd2 mpd: pptp873: connecting to 172.23.167.1 1723
          Dec 13 09:39:55 mpd2 mpd: pptp873: connected to 172.23.167.1 1723
          Dec 13 09:39:55 mpd2 mpd: pptp873: attached to connection with 172.23.167.1 1723
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Req-Sent
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: SendConfigReq #2
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #13 (Req-Sent)
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: SendConfigAck #13
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Sent
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #2 (Ack-Sent)
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: state change Ack-Sent --> Opened
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: auth: peer wants CHAP, I want nothing
          Dec 13 09:39:55 mpd2 mpd: [pptp873] LCP: LayerUp
          Dec 13 09:39:55 mpd2 mpd: [pptp873] CHAP: rec'd CHALLENGE #1
          Dec 13 09:39:55 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:39:56 mpd2 mpd: pptp873-0: outgoing call connected at 64000 bps
          Dec 13 09:39:56 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:39:56 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:39:56 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: SendConfigReq #1
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #1 (Req-Sent)
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: SendConfigReq #2
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #2 (Req-Sent)
          Dec 13 09:39:56 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:39:58 mpd2 mpd: [p873] IPCP: rec'd Configure Request #10 (Ack-Rcvd)
          Dec 13 09:39:58 mpd2 mpd: [p873] IPCP: SendConfigAck #10
          Dec 13 09:39:58 mpd2 mpd: [p873] IPCP: state change Ack-Rcvd --> Opened
          Dec 13 09:39:58 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:39:58 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:48:30 mpd2 mpd: [pptp873] LCP: no reply to 1 echo request(s)
          Dec 13 09:48:40 mpd2 mpd: [pptp873] LCP: no reply to 2 echo request(s)
          Dec 13 09:48:50 mpd2 mpd: [pptp873] LCP: no reply to 3 echo request(s)
          Dec 13 09:49:26 mpd2 mpd: [pptp873] LCP: rec'd Terminate Request #14 (Opened)
          Dec 13 09:49:26 mpd2 mpd: [pptp873] LCP: state change Opened --> Stopping
          Dec 13 09:49:26 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 608 seconds, 648 octets in, 810570 octets out
          Dec 13 09:49:26 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: SendTerminateReq #3
          Dec 13 09:49:26 mpd2 mpd: [p873] error writing len 8 frame to bypass: Network is down
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:49:26 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:49:26 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:49:26 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:49:26 mpd2 mpd: [p873] IPCP: state change Closing --> Initial
          Dec 13 09:49:26 mpd2 mpd: [p873] Last link has gone and no noretry option, will reopen in 4 seconds
          Dec 13 09:49:26 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:49:26 mpd2 mpd: [pptp873] LCP: SendTerminateAck #3
          Dec 13 09:49:26 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:49:28 mpd2 mpd: [pptp873] LCP: rec'd Terminate Request #15 (Stopping)
          Dec 13 09:49:28 mpd2 mpd: [pptp873] LCP: SendTerminateAck #4
          Dec 13 09:49:28 mpd2 mpd: [pptp873] LCP: state change Stopping --> Stopped
          Dec 13 09:49:28 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:49:30 mpd2 mpd: [p873] Last link has gone and no noretry option, reopening in 3 seconds
          Dec 13 09:49:30 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:49:30 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:49:30 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:49:30 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:49:30 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:49:30 mpd2 mpd: [pptp873] LCP: state change Stopped --> Starting
          Dec 13 09:49:30 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:49:33 mpd2 mpd: [p873] opening link "pptp873"...
          Dec 13 09:49:56 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:49:56 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:49:56 mpd2 mpd: [pptp873] LCP: state change Starting --> Initial
          Dec 13 09:49:56 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:50:04 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:50:04 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:50:04 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:50:04 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:50:04 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:50:04 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:50:04 mpd2 mpd: [pptp873] LCP: state change Initial --> Closed
          Dec 13 09:50:06 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #13 (Closed)
          Dec 13 09:50:06 mpd2 mpd: [pptp873] LCP: SendTerminateAck #5
          Dec 13 09:50:08 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #14 (Closed)
          Dec 13 09:50:08 mpd2 mpd: [pptp873] LCP: SendTerminateAck #6
          Dec 13 09:50:10 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #15 (Closed)
          Dec 13 09:50:10 mpd2 mpd: [pptp873] LCP: SendTerminateAck #7
          Dec 13 09:50:11 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: state change Closed --> Req-Sent
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: SendConfigReq #8
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #8 (Req-Sent)
          Dec 13 09:50:11 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:50:12 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #16 (Ack-Rcvd)
          Dec 13 09:50:12 mpd2 mpd: [pptp873] LCP: SendConfigAck #16
          Dec 13 09:50:12 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Opened
          Dec 13 09:50:12 mpd2 mpd: [pptp873] LCP: auth: peer wants CHAP, I want nothing
          Dec 13 09:50:12 mpd2 mpd: [pptp873] LCP: LayerUp
          Dec 13 09:50:13 mpd2 mpd: [pptp873] CHAP: rec'd CHALLENGE #1
          Dec 13 09:50:13 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:50:13 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:50:13 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:50:13 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: SendConfigReq #4
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #4 (Req-Sent)
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: SendConfigReq #5
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #5 (Req-Sent)
          Dec 13 09:50:13 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:50:15 mpd2 mpd: [p873] IPCP: rec'd Configure Request #10 (Ack-Rcvd)
          Dec 13 09:50:15 mpd2 mpd: [p873] IPCP: SendConfigAck #10
          Dec 13 09:50:15 mpd2 mpd: [p873] IPCP: state change Ack-Rcvd --> Opened
          Dec 13 09:50:15 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:50:15 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:50:42 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:50:42 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:50:42 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:50:42 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:50:42 mpd2 mpd: [pptp873] LCP: state change Opened --> Starting
          Dec 13 09:50:42 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 31 seconds, 285 octets in, 217308 octets out
          Dec 13 09:50:42 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: SendTerminateReq #6
          Dec 13 09:50:42 mpd2 mpd: [p873] error writing len 8 frame to bypass: Network is down
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:50:42 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:50:42 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:50:42 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:50:42 mpd2 mpd: [p873] IPCP: state change Closing --> Initial
          Dec 13 09:50:42 mpd2 mpd: [p873] Last link has gone and no noretry option, will reopen in 3 seconds
          Dec 13 09:50:42 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:50:42 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:50:45 mpd2 mpd: [p873] Last link has gone and no noretry option, reopening in 3 seconds
          Dec 13 09:50:45 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:50:49 mpd2 mpd: [p873] opening link "pptp873"...
          Dec 13 09:50:57 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:50:57 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:50:57 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:50:57 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:50:57 mpd2 mpd: [pptp873] LCP: state change Starting --> Req-Sent
          Dec 13 09:50:57 mpd2 mpd: [pptp873] LCP: SendConfigReq #9
          Dec 13 09:50:57 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #9 (Req-Sent)
          Dec 13 09:50:57 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #17 (Ack-Rcvd)
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: SendConfigAck #17
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Opened
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: auth: peer wants CHAP, I want nothing
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: LayerUp
          Dec 13 09:50:59 mpd2 mpd: [pptp873] CHAP: rec'd CHALLENGE #1
          Dec 13 09:50:59 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:50:59 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:50:59 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:50:59 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: SendConfigReq #7
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #7 (Req-Sent)
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: SendConfigReq #8
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #8 (Req-Sent)
          Dec 13 09:50:59 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:51:01 mpd2 mpd: [p873] IPCP: rec'd Configure Request #14 (Ack-Rcvd)
          Dec 13 09:51:01 mpd2 mpd: [p873] IPCP: SendConfigAck #14
          Dec 13 09:51:01 mpd2 mpd: [p873] IPCP: state change Ack-Rcvd --> Opened
          Dec 13 09:51:01 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:51:01 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:51:29 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: state change Opened --> Closing
          Dec 13 09:51:29 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 78 seconds, 204 octets in, 251084 octets out
          Dec 13 09:51:29 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: SendTerminateReq #9
          Dec 13 09:51:29 mpd2 mpd: [p873] error writing len 8 frame to bypass: Network is down
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:51:29 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:51:29 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:51:29 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:51:29 mpd2 mpd: [p873] IPCP: state change Closing --> Initial
          Dec 13 09:51:29 mpd2 mpd: [p873] Last link has gone and no noretry option, will reopen in 3 seconds
          Dec 13 09:51:29 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: SendTerminateReq #10
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:51:29 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:51:29 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: Oops, UP at Closing
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: rec'd Terminate Ack #18 (Closing)
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: state change Closing --> Closed
          Dec 13 09:51:29 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:51:32 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:51:32 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:51:32 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:51:32 mpd2 mpd: [pptp873] LCP: state change Closed --> Initial
          Dec 13 09:51:33 mpd2 mpd: [p873] Last link has gone and no noretry option, reopening in 3 seconds
          Dec 13 09:51:34 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:51:34 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:51:36 mpd2 mpd: [p873] opening link "pptp873"...
          Dec 13 09:51:37 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:51:37 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:51:37 mpd2 mpd: [pptp873] LCP: state change Initial --> Starting
          Dec 13 09:51:37 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:52:26 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:52:26 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:52:26 mpd2 mpd: [pptp873] LCP: state change Starting --> Initial
          Dec 13 09:52:26 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:52:32 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:52:32 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:52:32 mpd2 mpd: [pptp873] LCP: state change Initial --> Starting
          Dec 13 09:52:32 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:52:37 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:52:37 mpd2 mpd: [pptp873] link: UP event
          Dec 13 09:52:37 mpd2 mpd: [pptp873] link: origination is local
          Dec 13 09:52:37 mpd2 mpd: [pptp873] LCP: Up event
          Dec 13 09:52:37 mpd2 mpd: [pptp873] LCP: state change Starting --> Req-Sent
          Dec 13 09:52:37 mpd2 mpd: [pptp873] LCP: SendConfigReq #11
          Dec 13 09:52:37 mpd2 mpd: [pptp873] LCP: rec'd Configure Ack #11 (Req-Sent)
          Dec 13 09:52:37 mpd2 mpd: [pptp873] LCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: rec'd Configure Request #44 (Ack-Rcvd)
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: SendConfigAck #44
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: state change Ack-Rcvd --> Opened
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: auth: peer wants CHAP, I want nothing
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: LayerUp
          Dec 13 09:52:39 mpd2 mpd: [pptp873] CHAP: rec'd CHALLENGE #1
          Dec 13 09:52:39 mpd2 mpd: [pptp873] CHAP: sending RESPONSE len:57
          Dec 13 09:52:39 mpd2 mpd: [pptp873] CHAP: rec'd SUCCESS #1
          Dec 13 09:52:39 mpd2 mpd: [pptp873] LCP: authorization successful
          Dec 13 09:52:39 mpd2 mpd: [p873] Bundle up: 1 link, total bandwidth 64000 bps
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: Open event
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: state change Initial --> Starting
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: LayerStart
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: Up event
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: state change Starting --> Req-Sent
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: SendConfigReq #10
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: rec'd Configure Nak #10 (Req-Sent)
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: SendConfigReq #11
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: rec'd Configure Ack #11 (Req-Sent)
          Dec 13 09:52:39 mpd2 mpd: [p873] IPCP: state change Req-Sent --> Ack-Rcvd
          Dec 13 09:52:41 mpd2 mpd: [p873] IPCP: rec'd Configure Request #22 (Ack-Rcvd)
          Dec 13 09:52:41 mpd2 mpd: [p873] IPCP: SendConfigAck #22
          Dec 13 09:52:41 mpd2 mpd: [p873] IPCP: state change Ack-Rcvd --> Opened
          Dec 13 09:52:41 mpd2 mpd: [p873] IPCP: LayerUp
          Dec 13 09:52:41 mpd2 mpd: [p873] IFACE: Up event
          Dec 13 09:53:35 mpd2 mpd: [pptp873] PPTP call terminated
          Dec 13 09:53:35 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:53:35 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:53:35 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:53:35 mpd2 mpd: [pptp873] LCP: state change Opened --> Starting
          Dec 13 09:53:35 mpd2 mpd: [pptp873] AUTH: Accounting data for user : 63 seconds, 216 octets in, 443508 octets out
          Dec 13 09:53:35 mpd2 mpd: [p873] Bundle up: 0 links, total bandwidth 9600 bps
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: Close event
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: state change Opened --> Closing
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: SendTerminateReq #12
          Dec 13 09:53:35 mpd2 mpd: [p873] error writing len 8 frame to bypass: Network is down
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: LayerDown
          Dec 13 09:53:35 mpd2 mpd: [p873] IFACE: Down event
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: Down event
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: LayerFinish
          Dec 13 09:53:35 mpd2 mpd: [p873] No NCPs left. Closing links...
          Dec 13 09:53:35 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:53:35 mpd2 mpd: [p873] IPCP: state change Closing --> Initial
          Dec 13 09:53:35 mpd2 mpd: [p873] Last link has gone and no noretry option, will reopen in 3 seconds
          Dec 13 09:53:35 mpd2 mpd: [pptp873] AUTH: Cleanup
          Dec 13 09:53:35 mpd2 mpd: [pptp873] LCP: LayerDown
          Dec 13 09:53:38 mpd2 mpd: [p873] Last link has gone and no noretry option, reopening in 3 seconds
          Dec 13 09:53:38 mpd2 mpd: [p873] closing link "pptp873"...
          Dec 13 09:53:41 mpd2 mpd: [p873] opening link "pptp873"...
          Dec 13 09:53:43 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:53:43 mpd2 mpd: [pptp873] PPTP: can't attach pptpgre node: File exists
          Dec 13 09:53:44 mpd2 mpd: [pptp873] PPTP call failed
          Dec 13 09:53:44 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:53:44 mpd2 mpd: [pptp873] link: reconnection attempt 2
          Dec 13 09:53:44 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:54:41 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:54:41 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:54:41 mpd2 mpd: [pptp873] LCP: state change Starting --> Initial
          Dec 13 09:54:41 mpd2 mpd: [pptp873] LCP: LayerFinish
          Dec 13 09:54:41 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:54:41 mpd2 mpd: [pptp873] PPTP: can't attach pptpgre node: File exists
          Dec 13 09:54:41 mpd2 mpd: [pptp873] PPTP call failed
          Dec 13 09:54:41 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:54:41 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:54:42 mpd2 mpd: [pptp873] link: CLOSE event
          Dec 13 09:54:42 mpd2 mpd: [pptp873] LCP: Close event
          Dec 13 09:54:43 mpd2 mpd: [pptp873] link: OPEN event
          Dec 13 09:54:43 mpd2 mpd: [pptp873] LCP: Open event
          Dec 13 09:54:43 mpd2 mpd: [pptp873] LCP: state change Initial --> Starting
          Dec 13 09:54:43 mpd2 mpd: [pptp873] LCP: LayerStart
          Dec 13 09:54:43 mpd2 mpd: [pptp873] pausing 3 seconds before open
          Dec 13 09:55:04 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:55:04 mpd2 mpd: [pptp873] PPTP: can't attach pptpgre node: File exists
          Dec 13 09:55:04 mpd2 mpd: [pptp873] PPTP call failed
          Dec 13 09:55:04 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:55:04 mpd2 mpd: [pptp873] link: reconnection attempt 1
          Dec 13 09:55:04 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:55:08 mpd2 mpd: [pptp873] pausing 1 seconds before open
          Dec 13 09:55:25 mpd2 mpd: [pptp873] PPTP call successful
          Dec 13 09:55:25 mpd2 mpd: [pptp873] PPTP: can't attach pptpgre node: File exists
          Dec 13 09:55:25 mpd2 mpd: [pptp873] PPTP call failed
          Dec 13 09:55:25 mpd2 mpd: [pptp873] link: DOWN event
          Dec 13 09:55:25 mpd2 mpd: [pptp873] link: reconnection attempt 2
          Dec 13 09:55:25 mpd2 mpd: [pptp873] LCP: Down event
          Dec 13 09:55:27 mpd2 mpd: [pptp873] pausing 3 seconds before open

           
        • draga
          draga
          2007-12-13

          со стороны клиента в логах появилась следующая ругань:

          Dec 13 09:36:02 mpd2 kernel: failed in ng_con_nodes(): 12
          Dec 13 09:53:16 mpd2 kernel: failed in ng_con_nodes(): 12
          Dec 13 09:53:36 mpd2 kernel: failed in ng_con_nodes(): 12

          а со стороны сервера была такая в момент массовых подключений:

          Dec 12 15:59:09 mpd kernel: Limiting closed port RST response from 204 to 200 packets/sec
          Dec 12 16:36:32 mpd kernel: Limiting closed port RST response from 288 to 200 packets/sec
          Dec 12 16:36:34 mpd kernel: Limiting closed port RST response from 202 to 200 packets/sec
          Dec 12 16:36:35 mpd kernel: Limiting closed port RST response from 218 to 200 packets/sec

           
          • > Dec 13 09:36:02 mpd2 kernel: failed in ng_con_nodes(): 12

            12 - это ENOMEM (Cannot allocate memory). Видимо от избытка чувств net.graph.maxalloc исчерпались. Где возможно, эти ошибки обрабатываются, но в принципе это может быть причиной залипаний. В логах mpd ничего подозрительного небыло по залипшим линкам?

             
        • draga
          draga
          2007-12-13

          >В логах mpd сообщение вида 'can't shutdown ...' вида не появлялось?

          такой надписи в логах нет..

           
    • Кроме того, случай с 1000 соединений между двумя машинами не совсем аналогичен случаю соединений одной машины с тысячей. Как мне кажется, эта ситуация для PTPP сейчас реализована не самым эффективным способом.

       
    • draga
      draga
      2007-12-12

      дальнейшее тестирование:

      подняли 1000 туннелей, опустили сервака, туннели попадали
      сервак подняли
      туннели опять почти все поднялись, кроме некоторых
      на оставшихся следующая картина

      логи со стороны клиента:

      [pptp552] PPTP call successful
      [pptp552] PPTP: can't attach pptpgre node: File exists
      [pptp552] PPTP call failed
      [pptp552] link: DOWN event

      одновременно:
      интерфейс ng552 в дауне

      # ngctl list | grep 552
        Name: mpd2212-p552    Type: ppp             ID: 00036104   Num hooks: 2
        Name: ng552           Type: iface           ID: 00036103   Num hooks: 0
        Name: mpd2212-p552-so Type: socket          ID: 00036102   Num hooks: 1

       
      • То что некоторые соединения не потушились корректно я еще буду смотреть.

        В плане же производительности я не советую вам ориентироваться на случай 1000 соединений между двумя IP.
        Текущая реализация PPTP в ng_pptp изначально плохо продумана и в этом конкретном случае работает
        крайне неэффективно. Сейчас для каждого соединения внутри тунеля открывается отдельный GRE сокет,
        который по своей природе ничего про PPTP не знает и может фильтровать трафик только по src/dst адресам.
        Как следствие, каждый входящий пакет попадает в сокеты всех соединений, создавая значительную бесполезную
        нагрузку и потребляя море буферов. L2TP реализован иначе и этой проблемы не имеет.

        Для более адекватного теста поднимите на одном из хостов пару десятков IP и разбросайте соединения между ними равномерно, я думаю результаты теста существенно изменятся.

         
        • draga
          draga
          2007-12-13

          >>Для более адекватного теста поднимите на одном из хостов пару десятков IP и разбросайте соединения между ними равномерно, я думаю результаты теста существенно изменятся.

          Собственно так и сделано.

          mpd.links со стороны клиента:

          ...
          pptp996:
                  set link type pptp
                  set pptp peer 172.23.228.1
                  set pptp self 172.23.228.2
                  set pptp enable originate outcall
          pptp997:
                  set link type pptp
                  set pptp peer 172.23.229.1
                  set pptp self 172.23.229.2
                  set pptp enable originate outcall
          pptp998:
                  set link type pptp
                  set pptp peer 172.23.230.1
                  set pptp self 172.23.230.2
                  set pptp enable originate outcall
          ...