Bug with pts assigned/cleared

[maxnod]

With lot of failed connexion (for ex due to MD5 which is not supported in server side) with xl2tpd 1.3.17
In our case with 3700 failed login attempt we've got :
15 call_close: Descheduling event
Ex of log
Jan 6 04:42:04 s24 xl2tpd[32395]: handle_control: control ZLB received
Jan 6 04:42:05 s24 xl2tpd[32395]: control_finish: Connection closed to 130.93.54.137, serial 0 ()
Jan 6 04:42:05 s24 xl2tpd[32395]: control_zlb: sending control ZLB on tunnel 65260
Jan 6 04:42:05 s24 xl2tpd[32395]: close needclose
Jan 6 04:42:05 s24 xl2tpd[32395]: call_close: Descheduling event
All ppd (82) went down after Descheduling event
After all ppp ccustomer can reconnect.

We expected :
No master tunnel reset... no blocking pts due to existent and functional pppd pid

We thought that there is an error in freeing pts number or registered pts number

Ex of a blocking one :

Jan 6 04:43:23 s24 xl2tpd[32395]: Call established with 130.93.54.137, PID: 22720, Local: 48258, Remote: 7748, Serial: 0
Jan 6 04:43:23 s24 pppd[22720]: Plugin radius.so loaded.
Jan 6 04:43:23 s24 pppd[22720]: RADIUS plugin initialized.
Jan 6 04:43:23 s24 pppd[22720]: pppd 2.4.7 started by root, uid 0
Jan 6 04:43:23 s24 pppd[22720]: Removed stale lock on pts_19 (pid 19968)
Jan 6 04:43:23 s24 pppd[22720]: using channel 513319
Jan 6 04:43:23 s24 pppd[22720]: Using interface ppp19
Jan 6 04:43:23 s24 pppd[22720]: Connect: ppp19 <--> /dev/pts/19
.......
Jan 6 04:43:27 s24 pppd[22720]: found interface vlan43 for proxy arp
Jan 6 04:43:27 s24 pppd[22720]: local IP address x.x.x.x
Jan 6 04:43:27 s24 pppd[22720]: remote IP address x.x.x.x
Jan 6 04:43:27 s24 pppd[22720]: Script /etc/ppp/ip-up started (pid 23291)
Jan 6 04:43:27 s24 pppd[22720]: Script /etc/ppp/ip-up finished (pid 23291), status = 0x0
....
Jan 6 04:43:28 s24 xl2tpd[32395]: check_control: control, cid = 0, Ns = 78, Nr = 39
Jan 6 04:43:28 s24 xl2tpd[32395]: ourcid = 14323, entropy_buf = 37f3
Jan 6 04:43:28 s24 xl2tpd[32395]: trying to send control packet to 56363
Jan 6 04:43:28 s24 xl2tpd[32395]: control_xmit: Scheduling and transmitting packet 39
Jan 6 04:43:28 s24 xl2tpd[32395]: control_zlb: sending control ZLB on tunnel 27573
Jan 6 04:43:29 s24 xl2tpd[32395]: check_control: control, cid = 6635, Ns = 79, Nr = 40
Jan 6 04:43:29 s24 xl2tpd[32395]: start_pppd: I'm running:
Jan 6 04:43:29 s24 xl2tpd[32395]: "/usr/sbin/pppd"
Jan 6 04:43:29 s24 xl2tpd[32395]: "/dev/pts/38"
Jan 6 04:43:29 s24 xl2tpd[32395]: "passive"
Jan 6 04:43:29 s24 xl2tpd[32395]: "nodetach"
Jan 6 04:43:29 s24 xl2tpd[32395]: "5.182.136.2:192.168.0.39"
Jan 6 04:43:29 s24 xl2tpd[32395]: "file"
Jan 6 04:43:29 s24 xl2tpd[32395]: "/etc/ppp/options.l2tpd.lns"
Jan 6 04:43:29 s24 xl2tpd[32395]: Call established with 130.93.54.137, PID: 23775, Local: 14323, Remote: 6635, Serial: 0
Jan 6 04:43:29 s24 xl2tpd[32395]: control_zlb: sending control ZLB on tunnel 27573
Jan 6 04:43:29 s24 pppd[23775]: Plugin radius.so loaded.
Jan 6 04:43:29 s24 pppd[23775]: RADIUS plugin initialized.
Jan 6 04:43:29 s24 pppd[23775]: pppd 2.4.7 started by root, uid 0
Jan 6 04:43:29 s24 pppd[23775]: Removed stale lock on pts_38 (pid 21188)
Jan 6 04:43:29 s24 pppd[23775]: using channel 513338
Jan 6 04:43:29 s24 pppd[23775]: Using interface ppp38
Jan 6 04:43:29 s24 pppd[23775]: Connect: ppp38 <--> /dev/pts/38
Jan 6 04:43:29 s24 pppd[23775]: sent [LCP ConfReq id=0x1 <mru 1456> <asyncmap 0x0> <magic 0x71049b38> ]
Jan 6 04:43:31 s24 pppd[23775]: rcvd [LCP ConfReq id=0xd <magic 0x49c21cd4>]
Jan 6 04:43:31 s24 pppd[23775]: sent [LCP ConfAck id=0xd <magic 0x49c21cd4>]
Jan 6 04:43:31 s24 pppd[23775]: rcvd [LCP ConfRej id=0x1 ]
Jan 6 04:43:31 s24 pppd[23775]: sent [LCP ConfReq id=0x2 <mru 1456> <asyncmap 0x0> <magic 0x71049b38>]
Jan 6 04:43:31 s24 pppd[23775]: rcvd [LCP ConfNak id=0x2 ]
Jan 6 04:43:31 s24 pppd[23775]: sent [LCP ConfReq id=0x3 <mru 1456> <asyncmap 0x0> <magic 0x71049b38>]
Jan 6 04:43:31 s24 pppd[23775]: rcvd [LCP ConfAck id=0x3 <mru 1456> <asyncmap 0x0> <magic 0x71049b38>]
Jan 6 04:43:31 s24 pppd[23775]: peer refused to authenticate: terminating link
Jan 6 04:43:31 s24 pppd[23775]: sent [LCP TermReq id=0x4 "peer refused to authenticate"]
Jan 6 04:43:31 s24 pppd[23775]: rcvd [IPCP ConfReq id=0x1 <addr 0.0.0.0>]
Jan 6 04:43:31 s24 pppd[23775]: Discarded non-LCP packet when LCP not open
Jan 6 04:43:31 s24 pppd[23775]: rcvd [LCP TermAck id=0x4 "peer refused to authenticate"]
Jan 6 04:43:31 s24 pppd[23775]: Connection terminated.

