View Issue Details

IDProjectCategoryView StatusLast Update
0001872unrealircdpublic2004-06-25 19:46
Reportersh0 Assigned Tosyzop  
PrioritynormalSeveritycrashReproducibilityrandom
Status closedResolutionopen 
Product Version3.2 
Summary0001872: frequent rehashing crashes ircd
DescriptionFrequent rehashing appears to crash Unreal 3.2 under certain (unknown to me) conditions. I'm using a script that rehashes the ircd rather frequently (up to about once every 2-3 seconds for several minutes) under certain conditions. The rehashes are usually followed by tries of the ircd to connect to other servers of the network.
I'm not certain where the problem lies, and can't reproduce it. However, I'm currently getting about one coredump every 24 hours, so further data collection or testing shouldn't be a problem.
Steps To ReproduceHaven't found any way to do it reliably.
Perhaps make sure the ircd can't link a number of servers that are set to autoconnect, and flood it with REHASH commands from users with appropriate permissions?
Additional InformationUsing gdb on the latest corefile (after creating a symbolic link to commands.so in unrealircd's /tmp directory to allow gdb to find the file) as mentioned in the Unreal 3.1 bug report instructions gives the following:
"
[...]
Loaded symbols for tmp/F33A403.commands.so
#0 0x482df5f7 in ?? ()
(gdb) bt
#0 0x482df5f7 in ?? ()
#1 0x081b6cb0 in ?? ()
#2 0x0000002c in ?? ()
#3 0x00030008 in ?? ()
#4 0x081da730 in ?? ()
#5 0xbffff844 in ?? ()
#6 0xbffff848 in ?? ()
#7 0x00000001 in ?? ()
0000008 0x477d44d0 in ?? ()
#9 0xbffff860 in ?? ()
#10 0x482e80eb in ?? ()
#11 0xbffff844 in ?? ()
#12 0xbffff848 in ?? ()
#13 0x081b6cb0 in ?? ()
#14 0x081da730 in ?? ()
#15 0x29796c6e in ?? ()
#16 0x00030008 in ?? ()
0000017 0x00000001 in ?? ()
#18 0x081da730 in ?? ()
#19 0x081daac8 in ?? ()
0000020 0x482ec858 in ?? ()
#21 0x0000000d in ?? ()
#22 0x081cf770 in ?? ()
#23 0xbffff878 in ?? ()
#24 0x482da5ac in ?? ()
#25 0x482ee9e0 in ?? ()
0000026 0x081bb0e4 in ?? ()
#27 0x081bb0e8 in ?? ()
#28 0x29796c6e in ?? ()
#29 0x482da570 in ?? ()
0000030 0x081cf770 in ?? ()
#31 0xbffff898 in ?? ()
#32 0x08081807 in ircd_SSL_client_handshake (acptr=0x482ec858) at ssl.c:452
Previous frame inner to this frame (corrupt stack?)
"
This output appears to be identical for each of the three core files. Note that none of the links actually uses SSL, and it isn't listed in any of the link-options blocks either.
3rd party modules

Activities

syzop

2004-06-14 23:19

administrator   ~0006644

Stack looks totally corrupt :/

1. Just to be sure... it's a script that executes '/rehash' on IRC, and not a script that does killall -1 <pid> or ./unreal rehash on the shell all the time? :)
2. Are you using any 3rd party modules? (anything besides commands)
3. Do you have remote includes enabled? And if so, are you using them?
4. How many servers do you have on autoconnect? And in link::hostname do you have IP's? (ipv4/ipv6?) or hostnames? Or both.. And what (other) link::options do you have?
5. Hmm that was it for now ;) *sleep*

codemastr

2004-06-14 23:27

reporter   ~0006645

Could also be something in the config file...

sh0

2004-06-15 02:53

reporter   ~0006646

Last edited: 2004-06-15 02:54

as response to syzop:
1. To be precise the script sits on a server-to-server connection, and sends the rehash as ":operator-nick REHASH servername" where operator-nick is a nick with netadmin status and servername is the unrealircd 3.2 to be rehashed. It doesn't use process signals (as sent by kill) or the unreal scripts for rehashing.
2.No, "loadmodule "modules/commands.so";" is the only loadmodule statement in any of the used config files.
3.No, compiled without that feature.
4.There are 6 autoconnect servers altogether.
The link::options for most of the servers are just autoconnect and zip, though zip links are hardley ever used in practice, and are turned off for (exactly) one of the six autoconnect servers.
The ircd is compiled without ipv6 support.
link::hostname is a hostname, not an ip, for all autoconnect servers.
It might also be relevant that 'ciphers "DES-CBC3-MD5";' is set in the link blocks, even though the options don't include ssl.

as response to codemastr:
Anything specific I should look for? I obviously can't paste the file here since it's full of sensitive data for the network. The ircd has to my knowledge never complained about syntax errors in the current unrealircd.conf.

edited on: 2004-06-15 02:54

syzop

