<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN" "http://www.w3.org/TR/REC-html40/loose.dtd">
<html><head><meta http-equiv="content-type" content="text/html; charset=UTF-8"></head><body style="font-family:Arial;font-size:14px"><p>
        hi Karl,<br><br>
        thanks for your reply, highly appreciated !<br><br>
        I checked:<br>
        - no CRON jobs are configured on this master server:<br>
        # ls -l /var/spool/cron/crontabs<br>
        total 0<br><br>
        - no AT jobs are configured on this master server:<br>
        # ls -l /var/spool/cron/at*<br>
        /var/spool/cron/atjobs:<br>
        total 0<br><br>
        /var/spool/cron/atspool:<br>
        total 0<br><br>
        - the logrotate-status shows that there was indeed some log-rotation going on at 6:25 Oct-18th:<br>
        # grep '2015-10-18-6' /var/lib/logrotate/status<br>
        "/var/log/auth.log" 2015-10-18-6:25:8<br>
        "/var/log/tlwebaccess.log" 2015-10-18-6:25:8<br>
        "/var/log/kern.log" 2015-10-18-6:25:8<br>
        "/var/log/vsmagent.log" 2015-10-18-6:25:8<br>
        "/var/log/vsmserver.log" 2015-10-18-6:25:8<br>
        "/var/log/apache2/error.log" 2015-10-18-6:25:8<br>
        "/var/log/tlwebadm.log" 2015-10-18-6:25:8<br><br>
        So, despite that I do not understand what is kicking off the logrotation, it is indeed happening, and was the likely cause of the SIGHUP/stop/start of the VSM processes.<br><br>
        However, indeed it remains a mistery why the "vsmserver" process did not correctly startup.<br>
        That timestamp in the /var/lib/logrotate/status file is 6:25:08<br>
        # grep vsmserver /var/lib/logrotate/status<br>
        "/var/log/vsmserver.log" 2015-10-18-6:25:8<br><br>
        At that timestamp, there is nothing in the logs indicating the stop of "vsmserver" , only at 06:27:00<br>
        # tail /var/log/vsmserver.log.1<br>
        2015-10-18 06:24:54 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:25:34 2015<br>
        2015-10-18 06:25:34 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:26:14 2015<br>
        2015-10-18 06:26:14 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:26:54 2015<br>
        2015-10-18 06:26:54 WARNING vsmserver.loadinfo: Connection refused (ECONNREFUSED) talking to VSM Agent 127.0.0.1:904 in request for loadinfo. Marking as down.<br>
        2015-10-18 06:26:55 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:27:35 2015<br>
        2015-10-18 06:27:00 INFO vsmserver: Got SIGTERM, signaling process to quit<br><br>
        Its startup is logged in a new file "/var/log/vsmserver.log"<br>
        #head /var/log/vsmserver.log<br>
        2015-10-18 06:27:03 INFO vsmserver: VSM Server version 4.4.0 build 4775 started<br>
        2015-10-18 06:27:03 INFO vsmserver.license: Updating license data from disk to memory<br>
        2015-10-18 06:27:03 INFO vsmserver.license: License summary: 10 concurrent users. Hard limit of 11 concurrent users.<br>
        2015-10-18 06:27:03 ERROR vsmserver: Unable to bind to ('', 9000) - address already in use. Is another VSM Server running?<br>
        2015-10-18 06:27:03 ERROR vsmserver: Exiting<br><br>
        So apparently the SIGTERM did not really stop the program ? Something had port 9000 still in use.<br><br>
        At this moment, I see that port TCP/9000 is in use by the "vsmserver" process :<br>
        # netstat -an|grep 9000<br>
        tcp        0      0 0.0.0.0:9000            0.0.0.0:*               LISTEN<br>
        # lsof +c 15 -i tcp:9000<br>
        COMMAND          PID USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME<br>
        python-thinlinc 3150 root    5u  IPv4 22446417      0t0  TCP *:9000 (LISTEN)<br>
        # ps -aef|grep 3150<br>
        root      3150     1  0 Oct18 ?        00:00:12 python-thinlinc /opt/thinlinc/sbin/vsmserver<br><br>
        When I send it a TERM signal, it seems to cleanly shutdown :<br><br>
        2015-10-20 19:06:18 INFO vsmserver: Got SIGTERM, signaling process to quit<br>
        2015-10-20 19:06:18 INFO vsmserver: Terminating. Have a nice day!<br><br>
        And port tcp/9000 is gone as well, as expected :<br>
        # lsof +c 15 -i tcp:9000<br>
        #<br><br>
        Startup works normally as well, as expected :<br>
        # service vsmserver start<br>
        Starting ThinLinc vsmserver<br>
        # lsof +c 15 -i tcp:9000<br>
        COMMAND          PID USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME<br>
        python-thinlinc 6907 root    5u  IPv4 24693741      0t0  TCP *:9000 (LISTEN)<br><br>
        However, during the 'logrotate' actions, it did not properly terminate...<br><br>
        => has anybody else encountered that same problem , where "vsmserver" did not properly 'terminate' ?<br><br>
        Rob<br><br><br><br><br><br><br>
        Quoting Karl Mikaelsson <<a href="mailto:derfian@cendio.se">derfian@cendio.se</a>>:</p>