**two successful connexions **
Jan 6 04:43:32 s24 pppd[24330]:
Jan 6 04:43:32 s24 pppd[24332]:

And finaly the failed one exit..
Jan 6 04:43:32 s24 pppd[23775]: Exit.

But it seems that the PTS that has been free wasn't the good one...
....
Jan 6 04:43:37 s24 xl2tpd[32395]: check_control: control, cid = 0, Ns = 128, Nr = 65
Jan 6 04:43:37 s24 xl2tpd[32395]: ourcid = 56184, entropy_buf = db78
Jan 6 04:43:37 s24 xl2tpd[32395]: trying to send control packet to 56363
Jan 6 04:43:37 s24 xl2tpd[32395]: control_xmit: Scheduling and transmitting packet 65
Jan 6 04:43:37 s24 xl2tpd[32395]: control_zlb: sending control ZLB on tunnel 27573
Jan 6 04:43:37 s24 xl2tpd[32395]: check_control: control, cid = 16712, Ns = 129, Nr = 66
Jan 6 04:43:37 s24 xl2tpd[32395]: start_pppd: I'm running:
Jan 6 04:43:37 s24 xl2tpd[32395]: "/usr/sbin/pppd"
Jan 6 04:43:37 s24 xl2tpd[32395]: "/dev/pts/62"
Jan 6 04:43:37 s24 xl2tpd[32395]: "passive"
Jan 6 04:43:37 s24 xl2tpd[32395]: "nodetach"
Jan 6 04:43:37 s24 xl2tpd[32395]: "x.x.x.x:192.168.0.64"
Jan 6 04:43:37 s24 xl2tpd[32395]: "file"
Jan 6 04:43:37 s24 xl2tpd[32395]: "/etc/ppp/options.l2tpd.lns"
Jan 6 04:43:37 s24 xl2tpd[32395]: Call established with x.x.x.x, PID: 25157, Local: 56184, Remote: 16712, Serial: 0
Jan 6 04:43:37 s24 xl2tpd[32395]: control_zlb: sending control ZLB on tunnel 27573
Jan 6 04:43:37 s24 pppd[25157]: Plugin radius.so loaded.
Jan 6 04:43:37 s24 pppd[25157]: RADIUS plugin initialized.
Jan 6 04:43:37 s24 pppd[25157]: pppd 2.4.7 started by root, uid 0
Jan 6 04:43:37 s24 pppd[25157]: Device pts_62 is locked by pid 22720
Jan 6 04:43:37 s24 pppd[25157]: Exit.