2004-06-17 19:47

administrator   ~0006683

using mpatrol, added ~20 autoconnect link blocks.
/rehash works fine, then a while later another /rehash, too..
But.. /rehash and then immediately another /rehash when it's still trying to connect to the servers causes a crash...

[01:23:44] -maintest.test.net- *** Notice -- Loading IRCd configuration ..
[01:23:44] -maintest.test.net- *** Notice -- oldcloak: WARNING: The 'oldcloak' module should *ONLY* be used temporary for upgrading purposes since it is considered insecure, upgrade to 'cloak' as soon as you can.
[01:23:44] -maintest.test.net- *** Notice -- unrealircd.conf:121: listen with SSL flag enabled on a non SSL compile
[01:23:44] -maintest.test.net- *** Notice -- Configuration loaded without any problems ..
[01:23:44] Ping? Pong!
[01:23:44] -maintest.test.net- *** Notice -- Connection to link19.testnet[link19.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link18.testnet[link18.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link17.testnet[link17.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link16.testnet[link16.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link15.testnet[link15.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link14.testnet[link14.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link13.testnet[link13.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link12.testnet[link12.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link11.testnet[link11.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link10.testnet[link10.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link9.testnet[link9.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link8.testnet[link8.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link7.testnet[link7.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link6.testnet[link6.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link5.testnet[link5.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link4.testnet[link4.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link3.testnet[link3.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link2.testnet[link2.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to link1.testnet[link1.testnet] activated.
[01:23:44] -maintest.test.net- *** Notice -- Connection to winlink.test.net[192.168.5.24] activated.
[01:23:44] -maintest.test.net- *** Notice -- Hostname * is unknown for server services.test.net.
[01:23:44] -maintest.test.net- *** Notice -- Hostname * is unknown for server 4thlink.test.net.
[01:23:45] -maintest.test.net- *** Notice -- Hostname * is unknown for server testlink2.test.net.
[01:23:45] -maintest.test.net- *** Notice -- Hostname * is unknown for server testlink.test.net.
[01:23:45] -maintest.test.net- *** Notice -- Ein is rehashing server config file
unrealircd.conf Rehashing
[01:28:26] -maintest.test.net- *** Notice -- Loading IRCd configuration ..
[01:28:26] -maintest.test.net- *** Notice -- oldcloak: WARNING: The 'oldcloak' module should *ONLY* be used temporary for upgrading purposes since it is considered insecure, upgrade to 'cloak' as soon as you can.
[01:28:26] -maintest.test.net- *** Notice -- unrealircd.conf:121: listen with SSL flag enabled on a non SSL compile
[01:28:26] -maintest.test.net- *** Notice -- Configuration loaded without any problems ..
*crash*

Program received signal SIGSEGV, Segmentation fault.
0x08075d43 in completed_connection (cptr=0xbf90c68) at s_bsd.c:820
820 if (!BadPtr(aconf->connpwd))
(gdb) bt
#0 0x08075d43 in completed_connection (cptr=0xbf90c68) at s_bsd.c:820
#1 0x08077c01 in read_message (delay=1, listp=0x81577c0) at s_bsd.c:1898
#2 0x08067a51 in main (argc=0, argv=0xbffffb24) at ircd.c:1549
(gdb) frame 0
#0 0x08075d43 in completed_connection (cptr=0xbf90c68) at s_bsd.c:820
820 if (!BadPtr(aconf->connpwd))
(gdb) list
815 if (!aconf)
816 {
817 sendto_ops("Lost configuration for %s", get_client_name(cptr, FALSE));
818 return -1;
819 }
820 if (!BadPtr(aconf->connpwd))
821 sendto_one(cptr, "PASS :%s", aconf->connpwd);
822
823 send_proto(cptr, aconf);
824 sendto_one(cptr, "SERVER %s 1 :U%d-%s%s-%i %s",
(gdb) p *aconf
$4 = {prev = 0x0, next = 0xd1b4fbc, flag = {temporary = 0, permanent = 0}, servername = 0x0, username = 0x0, hostname = 0x0, bindip = 0x0,
  hubmask = 0x0, leafmask = 0x0, connpwd = 0x0, recvauth = 0x0, port = 6667, options = 4, leafdepth = 0 '\0', refcount = 0,
  class = 0xcac1fd8, ipnum = {s_addr = 319137984}, hold = 1087515222}

whole func:
/*
** completed_connection
** Complete non-blocking connect()-sequence. Check access and
** terminate connection, if trouble detected.
**
** Return TRUE, if successfully completed
** FALSE, if failed and ClientExit
*/
int completed_connection(aClient *cptr)
{
    ConfigItem_link *aconf = cptr->serv ? cptr->serv->conf : NULL;
    extern char serveropts[];
    SetHandshake(cptr);

    if (!aconf)
    {
        sendto_ops("Lost configuration for %s", get_client_name(cptr, FALSE));
        return -1;
    }
    if (!BadPtr(aconf->connpwd))
        sendto_one(cptr, "PASS :%s", aconf->connpwd);

    send_proto(cptr, aconf);
    sendto_one(cptr, "SERVER %s 1 :U%d-%s%s-%i %s",
        me.name, UnrealProtocol, serveropts, extraflags ? extraflags : "", me.serv->numeric,
        me.info);
    if (!IsDead(cptr))
        start_auth(cptr);

    return (IsDead(cptr)) ? -1 : 0;
}

so... cptr->serv->conf is fucked I guess..
Just checking cptr->serv to see if it's also f*cked..
(gdb) p *cptr->serv
$12 = {nexts = 0x0, user = 0x0, up = 0x8152829 "maintest.test.net", by = "AutoConn.", '\0' <repeats 21 times>, conf = 0xcfeefbc,
  timestamp = 0, numeric = 0, users = 0, flags = {synced = 0}}
nope, is fine.

will take a look ;).

w00t

2004-06-17 19:57

reporter   ~0006684

Syzop, one thing that I noted (still on b-18, so it might've been fixed) was that wircd.exe (not sure about nix version) with a /rehash, lost memory each time it executed. It wasn't much, around 60kb or so each time but that does add up...

I use winxp pro sp1. Open taskman.exe and watch the size of wircd.exe.

Perhaps the two are related?

syzop

2004-06-17 20:21

administrator   ~0006687

w00t: probably not. In either case, we don't support versions of 9 months ago.

syzop

2004-06-20 12:32

administrator   ~0006739

Unfortunately I'm quite busy atm, so this could take a few days (if it's up to me ;p).

w00t

2004-06-21 06:47

reporter   ~0006744

Actually, strike that.

It was increasing by around 200kb. Downloading 3.2 sometime now, god willing.
I had 2 mirc clients connected and rehashing reguarly, wircd.exe got up to 124mb (with 2 clients connected) before I got bored and stopped the experiment.

Will update you as to how things go.

As another note, I didnt get any problem with repeated rehashing on b18 ;)

w00t

2004-06-22 00:02

reporter   ~0006752

Allrighty, whatever it was has been fixed in 3.2Final.

No permanent gain recorded in wircd.exe after around 3000 rehashes.
(/rehash) No crashes/stack corruption either.

syzop

2004-06-25 19:46

administrator   ~0006783

This should be fixed now in CVS (.75).

It was quite a complicated problems. In fact it were 2 problems.
[Changes msg:]
- Fixed "quickly-rehashing + autoconnect linkblocks = crash"-bug. This involved fixing
  multiple reference count bugs, one related to sptr->serv->conf, and another one related
  to sptr->serv->class. Both caused problems when someone did a /rehash when a server
  was in the process of connecting (so it might also happen when connfreq was hit and you
  did a /rehash). Original bug was reported by sh0 (0001872).

[personal notes:]
sptr->serv->conf BUG:
- reference count for 'conf' (conf->refcount) was only increased upon
  succesfull (or start of) handshake, so any /rehash during 'connecting' state
  and 'succesfully connected' would cause a read-after-free.

sptr->serv->class BUG:
- when a 'conf' cannot be freed during reference count (== marked as 'temporary')
  then it still has a ->class attached to it. However this class might have been
  freed upon rehash... Fun!
  Now also doing ++ reference count if a link block uses it, and doing -- if a
  link block is removed.

Made the code more readable/nicer by adding delete_linkblock() and delete_classblock() to avoid any future inconsistency if we add more fields or whatever...

Blahhh... This took like 2 hours ;).

I think my patch is correct... I did like 10-20 rehashes which caused ~200 outgoing simultanous connections... and then rehashed to a conf with the class + all 24 link blocks gone and they got removed nicely (well, after a minute or so when the links understood they failed and the reference count dropped to zero).

sh0: I would appreciate it if you have some time to test this in the next 5 days or so :). If you could mail me any results ([email protected]), either negative or positive, that would be helpful :).

Issue History

Date Modified Username Field Change
2004-06-14 21:34 sh0 New Issue
2004-06-14 23:19 syzop Note Added: 0006644
2004-06-14 23:27 codemastr Note Added: 0006645
2004-06-15 02:53 sh0 Note Added: 0006646
2004-06-15 02:54 sh0 Note Edited: 0006646
2004-06-17 19:47 syzop Note Added: 0006683
2004-06-17 19:47 syzop Status new => confirmed
2004-06-17 19:57 w00t Note Added: 0006684
2004-06-17 20:21 syzop Note Added: 0006687
2004-06-20 12:32 syzop Note Added: 0006739
2004-06-21 06:47 w00t Note Added: 0006744
2004-06-22 00:02 w00t Note Added: 0006752
2004-06-25 18:00 syzop Status confirmed => assigned
2004-06-25 18:00 syzop Assigned To => syzop
2004-06-25 19:46 syzop Status assigned => closed
2004-06-25 19:46 syzop Note Added: 0006783