Logging (--log) implemented.
[mdsms.git] / mdsms.c
diff --git a/mdsms.c b/mdsms.c
index f0837c6..48eb8f5 100644 (file)
--- a/mdsms.c
+++ b/mdsms.c
@@ -5,6 +5,12 @@ static char rcsid[] ATTR_UNUSED = "$Id$";
 
 /*
  * $Log$
+ * Revision 1.3  1999/06/03 11:46:41  short
+ * Logging (--log) implemented.
+ *
+ * Revision 1.2  1999/06/03 10:38:52  short
+ * Implemented remaining communication timeouts and maximum retry count.
+ *
  * Revision 1.1.1.1  1999/05/26 13:06:26  short
  * First alpha release.
  *
@@ -28,6 +34,7 @@ static char rcsid[] ATTR_UNUSED = "$Id$";
 #include <fcntl.h>
 #include <errno.h>
 #include <signal.h>
+#include <time.h>
 
 #ifdef HAVE_GETOPT_LONG
 #include <getopt.h>
@@ -69,9 +76,9 @@ static int verbose
 static char *pname;
 static int dis_cleanup=0,devfd=-1;
 
-static char *phone,*body,*device,*lockfile,*smsc,*chartime,*cmdtime;
+static char *phone,*body,*device,*logname,*lockfile,*smsc,*maxretry,*readtime,*chartime,*cmdtime;
 static int readbody;
-static long chartimen=DEF_CHARTIME,cmdtimen=DEF_CMDTIME;
+static long maxretryn=DEF_MAXRETRY,readtimen=DEF_READTIME,chartimen=DEF_CHARTIME,cmdtimen=DEF_CMDTIME;
 static size_t bodylen;
 
 static char *devicename; /* path stripped */
@@ -79,6 +86,47 @@ static char lockreal[512],locked;
 
 static struct termios restios;
 static char restios_yes;
+static FILE *logf;
+
+static void vlogmsg(
+#ifndef PRINTF_WORKS_PM
+               char outerr,
+#endif
+               const char *fmt,va_list ap)
+{
+time_t stamp;
+char *ctm,*s;
+pid_t mypid=-1;
+char host[LINE_MAX];
+
+       if (!logf) return;
+       if (mypid==-1) {
+               mypid=getpid();
+               if (gethostname(host,sizeof(host))) strcpy(host,"<ERROR>");
+               }
+       time(&stamp);
+       ctm=ctime(&stamp);
+       if ((s=strchr(ctm,'\n'))) *s='\0';
+       fprintf(logf,"%s %s %s[%d]: ",ctm,host,pname,mypid);
+       vfprintf(logf,fmt,ap);
+#ifndef PRINTF_WORKS_PM
+       if (outerr) fputs(strerror(errno),logf);
+#endif
+       fputc('\n',logf);
+       fflush(logf);
+}
+
+static void logmsg(const char *fmt,...)
+{
+va_list ap;
+       va_start(ap,fmt);
+       vlogmsg(
+#ifndef PRINTF_WORKS_PM
+               0,
+#endif
+               fmt,ap);
+       va_end(ap);
+}
 
 static void error(const char *fmt,...)
 {
@@ -107,6 +155,13 @@ size_t fmtl;
                nfmt
 #endif
                ,ap);
+       if (fatal=='!') vlogmsg(
+#ifdef PRINTF_WORKS_PM
+               fmt
+#else
+               pm,nfmt
+#endif
+               ,ap);
        va_end(ap);
 
 #ifndef PRINTF_WORKS_PM
@@ -153,32 +208,39 @@ static void usage(void)
 %s\
 \n\
 Usage: " PACKAGE " [-c|--config <cfgfile>] [-d|--device <device>]\n\
