Notice: Any messages purporting to come from this site telling you that your password has expired, or that you need to verify your details, confirm your email, resolve issues, making threats, or asking for money, are
spam. We do not email users with any such messages. If you have lost your password you can obtain a new one by using the
password reset link.
Due to spam on this forum, all posts now need moderator approval.
Entire forum
➜ SMAUG
➜ SMAUG coding
➜ logfiles full or crap
It is now over 60 days since the last post. This thread is closed.
Refresh page
Pages: 1 2
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Thu 18 Jan 2007 07:24 AM (UTC) |
| Message
| having a small problem, i am trying to find out how this mumbled garbage is getting printed to my logfiles. what i did was make it so what file and line called the log_string function, and then made it so no line can print to the file stderr without going through the log string function. however i still have junk getting printed to my logfiles.
however i still couldn't figure out how this junk was getting into my logfile, so i commented everything in log_string out, so that none of my code is printing to the stderr file at all. however my logfiles are still getting the same junk printed to them.
so i figured none of my code is to blame for my bloated logfiles full of crap. does anyone have any idea how the smaug code is printing to the logfile or has anyone ran into this?
| | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #1 on Thu 18 Jan 2007 07:41 AM (UTC) |
| Message
| By garbage, do you mean completely random symbols? That means that somewhere you are not terminating a string correctly with a \0 at the end.
Have you tried grepping for all places that print to stderr? That would at least let you figure out where the culprit might be. You'd have to work backwards from there.
Are the garbage lines completely garbage, or are parts of them correct? That would be an even better hint as to where the problem is. |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #2 on Thu 18 Jan 2007 01:50 PM (UTC) |
| Message
| i already did grep for stderr and changed every single line to go through log_string so that i could see what file and line number the call was coming from in an effort to find out which string was not being done properly. and in some cases its random characters, or its the same thing over and over, like some random ip address, or the word endif over and over and over. and also what is being printed to the logfile does not have the file and line number next to it, so its not coming through the log_string function.
void log_string_plus2( const char *str, sh_int log_type, sh_int level, int lineNumber, const char *file )
{
char strtime[MAX_STRING_LENGTH];
snprintf( strtime, MAX_STRING_LENGTH, "%s :: (%s, line %d) :: %s\n", friendly_ctime( ¤t_time), file, lineNumber, str );
fprintf( stderr, strtime );
return;
}
defined in mud.h as:
#define log_string_plus(txt, log_type, level) ( log_string_plus2( (txt), (log_type), (level), __LINE__, __FILE__ ) )
thats the func in case anyone was askin. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #3 on Thu 18 Jan 2007 04:34 PM (UTC) |
| Message
| | Yes, that definitely sounds like a problem with not terminating the string. Is the first part of these bad lines valid? Again that would give a very good hint as to where you should be looking for the culprit. |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #4 on Fri 19 Jan 2007 12:35 AM (UTC) |
| Message
| | ok upon further review it looks like the garbage might be getting sent from the function PERROR. i grepped and found about a hundred matches, so the hunt begins. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #5 on Fri 19 Jan 2007 12:42 AM (UTC) |
| Message
| | Well, like I said, the best thing to do is look at the prefix of the line. Find the part that's not garbage. Search for that, and see where the string is generated. If the point of generation is not broken, simply follow all functions it gets passed through. That will get you the culprit fairly quickly. This assumes that the first part of the line isn't garbage as well; if it is then you have other concerns because you're printing out a purely garbage string somewhere. |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #6 on Fri 19 Jan 2007 12:54 AM (UTC) |
| Message
| | i rerouted PERROR to my log_string function and the junk still got printed and no line numbers got printed. so i commented out log_string again with everyhting being rerouted there nothing should be getting printed in theory, but the junk is still being printed. so i am back to square one, and have no clue where it is coming from. and it is nonsensical, nothin leads me to where it might be coming from. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #7 on Fri 19 Jan 2007 01:17 AM (UTC) |
| Message
| Could you please answer my question: is or is not the first part of the line something you expect to see?
As for the rest, well, all I can say is grep for things like:
printf
fprintf
warn
error
perror
etc.
and make sure that everything looks like it should be there. If you comment out **all** of those lines, and you still are getting stuff, well, you need to look more! :-)
Have you tried using valgrind? It's a very good tool for this kind of problem.
There's a program you can run call strace that traces all system calls a program makes. You'll get a lot of uninteresting information, but you will also get to see which call is being made to print stuff to the screen. |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #8 on Fri 19 Jan 2007 03:22 AM (UTC) |
| Message
| | i am not trying to rude but if the stuff being printed was interrupting that was supposed to be being printed to the logfiles, i would have simply gone to that section of the code. unfortunately wolfpaw are morons, i sent them numerous emails about getting valgrind installed and they never responded, so that is a dead alley. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #9 on Fri 19 Jan 2007 07:05 AM (UTC) |
| Message
| Well, ok, but you should have just said straight off that there was no interruption. :)
Anyhow, you can try using strace as I mentioned which will list the system calls. (ltrace does the same thing but for dynamic links e.g. the C runtime library) This is not ideal as it does not give you the line of code that made the system call, however, it will at least tell you which system calls you should be looking for in the code.
I mean, you claim to have commented out every single line that prints something, and yet stuff is still being printed, so something was missed somewhere. These diagnostic tools can help you pinpoint what was called where.
Here is some sample output running ltrace on my MUD:
vsnprintf("---------------------[ Boot Log "..., 4096, "---------------------[ Boot Log "..., 0xff976ba4) = 53
ctime(0x82a2ec4) = "Fri Jan 19 00:03:25 2007\n"
fprintf(0xf7dde560, "%s :: %s\n", "Fri Jan 19 00:03:25 2007", "[*****] BOOT: ------------------"...Fri Jan 19 00:03:25 2007 :: [*****] BOOT: ---------------------[ Boot Log ]--------------------
) = 96
fclose(0x82bacf8) = 0
fopen("../system/boot.txt", "a") = 0
fopen("/dev/null", "r") = 0x82bacf8
ctime(0x82a2ec4) = "Fri Jan 19 00:03:25 2007\n"
fprintf(0xf7dde560, "%s :: %s\n", "Fri Jan 19 00:03:25 2007", "Loading commands"Fri Jan 19 00:03:25 2007 :: Loading commands
) = 45
fopen("../system/commands.dat", "r") = 0
vsprintf(0xff975b15, 0x826feb2, 0xff976b84, 0x8124067, 0xff975b20) = 24
ctime(0x82a2ec4) = "Fri Jan 19 00:03:25 2007\n"
fprintf(0xf7dde560, "%s :: %s\n", "Fri Jan 19 00:03:25 2007", "[*****] BUG: Cannot open command"...Fri Jan 19 00:03:25 2007 :: [*****] BUG: Cannot open commands.dat
) = 66
fclose(0x82bacf8) = 0
fopen("../system/bugs.txt", "a") = 0
fopen("/dev/null", "r") = 0x82bacf8
exit(0 <unfinished ...>
|
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #10 on Fri 19 Jan 2007 08:40 AM (UTC) Amended on Fri 19 Jan 2007 08:47 AM (UTC) by Gohan_TheDragonball
|
| Message
| ok i ran strace on my mud and heres what i got:
open("../system/REQUESTS", O_RDONLY|O_NONBLOCK) = 7
write(1, "if\n\rendif\n\rndif\n\rendif\n\rndif\n\ren"..., 4096) = 4096
fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
read(9, 0x831c188, 8192) = -1 EAGAIN (Resource temporarily unavailable)
fcntl64(9, F_SETFL, O_RDWR) = 0
i can't tell where the call is coming from though. i turned off the requests pipe and it seemed to remove the problem. but i can't figure out how the requests pipe is writing this crap to the logfiles. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #11 on Fri 19 Jan 2007 09:10 AM (UTC) |
| Message
| OK. The line
write(1, "if\n\rendif\n\rndif\n\rendif\n\rndif\n\ren"..., 4096)
is a problem. The '1' as the first argument means file descriptor #1, which is standard output. The second argument is the string to write. The third argument is how much to write. Somehow, you are printing out that string very shortly after opening the requests pipe. ("that string" being something basically random from memory)
What you need to do is to trace the code starting at that open syscall -- the one that opens the request pipe -- and look for *any* line that could *possibly* issue a call down the line to the write system call. Note that functions like printf are not system calls but library calls; basically you need to look for anything that prints anything anywhere.
If you don't feel like tracing line by line, you can try putting in bogus calls to the "open" system call, and narrow down where that write call is being made. (This is basically printf debugging, but using strace! Whee!) |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #12 on Mon 22 Jan 2007 01:17 AM (UTC) |
| Message
| | well i finally found the problem, well at least the function which is the source of the problem. when i turned off the webwho updater, which is located in the requests part, the crap stopped coming into my logs. so its somewhere in my WHO command. now the hard part of tracking it down. | | Top |
|
| Posted by
| Gohan_TheDragonball
USA (183 posts) Bio
|
| Date
| Reply #13 on Wed 24 Jan 2007 09:01 AM (UTC) |
| Message
| | turned out to not be that hard, looks like when i was adding in my sql stuff i forgot an 's' and put printf instead of sprintf. | | Top |
|
| Posted by
| David Haley
USA (3,881 posts) Bio
|
| Date
| Reply #14 on Wed 24 Jan 2007 09:09 AM (UTC) |
| Message
| | How come you didn't find this when grepping for printf? :P |
David Haley aka Ksilyan
Head Programmer,
Legends of the Darkstone
http://david.the-haleys.org | | Top |
|
The dates and times for posts above are shown in Universal Co-ordinated Time (UTC).
To show them in your local time you can join the forum, and then set the 'time correction' field in your profile to the number of hours difference between your location and UTC time.
40,675 views.
This is page 1, subject is 2 pages long: 1 2
![[Next page]](/images/thin_next.gif)
It is now over 60 days since the last post. This thread is closed.
Refresh page
![[Go to top]](/images/gototop.gif)
top