Opened 13 years ago

Closed 13 years ago

Last modified 13 years ago

#1836 closed defect (fixed)

cccam : duplicate user bug

Reported by: cairol Owned by: schlocke
Priority: critical Component: Protocol - CCCam
Severity: high Keywords:
Cc: Sensitive: no

Description

Revision

latest

Issue Description

duplicate user not running properly. see the log below.

When the issue occurs

<Please fill in>

How the issue is reproducable

<Please fill in>
2011/05/05 0:14:10 A8CA8280 c client(A89F3280) duplicate user 'XXXXXXXXXXXX' from 175.138.117.133 (prev 175.138.117.133) set to fake (uniq=3)
2011/05/05 0:14:10 A8CBD280 c anonymous disconnected from 124.13.39.156
2011/05/05 0:14:10 A8CBD280 c thread A8CBD280 ended!
2011/05/05 0:14:10 A8C46280 c encrypted cccam-client 124.13.39.156 granted (XXXXXXXXXX, au=off)
2011/05/05 0:14:10 A8DC0280 c encrypted cccam-client 175.145.175.207 granted (XXXXXXXXX, au=off)
2011/05/05 0:14:10 A8B90280 c anonymous disconnected from 202.75.4.160
2011/05/05 0:14:10 A8B90280 c thread A8B90280 ended!
2011/05/05 0:14:10 A8BC1280 c encrypted cccam-client 120.140.91.91 granted (XXXXXXXXXX, au=off)
2011/05/05 0:14:10 A8C46280 c XXXXXXXXXXX disconnected from 124.13.39.156
2011/05/05 0:14:10 A8C46280 c thread A8C46280 ended!
2011/05/05 0:14:10 A8AE1280 c anonymous disconnected from 175.142.138.37
2011/05/05 0:14:10 A8AE1280 c thread A8AE1280 ended!
2011/05/05 0:14:10 A8E30280 c anonymous disconnected from 118.101.81.188
2011/05/05 0:14:10 A8E30280 c thread A8E30280 ended!
2011/05/05 0:14:10 A84BD280 c client(A8565280) duplicate user 'XXXXXXXXXX' from 60.54.17.135 (prev 60.54.17.135) set to fake (uniq=3)
2011/05/05 0:14:10 A8CA8280 c thread A89F3280 killed!
2011/05/05 0:14:10 A8CA8280 c encrypted cccam-client 175.138.117.133 granted (XXXXXXXXXXX, au=off)
2011/05/05 0:14:10 A8CA8280 c XXXXXXXXXX disconnected from 175.138.117.133
2011/05/05 0:14:10 A8CA8280 c thread A8CA8280 ended!
2011/05/05 0:14:11 A8ED8280 c anonymous disconnected from 202.190.134.32
2011/05/05 0:14:11 A8ED8280 c thread A8ED8280 ended!
2011/05/05 0:14:11 A8CBD280 c encrypted cccam-client 60.48.253.98 granted (XXXXXXXXX, au=off)
2011/05/05 0:14:11 A89F3280 c anonymous disconnected from 175.138.117.133
2011/05/05 0:14:11 A89F3280 c thread A89F3280 ended!
2011/05/05 0:14:11 A8D81280 c thread A89EC280 killed!
2011/05/05 0:14:11 A8D81280 c encrypted cccam-client 175.144.142.30 granted (XXXXXXXXXXX, au=off)
2011/05/05 0:14:11 A8D81280 c XXXXXXXXXX disconnected from 175.144.142.30
2011/05/05 0:14:11 A8D81280 c thread A8D81280 ended!
2011/05/05 0:14:11 A8BB3280 c anonymous disconnected from 180.75.218.249
2011/05/05 0:14:11 A8BB3280 c thread A8BB3280 ended!
2011/05/05 0:14:11 A8B58280 c encrypted cccam-client 124.13.39.156 granted (XXXXXXXXXX, au=off)
2011/05/05 0:14:11 A8D57280 c thread A8D11280 killed!
2011/05/05 0:14:11 A8D57280 c encrypted cccam-client 124.82.86.242 granted (XXXXXXXXXX, au=off)
2011/05/05 0:14:12 A8BB3280 c client(A8CCB280) duplicate user 'XXXXXXXXXXXX' from 175.138.39.73 (prev 175.138.39.73) set to fake (uniq=3)
2011/05/05 0:14:12 A8D11280 c encrypted cccam-client 124.13.39.156 granted (XXXXXXXXXX, au=off)
2011/05/05 0:14:12 A8ED8280 c anonymous disconnected from 124.82.79.242
2011/05/05 0:14:12 A8ED8280 c thread A8ED8280 ended!
2011/05/05 0:14:12 A8CAF280 c thread A851F280 killed!
2011/05/05 0:14:12 A8CAF280 c client(A8B58280) duplicate user 'XXXXXXXXXXX' from 124.13.39.156 (prev 124.13.39.156) set to fake (uniq=3)
2011/05/05 0:14:12 A89F3280 c client(A8DDC280) duplicate user 'XXXXXXXXXXX' from 124.82.31.209 (prev 124.82.31.209) set to fake (uniq=3)
2011/05/05 0:14:12 A8CAF280 c thread A8B58280 killed!