<blockquote style="border-left:2px solid blue;margin-left:2px;padding-left:12px;" type="cite">
        Rob De Langhe <<a href="mailto:rob.de.langhe@twistfare.be">rob.de.langhe@twistfare.be</a>> writes:
        <blockquote style="border-left:2px solid blue;margin-left:2px;padding-left:12px;" type="cite">
                hi all,<br><br>
                I found that we could no longer login, because the "vsmserver" process on<br>
                the master was gone.<br>
                Checking its logs (/var/log/vsmserver.log), I found messages about its<br>
                dying, which I cannot recognize from anything in the documentation :<br><br>
                ...<br>
                2015-10-18 06:20:54 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:21:34 2015<br>
                2015-10-18 06:21:34 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:22:14 2015<br>
                2015-10-18 06:22:14 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:22:54 2015<br>
                2015-10-18 06:22:54 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:23:34 2015<br>
                2015-10-18 06:23:34 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:24:14 2015<br>
                2015-10-18 06:24:14 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:24:54 2015<br>
                2015-10-18 06:24:54 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:25:34 2015<br>
                2015-10-18 06:25:34 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:26:14 2015<br>
                2015-10-18 06:26:14 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:26:54 2015<br>
                2015-10-18 06:26:54 WARNING vsmserver.loadinfo: Connection refused (ECONNREFUSED) talking to VSM Agent 127.0.0.1:904 in request for loadinfo. Marking as down.<br>
                2015-10-18 06:26:55 DEBUG vsmserver: Scheduled load update of 127.0.0.1 at Sun Oct 18 06:27:35 2015<br>
                2015-10-18 06:27:00 INFO vsmserver: Got SIGTERM, signaling process to quit<br><br>
                Any idea what might have caused this ?<br><br>
                cheers and thanks all in advance for any feedbacks !<br>
                Rob</blockquote>
        Hi Rob,<br><br>
        That looks like a perfectly normal shutdown (i.e. service vsmserver<br>
        stop). Seeing as the vsmagent also stopped at approximately the same<br>
        time, I'm guessing that logrotate might have something to do with it<br>
        since that's the only thing I know that will restart vsmserver/vsmagent<br>
        in an standard install.<br><br>
        Are there any logs from cron or logrotate that can tell you why the<br>
        services aren't starting again?<br><br>
        regards,<br><br>
        --<br>
        Karl Mikaelsson     <a href="mailto:derfian@cendio.se">derfian@cendio.se</a><br>
        System Developer    +46 (0)13-290863Cendio AB           <a href="https://www.cendio.com/" target="_blank">https://www.cendio.com/</a></blockquote>
<br><br></body></html>