-             [-l|--lockfile <lock>] [-s|--smsc <smsc #>]\n\
-             [-t|--chartime <msec>] [-T|--cmdtime <msec>]\n\
+             [-L|--log <file>]\n\
+             [-l|--lockfile <lock>] [-s|--smsc <smsc #>] [-m|--maxretry <#>]\n\
+             [-r|--readtime <sec>] [-t|--chartime <msec>] [-T|--cmdtime <msec>]\n\
              [-f|--file] [-v|--verbose] [-h|--help] [-V|--version]\n\
              <dest. phone> <msg text|msg filename>\n\
 \n\
  -c, --config\tRead this additional config file\n\
 \t\t(def. \"" CONFIG_MAIN "\" and \"$HOME" CONFIG_HOME "\")\n\
  -d, --device\tMobilDock on this serial device (def. \"" DEF_DEVICE "\")\n\
+ -L, --log\tLog all important messages to this file (def. \"" DEF_LOGNAME "\")\n\
  -l, --lockfile\tLock serial port by this file, \"%%s\" is basename of device\n\
 \t\t(def. \"%s\")\n\
  -s, --smsc\tUse this SMS Center number (def. query from Siemens A1)\n\
+ -m, --maxretry\tMaximum retries of any command before giving up (def. %d)\n\
+ -r, --readtime\tSeconds for maximum wait time for response (def. %ds)\n\
  -t, --chartime\tMilliseconds between each char on baud 19200 (def. %dms)\n\
  -T, --cmdtime\tMilliseconds before each whole AT command (def. %dms)\n\
  -f, --file\tRead contents of message from file instead\n\
  -v, --verbose\tIncrease verbosity level, more \"-v\"s give more messages\n\
  -h, --help\tPrint a summary of the options\n\
  -V, --version\tPrint the version number\n\
-\n",version,DEF_LOCKFILE,DEF_CHARTIME,DEF_CMDTIME);
+\n",version,DEF_LOCKFILE,DEF_MAXRETRY,DEF_READTIME,DEF_CHARTIME,DEF_CMDTIME);
        exit(EXIT_FAILURE);
 }
 
 static const struct option longopts[]={
 {"config"  ,1,0,'c'},
 {"device"  ,1,0,'d'},
+{"log"     ,1,0,'l'},
 {"lockfile",1,0,'l'},
 {"smsc"    ,1,0,'s'},
+{"maxretry",1,0,'m'},
+{"readtime",1,0,'r'},
 {"chartime",1,0,'t'},
 {"cmdtime" ,1,0,'T'},
 {"file"    ,0,0,'f'},
@@ -269,8 +331,11 @@ static struct {
        unsigned stamp;
        } optset[]={
                { 'd',&device   },
+               { 'L',&logname  },
                { 'l',&lockfile },
                { 's',&smsc     },
+               { 'm',&maxretry },
+               { 'r',&readtime },
                { 't',&chartime },
                { 'T',&cmdtime  },
        };
@@ -283,7 +348,7 @@ int i;
 
        seq++;
        optarg=NULL; optind=0; /* FIXME: Possible portability problem. */
-       while ((optc=getopt_long(argp,args,"c:d:l:s:t:T:fvhV",longopts,NULL))!=EOF) switch (optc) {
+       while ((optc=getopt_long(argp,args,"c:d:L:l:s:m:r:t:T:fvhV",longopts,NULL))!=EOF) switch (optc) {
                case 'c':
                        if (cfgstacki>=NELEM(cfgstack)) {
                                error("Looping (%d) during attempt to read config file \"%s\", break-out",NELEM(cfgstack),optind);
@@ -291,7 +356,7 @@ int i;
                                }
                        chk(cfgstack[cfgstacki++]=strdup(optarg));
                        break;
-               case 'd': case 'l': case 's': case 't': case 'T':
+               case 'd': case 'L': case 'l': case 's': case 'm': case 'r': case 't': case 'T':
                        for (i=0;i<NELEM(optset);i++)
                                if (optset[i].c==optc) {
                                        if (optset[i].stamp && optset[i].stamp!=seq) {
@@ -360,7 +425,7 @@ static const struct {
                {&device,"device for communication"},
 #endif
        };
-static char **emptycheck[]={&smsc,&body};
+static char **emptycheck[]={&logname,&smsc,&body};
 
 static void lockclose(int fd)
 {
@@ -420,8 +485,11 @@ remove:
        lockclose(fd);
 }
 
+static char wasalarm=0;
 static void sigalarm(int signo)
 {
+       signal(SIGALRM,(RETSIGTYPE (*)(int))sigalarm);
+       wasalarm=1;
        if (verbose>=1) error("Timed out");
 }
 
@@ -457,12 +525,18 @@ void *p;
        assert(catchdatal<=catchdatasiz);
 }
 
+static int retrycnt=0;
+static void retrying(void)
+{
+       if (++retrycnt>maxretryn) error("!Maximum command retry count (%d) exceeded",maxretryn);
+       if (verbose>=2) error(".Retrying phase, %d out of %d..",retrycnt,maxretryn);
+}
+
 static char *devcmd(const char *term,const char *catch,const char *send,...)
 {
 size_t l,bufl,terml,catchl,fragl,offs;
 char buf[LINE_MAX];
 ssize_t got;
-RETSIGTYPE (*origsig)(int);
 char *hit,*s;
 va_list ap;
 char errout;
@@ -471,8 +545,9 @@ char errout;
        if ((errout=(*send=='!'))) send++;
        if (0) {
 err:
+               alarm(0);
                if (errout) return(NULL);
-               if (verbose>=2) error(".Retrying last device command..");
+               retrying();
                }
        catchdatal=0;
        va_start(ap,send);
@@ -481,7 +556,6 @@ err:
        if (bufl>=sizeof(buf)-1) error("!Command too big (%d>%d)",bufl,sizeof(buf)-1);
        if (verbose>=2) error(".devcmd(send=\"%s\",term=\"%s\",catch=\"%s\")",buf,term,catch);
        buf[l]='\r'; buf[l+1]='\n';
-       origsig=signal(SIGALRM,(RETSIGTYPE (*)(int))sigalarm);
        for (offs=0,got=0;offs<bufl;offs++) {
                alarm(MAXSENDTIME);
                usleep((offs?chartimen:cmdtimen)*1000);
@@ -493,7 +567,6 @@ err:
                        error("Error forcing output of char %d of cmd \"%s\": %m",offs,buf);
                }
        alarm(0);
-       signal(SIGALRM,origsig);
        if (got!=bufl) {
                error("Wrote only %d of %d bytes of command: %m",got,bufl);
                goto err;
@@ -511,6 +584,8 @@ err:
        fragl=MAX(fragl,MAX(strlen(ERROR_SUBSTR1),strlen(ERROR_SUBSTR2)));
        bufl=0;
        record=NULL;
+       wasalarm=0;
+       alarm(readtimen);
        for (;;) {
                blocking(0);
                errno=0;
@@ -521,7 +596,8 @@ err:
                        got=read(devfd,buf+bufl,1);
                        }
                if (got<=0) {
-                       error("Could read device data (ret=%d): %m",got);
+                       if (wasalarm) error("!Maximum response timeout (%ds) exceeded",readtimen);
+                       error("Couldn't read device data (ret=%d): %m",got);
                        goto err;
                        }
                s=buf+bufl;
@@ -548,6 +624,7 @@ err:
                        if (record) record=buf+bufl;
                        }
                }
+       alarm(0);
        if (!catchdatal) {
                if (!catch) return(NULL);
                error("Data requested on command \"%s\" but no found after term \"%s\"",send,term);
@@ -698,6 +775,8 @@ static struct {
        long *ip;
        const char *const msg;
        } numarg[]={
+               { &maxretry,&maxretryn,"maxretry" },
+               { &readtime,&readtimen,"readtime" },
                { &chartime,&chartimen,"chartime" },
                { &cmdtime ,&cmdtimen ,"cmdtime"  },
        };
@@ -710,7 +789,7 @@ int i;
 unsigned fatal=0;
 struct termios tios;
 
-       pname=*argv;
+       if ((s=strrchr((pname=*argv),'/'))) pname=s+1;
        atexit(cleanup);
        signal(SIGTERM,(RETSIGTYPE (*)(int))cleanup);
        signal(SIGQUIT,(RETSIGTYPE (*)(int))cleanup);
@@ -739,6 +818,7 @@ char *buf=malloc(l+50);
                        free(*emptycheck[i]);
                             *emptycheck[i]=NULL;
                        }
+       if (!logname) logname=DEF_LOGNAME;
        if (!lockfile) lockfile=DEF_LOCKFILE;
        if (!device) device=DEF_DEVICE;
        if (body && readbody) {
@@ -788,11 +868,22 @@ size_t l=strlen(device);
                        }
                error("!Invalid format-character '%c' in lockfile format-string, only \"%%s\" allowed",*s);
                }
+       
+       if (*logname) {
+               if (!(logf=fopen(logname,"a")))
+                       error("!Error opening log \"%s\" for append: %m",logname);
+               logmsg("Starting up: " PACKAGE " " VERSION);
+               }
        genpdu();
                
        if (lockfile && *lockfile && VARPRINTF(lockreal,lockfile,devicename)>0) {
+time_t start,end;
                if (verbose>=1) error(".Locking device \"%s\" by \"%s\"..",device,lockreal);
+               time(&start);
                lockdevice();
+               time(&end);
+               if ((end-=start)>LOCKREPORT)
+                       logmsg("Device lock succeeded after %d seconds",end);
                }
        if (verbose>=1) error(".Opening device \"%s\"..",device);
        if ((devfd=open(device,O_RDWR|O_NDELAY))<0)
@@ -816,17 +907,19 @@ size_t l=strlen(device);
        if (tcsetattr(devfd,TCSANOW,&tios))
                error("!Unable to set initial termios device settings");
 
+       signal(SIGALRM,(RETSIGTYPE (*)(int))sigalarm);
        do {
                devcmd("",NULL,"\r\nAT\x1A");
                devcmd(NULL,NULL,"\r\nAT");
                smscset();
                devcmd(NULL,NULL,"\r\nAT+CMGF=0");
                devcmd("\n> ",NULL,"\r\nAT+CMGS=%d",(strlen(pdusmsc)+strlen(pdudata))/2);
-               s=devcmd(NULL,"\n+CMGS:","!%s%s\x1A",pdusmsc,pdudata);
+               if (!(s=devcmd(NULL,"\n+CMGS:","!%s%s\x1A",pdusmsc,pdudata))) retrying();
                } while (!s);
        while (isspace(*s)) s++;
        if (verbose>=1) error("\nMessage successfuly sent with MR: %s",s);
        devcmd(NULL,NULL,"\r\nAT");
 
+       logmsg("SMS sent (after %d retries), message reference: %s",retrycnt,s);
        return(EXIT_SUCCESS);
 }