Attachments (2)

5244valgrind-log.txt (21.1 KB ) - added by littlejoe 13 years ago.
valgrind log of my PC linux version 5244
5244valgrind-log-nolb.txt (22.9 KB ) - added by littlejoe 13 years ago.
Valgrind log 5244 without loadbalancer same memory leak.

Download all attachments as: .zip

Change History (35)

comment:1 by littlejoe, 13 years ago

With rev 5217 and 5218 same issue after approximately 2H. I begin to see lines like this, a lot of users connections, the number of users double and grows up to more than 350... Restarting oscam makes it dissapearing for the next 2H and back again...

(My config: x86 64 CPU, 65 readers, 45 users online/130 configured)

comment:2 by littlejoe, 13 years ago

Owner: set to schlocke

comment:3 by Deas, 13 years ago

Resolution: invalid
Status: newclosed

rtfm:

dropdups = 0|1

mode for duplicate client connections (requirement: uniq > 0):

0 = mark client as duplicate, but don't disconnect them (default)
1 = drop duplicate connections instead of marking as duplicate

in reply to:  3 comment:4 by littlejoe, 13 years ago

Resolution: invalid
Status: closedreopened

Replying to Deas:

rtfm:

dropdups = 0|1

mode for duplicate client connections (requirement: uniq > 0):

0 = mark client as duplicate, but don't disconnect them (default)
1 = drop duplicate connections instead of marking as duplicate

My config dropdups=1 - 5206 version is OK.

comment:5 by beneee, 13 years ago

If 5206 is OK then set it to fixed or not

comment:6 by littlejoe, 13 years ago

I noticed this:
I compiled 5206 with EasyBuild script 0.8.0d and 5218 with 0.8.1. See the folowing changelog:

-------------------------------------------------------------------------------------------

v.0.8.0d

  • globals.h: clientmaxidle-entry corrected (max 9999 default) clientimeout-entry corrected (max 99999 default) take care to set both to your preferred timeout in your config! (if nothing set 9999/99999 are default!!!!)
  • oscam-http.c: webif-shutdown-restart corrected (set restarttime to 5 seconds for better refr esh without 404)

v.0.8.0e

  • many generall code fixxes/optimized part14
  • get toolchains dreambox+nslu2unslung fixxed.
  • add toolchain ppc-tuxbox-dbox2_old for: PPC Tuxbox Old (Dbox2, Dreambox 500/60 0) (first do: get toolchain 4-13 than build-single 2-14, 1st time chain will buil d-finished and that takes some time ca 20mins up to 1h)) PLEASE TEST IF BINARY WORKING ON DBOX2!

v.0.8.0f

  • showbuild_* off on fixxed

v.0.8.1

  • clientmaxidle revert to 120 also clienttimeout reverted (fixed by Admin on svn , so patch no longer needed! many thx!!)
  • dockstar: set build to static so on openwrt+debian working ==

If I look at the defaults in webif from 5206, clientmaxidle = 99999 seconds and on my 5218 version it is back to 120 seconds.

