[SOLVED] C apparent segfault in fprintf

ccj4467 · 03-09-2022, 10:47 AM

I have been developing a program that queries remote servers for a file and receiving the a file. I have it setups to run as a daemon. The program runs for 10 to 14 hours before it gets a segfault. I am totally confused as it appears to be happening in the fprintf function. The particular call gets executed multiple times every 10 minutes( it is in a logging routine ). Can anybody give me a clue as to what is going on?

Code:

System details:
Ubuntu 20.04 Server LTS
gcc version:  9.3.0
libc version:  2.31

gdb output:

Code:

Core was generated by `./sysmond_vfprintf_debug receive'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __vfprintf_internal (s=0x0, format=0x56458e7315b8 "%02d/%02d/%04d %02d:%02d:%02d: ", ap=ap@entry=0x7fff3b5b37d0, 
    mode_flags=mode_flags@entry=0) at vfprintf-internal.c:1328
1328	vfprintf-internal.c: No such file or directory.
(gdb) bt
#0  __vfprintf_internal (s=0x0, format=0x56458e7315b8 "%02d/%02d/%04d %02d:%02d:%02d: ", ap=ap@entry=0x7fff3b5b37d0, 
    mode_flags=mode_flags@entry=0) at vfprintf-internal.c:1328
#1  0x00007f2f47626c9a in __fprintf (stream=<optimized out>, format=<optimized out>) at fprintf.c:32
#2  0x000056458e7302a5 in log_message (log_file=0x56458ffee4d0 "/var/log/sysmon_xfer.log", 
    format=0x56458e731516 "Total bytes received: %ld") at sysmond_vfprintf_debug.c:594
#3  0x000056458e72fb1e in receiver () at sysmond_vfprintf_debug.c:431
#4  0x000056458e72ea12 in main (argc=2, argv=0x7fff3b5b4fc8) at sysmond_vfprintf_debug.c:146
(gdb) frame 2
#2  0x000056458e7302a5 in log_message (log_file=0x56458ffee4d0 "/var/log/sysmon_xfer.log", 
    format=0x56458e731516 "Total bytes received: %ld") at sysmond_vfprintf_debug.c:594
594	   fprintf ( fd, "%02d/%02d/%04d %02d:%02d:%02d: ", timeinfo->tm_mon+1, timeinfo->tm_mday, timeinfo->tm_year+1900,
(gdb) list
589	
590	   fd = fopen ( log_file, "a" );
591	
592	   time ( &timer );
593	   timeinfo = localtime ( &timer );
594	   fprintf ( fd, "%02d/%02d/%04d %02d:%02d:%02d: ", timeinfo->tm_mon+1, timeinfo->tm_mday, timeinfo->tm_year+1900,
595	                                                    timeinfo->tm_hour, timeinfo->tm_min, timeinfo->tm_sec );
596	
597	   va_start ( args, format );
598	   vfprintf ( fd, format, args );
(gdb) print timeinfo->tm_mon
$1 = 2
(gdb) print timeinfo->tm_mday
$2 = 9
(gdb) print timeinfo->tm_year
$3 = 122
(gdb) print timeinfo->tm_hour
$4 = 4
(gdb) print timeinfo->tm_min
$5 = 32
(gdb) print timeinfo->tm_sec
$6 = 1
(gdb)

sundialsvcs · 03-09-2022, 12:30 PM

I don't even need to look at this. Locate the statement and examine carefully what the format-string tells the function to expect. Then, find out which one of the subsequent parameters doesn't match this. If possible, set a breakpoint right before the function is called and examine each one of the parameter values. One of these is being used as "a pointer to something" (no doubt a 'string'), and the value is bogus.

NevemTeve · 03-09-2022, 01:00 PM

Never forget to check the return value of fopen.

Code:

errno= 0;
fd= fopen(log_file, "a");
if (!fd) {
    int ern= errno;

    fprintf(stderr, "fopen(\"%s\",\"a\") error errno=%d: %s\n",
        log_file, ern, strerror(ern));
    return;
}

dugan · 03-09-2022, 02:39 PM

Just backing up the last guy. Your gdb output doesn't print fd.

rtmistler · 03-09-2022, 02:51 PM

Quote:

Originally Posted by dugan

Just backing up the last guy. Your gdb output doesn't print fd.

But while in GDB, you can examine that.

Psst, see my signature for info about core dump analysis using GDB. But be aware, as others have indicated, it's a diagnostic tool, not something which serves up an answer.

Examine variables, likely one of them is invalid when the code was expecting otherwise.

ccj4467 · 03-09-2022, 03:17 PM

I guess I should have posted the entire function code

Code:

void log_message ( char *log_file, char *format, ... )
{
   FILE *fd;
   time_t timer;
   struct tm *timeinfo;
   struct passwd *pwd;
   uid_t uid;
   gid_t gid;
   va_list args;

   if ( !(fd = fopen (log_file, "r")) )
   {
      fd = fopen ( log_file, "w" );
      fclose ( fd );
      chmod ( log_file, S_IRUSR|S_IWUSR|S_IRGRP );
      if ( (pwd = getpwnam( "www-data" )) == NULL )
      {
         uid = 0;
         gid = 0;
      }
      else
      {
         uid = pwd->pw_uid;
         gid = pwd->pw_gid;
      }
      chown ( log_file, uid, gid );
   }

   fd = fopen ( log_file, "a" );

   time ( &timer );
   timeinfo = localtime ( &timer );
   fprintf ( fd, "%02d/%02d/%04d %02d:%02d:%02d: ", timeinfo->tm_mon+1, timeinfo->tm_mday, timeinfo->tm_year+1900,
                                                    timeinfo->tm_hour, timeinfo->tm_min, timeinfo->tm_sec );

   va_start ( args, format );
   vfprintf ( fd, format, args );
   va_end ( args );
   fprintf ( fd, "\n" );

   fflush ( fd );
   fclose ( fd );

}

Anyway, value of fd from gdb

Code:

(gdb) print fd
$1 = (FILE *) 0x0

Not sure if that is correct but it looks like it might not be.
All I know is the particular line does get written into the log file.

I have been using this logging function for years and have never had a problem before.

One other item I have noticed that the memory usage via pmap increases by 128Kbytes every 4-6 hours

dugan · 03-09-2022, 04:33 PM

Well, then it's exactly what was speculated. GDB shows that fd is null. That means fopen returned null, and you needed to check whether it returned null.

GazL · 03-09-2022, 05:20 PM

You're overwriting fd with a new stream from the fopen( blah, "a") without closing the original stream from the fopen( blah, "r"). Eventually, you're going to run out of file-descriptors.

ccj4467 · 03-09-2022, 09:11 PM

Doh, what a stupid mistake. I was really looking in the wrong place. Good catch. Thank you!

I should add the section with the initial fopen, chmod and chown was something I just added because of the security constraints on the new systems I am working on.
Should have looked at that first thing.

ccj4467 · 03-10-2022, 02:36 PM

Many thanks to GazL. I guess I just needed another set of eyes on the problem. The problem is solved and it was because I was being lazy and just cut and pasting code. I know better than that. Thanks again for everyone's help.

GazL · 03-10-2022, 03:41 PM

You're welcome, but I just put the last bits of the puzzle together. Neve' pointed the way initially.

The distance that comes with a fresh set of eyes is often a huge advantage. It's so easy to tunnel-vision yourself into thinking one specific way when you've been looking at a problem for any length of time. I suspect we've all been there. I certainly have.