So now I have configured clientmaxidle = 99998 to try the same with 5218. I will let it run for some hours and keep you informed.

Keeping the ticket open for now.

comment:7 by Deas, 13 years ago

Resolution: invalid
Status: reopenedclosed

but this is not a bug. clientmaxidle disconnects per default after 120 minutes. the client does not respect this and reconnect even if idle.

you have these options: increase clientmaxidle, configure the client to not reconnect if disconnected when idle or use a client/protocol that supports sleep...

in reply to:  7 comment:8 by littlejoe, 13 years ago

Replying to Deas:

but this is not a bug. clientmaxidle disconnects per default after 120 minutes. the client does not respect this and reconnect even if idle.

you have these options: increase clientmaxidle, configure the client to not reconnect if disconnected when idle or use a client/protocol that supports sleep...

So the documentation is not correct? those are minutes and not seconds???

"clientmaxidle
parameter is optional
value for client process being idle before disconnect in seconds
Example:
clientmaxidle = 200 # Disconnect after 200 seconds
Default:
clientmaxidle = 120 # Disconnect after 120 seconds
"

All my clients are CCcam or Oscam using CCcam 2.2.1 protocol and I never had this before. 5206 after one night has the same bug.

Trying with the last SVN 5219 version compiled without Easybuild. Just started it. Let's see what happend after 120 MINUTES.

comment:9 by littlejoe, 13 years ago

Resolution: invalid
Severity: mediumhigh
Status: closedreopened

Still the same vith 5224. Num of users grows ans lot's of sleeping anonymouse connections with duplicate IPs after a few heavy load hours. The number of users double, triple and the active users goes down to 5 or 6...

Tried with and witout loadbalancer (=0 or =1) and my dropdups = 1. Same issue.

Reopening ticket.

Last edited 13 years ago by littlejoe (previous) (diff)

comment:10 by Deas, 13 years ago

sorry - seconds, not minutes. this was just a typo... please post your oscam.conf

in reply to:  10 comment:11 by littlejoe, 13 years ago

Replying to Deas:

sorry - seconds, not minutes. this was just a typo... please post your oscam.conf

With 5206 (stays longer before the bug)

[global]
serverip = xx.xx.xx.xx
usrfile = /var/log/oscam/oscamuser.log
logfile = /var/log/oscam/oscam.log
cwlogdir = /var/log/oscam/cw
disablelog = 1
clientmaxidle = 120
failbantime = 15
failbancount = 5
sleep = 600
unlockparental = 1
nice = -15
maxlogsize = 2000
saveinithistory = 1
dropdups = 1
lb_save = 10000
lb_nbest_readers = 2
lb_nfb_readers = 2
lb_retrylimit = 2000
lb_stat_cleanup = 120
lb_reopen_mode = 1

[monitor]
port = 988
aulow = 120
hideclient_to = 30
monlevel = 1
appendchaninfo = 0

[cccam]
port = 12000
reshare = 0
ignorereshare = 1
version = 2.2.1
minimizecards = 2

[webif]
httpport = xxxxx
httpuser = xxxxxxxx
httppwd = xxxxx
httpallowed = 0.0.0.0-255.255.255.255

comment:12 by alborland, 13 years ago

clientmaxidle = 86400
try it
its not a prob from easyscript builds!
if you dont set an entry its 120
if you set 120 its 120
actual theres no option to stay client!
86400=seks*h*d
so client max disconnected after 24h!

comment:13 by littlejoe, 13 years ago

I have tried with 99998 but the bug comed a lot quicker than 24H :-) 2H or 3H is enough (I have 64 CCcam proxies, 4 newcamd readers and 130 CCcam clients with an average of 40 active.

comment:14 by alborland, 13 years ago

so something is wrong caculate in code!
1h=3600secs
3600*24=86400
so it must be 24h
if not its a svn code bug

Last edited 13 years ago by alborland (previous) (diff)

comment:15 by littlejoe, 13 years ago

I have more informations and a log of what happend just before restart. (the webif is down or not responding at this moment but I connected using OneStep OScamMonitor and got the folowing log (IP addresses replaced by 111.222.ori.ori, usernames and proxies are changed for confidentiality). It seems to be a TREAD ERROR (treads not released or ended somewhere?).
--LOG--
x86-64_SVR: [LOG803]2011/05/12 8:36:42 60AFDE10 c encrypted cccam-client 111.222.154.220 granted (friend118, au=off)
x86-64_SVR: [LOG804]2011/05/12 8:36:42 4FBE5E10 p cccamproxy1.xx.yy connection blocked, retrying in 43s
x86-64_SVR: [LOG805]2011/05/12 8:36:42 50D53B20 s ERROR: can't create thread for TCP client from 111.222.169.78
x86-64_SVR: [LOG806]2011/05/12 8:36:42 60A40E10 c client(5FC08E10) duplicate user 'friend76' from 111.222.114.175 (prev 111.222.114.175) set to fake (uniq=3)
x86-64_SVR: [LOG807]2011/05/12 8:36:42 607BCE10 c thread 5FA10E10 killed!
x86-64_SVR: [LOG808]2011/05/12 8:36:42 607BCE10 c client(609E5E10) duplicate user 'Client_x' from 111.222.178.151 (prev 111.222.178.151) set to fake (uniq=3)
x86-64_SVR: [LOG809]2011/05/12 8:36:42 50D53B20 s ERROR: can't create thread for TCP client from 111.222.194.71
x86-64_SVR: [LOG810]2011/05/12 8:36:43 5FA10E10 c encrypted cccam-client 111.222.245.225 granted (friend98, au=off)
x86-64_SVR: [LOG811]2011/05/12 8:36:43 4FBE5E10 p cccamproxy1.xx.yy, retrying in 42s
x86-64_SVR: [LOG812]2011/05/12 8:36:43 588E1E10 c thread 608B1E10 killed!
x86-64_SVR: [LOG813]2011/05/12 8:36:43 588E1E10 c client(607A0E10) duplicate user 'Client_y' from 111.222.139.46 (prev 111.222.139.46) set to fake (uniq=3)
x86-64_SVR: [LOG814]2011/05/12 8:36:43 50D53B20 s ERROR: can't create thread for TCP client from 111.222.130.66
x86-64_SVR: [LOG815]2011/05/12 8:36:43 608B1E10 c anonymous disconnected from 111.222.199.182
x86-64_SVR: [LOG816]2011/05/12 8:36:43 608B1E10 c thread 608B1E10 ended!
x86-64_SVR: [LOG817]2011/05/12 8:36:43 5D95CE10 c thread 58EC2E10 killed!
x86-64_SVR: [LOG818]2011/05/12 8:36:43 5D95CE10 c client(604D6E10) duplicate user 'Client_z' from 111.222.16.86 (prev 111.222.16.86) set to fake (uniq=3)
x86-64_SVR: [LOG819]2011/05/12 8:36:43 50D53B20 s ERROR: can't create thread for TCP client from 111.222.36.186
x86-64_SVR: [LOG820]2011/05/12 8:36:43 58EC2E10 c anonymous disconnected from 111.222.90.39
x86-64_SVR: [LOG821]2011/05/12 8:36:43 58EC2E10 c thread 58EC2E10 ended!
x86-64_SVR: [LOG822]2011/05/12 8:36:44 60D73E10 c thread 5F762E10 killed!
x86-64_SVR: [LOG823]2011/05/12 8:36:44 60D73E10 c encrypted cccam-client 111.222.67.84 granted (client_a, au=off)
x86-64_SVR: [LOG824]2011/05/12 8:36:44 4FBE5E10 p cccamproxy1.xx.yy connection blocked, retrying in 41s
x86-64_SVR: [LOG825]2011/05/12 8:36:44 50D53B20 s ERROR: can't create thread for TCP client from 111.222.67.84
x86-64_SVR: [LOG826]2011/05/12 8:36:44 5F762E10 c anonymous disconnected from 111.222.80.121
x86-64_SVR: [LOG827]2011/05/12 8:36:44 5F762E10 c thread 5F762E10 ended!
x86-64_SVR: [LOG828]2011/05/12 8:36:44 608B1E10 c anonymous disconnected from 111.222.154.220
x86-64_SVR: [LOG829]2011/05/12 8:36:44 608B1E10 c thread 608B1E10 ended!
x86-64_SVR: [LOG830]2011/05/12 8:36:44 5F475E10 c thread 5EB7DE10 killed!
x86-64_SVR: [LOG831]2011/05/12 8:36:44 5F475E10 c encrypted cccam-client 111.222.161.20 granted (client_b, au=off)
x86-64_SVR: [LOG832]2011/05/12 8:36:44 4FBE5E10 p cccamproxy1.xx.yy connection blocked, retrying in 40s
x86-64_SVR: [LOG833]2011/05/12 8:36:44 50D53B20 s ERROR: can't create thread for TCP client from 111.222.4.13
x86-64_SVR: [LOG834]2011/05/12 8:36:44 5EB7DE10 c anonymous disconnected from 111.222.153.242
x86-64_SVR: [LOG835]2011/05/12 8:36:44 58EC2E10 c anonymous disconnected from 111.222.16.86
x86-64_SVR: [LOG836]2011/05/12 8:36:44 5EB7DE10 c thread 5EB7DE10 ended!
x86-64_SVR: [LOG837]2011/05/12 8:36:44 58EC2E10 c thread 58EC2E10 ended!
x86-64_SVR: [LOG838]2011/05/12 8:36:45 59097E10 c thread 5FBF3E10 killed!
x86-64_SVR: [LOG839]2011/05/12 8:36:45 59097E10 c encrypted cccam-client 111.222.139.46 granted (client_c, au=off)
x86-64_SVR: [LOG840]2011/05/12 8:36:45 4FBE5E10 p cccamproxy1.xx.yy connection blocked, retrying in 39s
x86-64_SVR: [LOG841]2011/05/12 8:36:45 50D53B20 s ERROR: can't create thread for TCP client from 111.222.141.34
x86-64_SVR: [LOG842]2011/05/12 8:36:45 608B1E10 c anonymous disconnected from 111.222.208.198
x86-64_SVR: [LOG843]2011/05/12 8:36:45 5F762E10 c anonymous disconnected from 111.222.240.60
x86-64_SVR: [LOG844]2011/05/12 8:36:45 608B1E10 c thread 608B1E10 ended!
x86-64_SVR: [LOG845]2011/05/12 8:36:45 5F762E10 c thread 5F762E10 ended!
x86-64_SVR: [LOG846]2011/05/12 8:36:45 5FBF3E10 c anonymous disconnected from 111.222.138.143
x86-64_SVR: [LOG847]2011/05/12 8:36:45 5FBF3E10 c thread 5FBF3E10 ended!
x86-64_SVR: [LOG848]2011/05/12 8:36:45 606E3E10 c thread 6046DE10 killed!
x86-64_SVR: [LOG849]2011/05/12 8:36:45 606E3E10 c encrypted cccam-client 111.222.65.2 granted (friend117, au=off)
x86-64_SVR: [LOG850]2011/05/12 8:36:45 4FBE5E10 p cccamproxy1.xx.yy connection blocked, retrying in 39s
x86-64_SVR: [LOG851]2011/05/12 8:36:45 50D53B20 s ERROR: can't create thread for TCP client from 111.222.79.112
x86-64_SVR: [LOG852]2011/05/12 8:36:45 58EC2E10 c anonymous disconnected from 111.222.27.18
x86-64_SVR: [LOG853]2011/05/12 8:36:45 5EB7DE10 c anonymous disconnected from 111.222.51.51
x86-64_SVR: [LOG854]2011/05/12 8:36:45 58EC2E10 c thread 58EC2E10 ended!
x86-64_SVR: [LOG855]2011/05/12 8:36:45 5EB7DE10 c thread 5EB7DE10 ended!

Last edited 13 years ago by littlejoe (previous) (diff)

comment:16 by Admin, 13 years ago

Maybe you have some kind of system wide limit on the maximum amount of threads. The error indicates that pthread_create fails and OSCam can't do anything against that.

comment:17 by littlejoe, 13 years ago

My system has 512M of memory and what I can find if I ask for a thread limit is:
# cat /proc/sys/kernel/threads-max

  1. I think it is a lot!

When this bug starts, I get only duplicate clients then when the memory is nearly full and the webif already not responding, ERROR can't create thread begins.

I think that cleanup_thread during heavy load disconnects clients but doesn't kills threads correctly. I have now build a version without the 500ms delay added in function cleanup_thread in rev 5135 to test.

comment:19 by littlejoe, 13 years ago

Thanks but I had these "cannot create pipe errors" before and already set my ulimit to 819200 and that did the trick.

For infos. without the 500ms delay in my modifed 5225 version, the duplicate user bug comes early so I have now doubled the delay (1000ms) and I'm currently testing this...

comment:20 by Deas, 13 years ago

isn´t that a little bit too hight? schlocke talks about 4 times the user accounts and others set it to 4000...

comment:21 by littlejoe, 13 years ago

My usercount is 130. My Readers/Proxies count is 68.
The native value of my Ubuntu is 1024. That sould be enough ;-)

At the time this happend, I tried a lot of combinations and finally (maybe also because of SVN versions changes too) I stopped with a working config with 819200 (I agree it is too much). During my last tests concerning this ticket I have tried 4096 and it doesn't make any difference.

For infos, 1000ms is worst!! Currently trying 200ms ;-)

Last edited 13 years ago by littlejoe (previous) (diff)

comment:22 by littlejoe, 13 years ago

200ms nope.
Another info. During the bug, the client count is 4/1175 keep growing... The only remaining 4 are all CCcam 2.0.x or 2.1.x no 2.2.x or Oscam client'''

comment:23 by littlejoe, 13 years ago

Still the same with 5228 and 5229 :-(

comment:24 by littlejoe, 13 years ago

5232 and 5233 still have this bug.

comment:25 by littlejoe, 13 years ago

Tested 5237. Same bug.

As soon as the number of users grow, the active users decreases and you see a lot of duplicate users with same ip log lines and the memory grows until oscam crash or your system hang. What is this memory leak or tread not killed issue appearing only with high number of CCcam clients connexions???

comment:26 by littlejoe, 13 years ago

Tested 5240 (client list lock by admin). Sorry but this is the same.

by littlejoe, 13 years ago

Attachment: 5244valgrind-log.txt added

valgrind log of my PC linux version 5244

by littlejoe, 13 years ago

Attachment: 5244valgrind-log-nolb.txt added

Valgrind log 5244 without loadbalancer same memory leak.

comment:27 by littlejoe, 13 years ago

Admin, schlocke and developers, Please look at the folowing related to this ticket in the forum about memory leaks and threads. http://www.streamboard.tv/wbb2/thread.php?postid=382336#post382336

Thanks

comment:28 by littlejoe, 13 years ago

Resolution: fixed
Status: reopenedclosed

Fixed with the refactor of cleanup_thread() from Admin in #5381
THANKS FOR YOUR GREAT JOB!

comment:29 by roni1980, 13 years ago

Resolution: fixed
Status: closedreopened

in csloghistory with last svn 5386 i see duplicate and triplicate users wich dont have with 5377.
can anyone confirm?

Last edited 13 years ago by roni1980 (previous) (diff)

comment:30 by FilipeAmadeuO, 13 years ago

I can confirm. I have a lot more duplicates with 5386.
The only reason to not have duplicates is to activate the Drop duplicate users:YES

in reply to:  30 comment:31 by littlejoe, 13 years ago

Replying to FilipeAmadeuO:

I can confirm. I have a lot more duplicates with 5386.
The only reason to not have duplicates is to activate the Drop duplicate users:YES

Please test 5384. (5386 is for the dynamic-threads branch)
I can confirm that 5385 has a problem (hi cpu load on my x86)

comment:32 by littlejoe, 13 years ago

Resolution: fixed
Status: reopenedclosed

Fixed with changeset: [5392]

comment:33 by roni1980, 13 years ago

i confirm.have in use 5395 and it is ok
thanks

Note: See TracTickets for help on using tickets.