Re: [Wrapper-user] Windows Share debugging?

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

Steven,
I am sorry we did not notice right away.
>From your log file, it looks like you are running version 3.3.3 of the
Wrapper.
Network sharing was not added until 3.5.0.
http://wrapper.tanukisoftware.com/doc/english/prop-share-general.html
Most likely the server that is working either already has the mapping setup
or is using a newer version of the Wrapper.
Could you please try upgrading to 3.5.25 and try this again?

Thanks,
Leif


On Fri, Jul 11, 2014 at 2:34 PM, Alexandre Klein <
ale...@ta...> wrote:

> Hi Steve,
>
> In which situation you can see this problem:
> 1) when Windows boot?
> 2) once Windows is running?
>
> If situation #1:
> Can it be a problem in the start order of the services ?
>
> If situation #2:
> Can you try to run the Wrapper as a console ?
>
> Please let me know the result.
>
> In case you would like to send us some information that you don't want it
> to be public, please use the following email: su...@ta...
>
> Best regards,
> Alexandre Klein
>
> Alexandre Klein
> Tanuki Software, Ltd.
> 6-16-7-1001 Nishi-Kasai, Edogawa-ku
> Tokyo 134-0088 Japan
> Tel: +81-3-3878-3211
> Fax: +81-3-3878-0313
> http://www.tanukisoftware.com
>
>
> On Wed, Jul 9, 2014 at 10:20 PM, Elkind, Steven <ste...@mh...>
> wrote:
>
>> I'm using the wrapper indirectly - it's embedded in the Go continuous
>> delivery agents we're using on Windows, to make them runnable as a Windows
>> service.
>>
>> We're now trying to map a network share drive for our services, using the
>> following set of properties in wrapper-agent.conf, that I was able to find
>> the wrapper's online docs.  However, this works on only one of our three
>> Windows Server 2008R2 machines, but not on the other two.  I have no clue
>> as to why - even with wrapper.debug set to TRUE, there is no output in the
>> wrapper log concerning the share mapping - on either the successful system
>> or the other two.  The logs on successful and unsuccessful machines look
>> the same (sample from a log below my signature)
>>
>>
>>     # Mounting the shared drive for the build grid
>>     wrapper.debug=FALSE
>>     wrapper.share.1.location=\\sharehost.foo.com\BuildGridShare
>>     wrapper.share.1.target=P:
>>     wrapper.share.1.type=DISK
>>     wrapper.share.1.startup.premapped=CONTINUE
>>     wrapper.share.1.startup.max_retries=5
>>     wrapper.share.1.startup.retry_interval=10
>>
>> The service is configured to login in as the AD domain service user,
>> hence no username and password in the above (I don't want the password in
>> the clear on disk anyway).
>>
>> Does anyone have any ideas on how to troubleshoot this?  See below for
>> what I've done/tried so far.
>>
>> The product uses "Java Service Wrapper Standard Edition 3.3.3"
>>
>> More detail on some troubleshooting I've been doing:
>>
>> Our Windows admins claim that all three have the drive mapped for the
>> service user at boot time, and all in the same way.  The drive _is_
>> map-able - I can see the drive mounted on all three if I login to the
>> desktop as the service user, or I can map it manually when logged as
>> another user.  However, the Windows services running with the wrapper on
>> the two machines don't see it.
>>
>> I can also map it using the command "net use P:  \\sharehost.foo.com\BuildGridShare"
>> in a Windows batch script run by the Go Agent as a job, but many of the
>> jobs we have do not run batch scripts, instead directly invoking Ant,
>> Maven, or other tools without a script wrapping them - so that's not a
>> viable solution.
>>
>> I can find nothing in the Windows event log.
>>
>> Thanks in advance for any help....
>>
>> Steve Elkind
>> ste...@mh...
>>
>>
>>
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | Allocating a console for the
>> service.
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | Found console window.
>> STATUS | wrapper  | 2014/07/08 12:48:01 | --> Wrapper Started as Service
>> STATUS | wrapper  | 2014/07/08 12:48:01 | Java Service Wrapper Standard
>> Edition 3.3.3
>> STATUS | wrapper  | 2014/07/08 12:48:01 |   Copyright (C) 1999-2009
>> Tanuki Software, Ltd.  All Rights Reserved.
>> STATUS | wrapper  | 2014/07/08 12:48:01 |
>> http://wrapper.tanukisoftware.org
>> STATUS | wrapper  | 2014/07/08 12:48:01 |   Licensed to ThoughtWorks for
>> Cruise Agent
>> STATUS | wrapper  | 2014/07/08 12:48:01 |
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | Using tick timer.
>> DEBUG  | wrapperp | 2014/07/08 12:48:01 | server listening on port 32007.
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | Ping settings:
>> wrapper.ping.interval=5, wrapper.ping.interval.logged=1,
>> wrapper.ping.timeout=30
>> STATUS | wrapper  | 2014/07/08 12:48:01 | Launching a JVM...
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | command:
>> "D:\BuildTools\HarmonyGoProdAgent\jdk\bin\java"
>> -Done-jar.main.class=com.thoughtworks.cruise.agent.AgentBootstrapper
>> "-DJAVA_SYS_MON_TEMP_DIR=D:\BuildTools\HarmonyGoProdAgent\tmp"
>> -Djava.library.path="lib" -classpath
>> "lib/wrappertest.jar;lib/wrapper.jar;agent-bootstrapper.jar"
>> -Dwrapper.key="LiT74k9ZeQSYB64rkyC56s3QjKXhPcnQ" -Dwrapper.port=32007
>> -Dwrapper.jvm.port.min=31000 -Dwrapper.jvm.port.max=31999
>> -Dwrapper.debug="TRUE" -Dwrapper.pid=2848 -Dwrapper.version="3.3.3-st"
>> -Dwrapper.native_library="wrapper" -Dwrapper.service="TRUE"
>> -Dwrapper.cpu.timeout="10" -Dwrapper.jvmid=1
>> org.tanukisoftware.wrapper.WrapperSimpleApp com.simontuffs.onejar.Boot
>> im-go.mhf.mhc 8153
>> DEBUG  | wrapper  | 2014/07/08 12:48:01 | JVM started (PID=3584)
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> WrapperManager class initialized by thread: main  Using classloader:
>> sun.misc.Launcher$AppClassLoader@14fe5c
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager: Initializing...
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: JVM #1
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Running a
>> 32-bit JVM.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> Registering shutdown hook
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Using
>> wrapper
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Load
>> native library.  One or more attempts may fail if platform specific
>> libraries do not exist.  This is NORMAL and is only a problem if they all
>> fail.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:   Unable
>> to load native library: wrapper-windows-x86-32.dll  Cause: no
>> wrapper-windows-x86-32 in java.library.path
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:   Loaded
>> native library: wrapper.dll
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Calling
>> native initialization method.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperJNI Debug: Initializing
>> WrapperManager native library.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperJNI Debug: Java
>> Executable: D:\BuildTools\HarmonyGoProdAgent\jdk\bin\java.exe
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperJNI Debug: Windows
>> version: 6.1.7600
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Java
>> Version   : 1.6.0_17-b04 Java HotSpot(TM) Client VM
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Java VM
>> Vendor : Sun Microsystems Inc.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: OS Name
>>      : Windows Server 2008 R2
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: OS Arch
>>      : x86
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Control
>> event monitor thread started.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Startup
>> runner thread started.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> WrapperManager.start(org.tanukisoftware.wrapper.WrapperSimpleApp@6e3d60,
>> args["im-go.mhf.mhc", "8153"]) called by thread: main
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> Communications runner thread started.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Open
>> socket to wrapper...Wrapper-Connection
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31000
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31001
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31002
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31003
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31004
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31005
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31006
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Failed
>> attempt to bind using local port 31007
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Opened
>> Socket from 31008 to 32007
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Send a
>> packet KEY : LiT74k9ZeQSYB64rkyC56s3QjKXhPcnQ
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> handleSocket(Socket[addr=/127.0.0.1,port=32007,localport=31008])
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | accepted a socket from
>> 127.0.0.1 on port 31008
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | read a packet KEY :
>> LiT74k9ZeQSYB64rkyC56s3QjKXhPcnQ
>> DEBUG  | wrapper  | 2014/07/08 12:48:02 | Got key from JVM:
>> LiT74k9ZeQSYB64rkyC56s3QjKXhPcnQ
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | send a packet LOW_LOG_LEVEL : 1
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | send a packet PING_TIMEOUT : 30
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | send a packet PROPERTIES :
>> (Property Values)
>> DEBUG  | wrapper  | 2014/07/08 12:48:02 | Start Application.
>> DEBUG  | wrapperp | 2014/07/08 12:48:02 | send a packet START : start
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Received
>> a packet LOW_LOG_LEVEL : 1
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> LowLogLevel from Wrapper is 1
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Received
>> a packet PING_TIMEOUT : 30
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> PingTimeout from Wrapper is 30000
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Received
>> a packet PROPERTIES : (Property Values)
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: Received
>> a packet START : start
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug: calling
>> WrapperListener.start()
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperManager Debug:
>> WrapperListener.start runner thread started.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperSimpleApp Debug:
>> start(args) Will wait up to 2 seconds for the main method to complete.
>> INFO   | jvm 1    | 2014/07/08 12:48:02 | WrapperSimpleApp Debug:
>> invoking main method
>> 2014-07-08 12:48:02,685 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.agent.ServerAgentDownloader:112 - download started at
>> Tue Jul 08 12:48:02 EDT 2014
>> 2014-07-08 12:48:02,685 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.agent.ServerAgentDownloader:118 - got server response
>> at Tue Jul 08 12:48:02 EDT 2014
>> INFO   | jvm 1    | 2014/07/08 12:48:03 | WrapperManager Debug: Send a
>> packet START_PENDING : 5000
>> DEBUG  | wrapperp | 2014/07/08 12:48:03 | read a packet START_PENDING :
>> 5000
>> DEBUG  | wrapper  | 2014/07/08 12:48:03 | JVM signalled a start pending
>> with waitHint of 5000 millis.
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperManager Debug: Send a
>> packet START_PENDING : 5000
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperSimpleApp Debug:
>> start(args) end.  Main Completed=false, exitCode=null
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperManager Debug: returned
>> from WrapperListener.start()
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperManager Debug: Send a
>> packet STARTED :
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperManager Debug:
>> WrapperListener.start runner thread stopped.
>> INFO   | jvm 1    | 2014/07/08 12:48:04 | WrapperManager Debug: Startup
>> runner thread stopped.
>> DEBUG  | wrapperp | 2014/07/08 12:48:04 | read a packet START_PENDING :
>> 5000
>> DEBUG  | wrapper  | 2014/07/08 12:48:04 | JVM signalled a start pending
>> with waitHint of 5000 millis.
>> DEBUG  | wrapperp | 2014/07/08 12:48:04 | read a packet STARTED :
>> DEBUG  | wrapper  | 2014/07/08 12:48:04 | JVM signalled that it was
>> started.
>> DEBUG  | wrapperp | 2014/07/08 12:48:06 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:06 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:06 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:06 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:10 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:10 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:10 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:10 | read a packet PING : ping
>> 2014-07-08 12:48:13,264 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.agent.ServerAgentDownloader:121 - pipe the stream to
>> agent.jar atTue Jul 08 12:48:13 EDT 2014
>> 2014-07-08 12:48:13,279 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.util.PerfTimer:37 - Performance: Downloading new agent
>> with md5 signature: dKqUVC2fvLstTHvB8Ag6MQ== took 10609ms
>> 2014-07-08 12:48:13,279 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.agent.AgentBootstrapper:100 - Agent is version: 2.3.1
>> 2014-07-08 12:48:13,279 [WrapperSimpleAppMain] INFO
>>  thoughtworks.cruise.agent.AgentBootstrapper:101 - Launching Agent with
>> command: D:\BuildTools\HarmonyGoProdAgent\jdk\jre\bin\java -Xms128m
>> -Xmx256m "-DJAVA_SYS_MON_TEMP_DIR=D:\BuildTools\HarmonyGoProdAgent\tmp"
>> -Dagent.binary.md5=dKqUVC2fvLstTHvB8Ag6MQ== -jar agent.jar
>> https://im-go.mhf.mhc:8154/go/
>> DEBUG  | wrapperp | 2014/07/08 12:48:15 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:15 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:15 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:15 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:19 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:19 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:19 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:19 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:24 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:24 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:24 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:24 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:28 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:28 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:28 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:28 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:33 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:33 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:33 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:33 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:34 | send a packet
>> SERVICE_CONTROL_CODE : 4
>> DEBUG  | wrapper  | 2014/07/08 12:48:34 |   SERVICE_CONTROL_INTERROGATE
>> INFO   | jvm 1    | 2014/07/08 12:48:34 | WrapperManager Debug: Received
>> a packet SERVICE_CONTROL_CODE : 4
>> INFO   | jvm 1    | 2014/07/08 12:48:34 | WrapperManager Debug:
>> ServiceControlCode from Wrapper with code 4
>> DEBUG  | wrapperp | 2014/07/08 12:48:34 | send a packet
>> SERVICE_CONTROL_CODE : 4
>> DEBUG  | wrapper  | 2014/07/08 12:48:34 |   SERVICE_CONTROL_INTERROGATE
>> INFO   | jvm 1    | 2014/07/08 12:48:34 | WrapperManager Debug: Received
>> a packet SERVICE_CONTROL_CODE : 4
>> INFO   | jvm 1    | 2014/07/08 12:48:34 | WrapperManager Debug:
>> ServiceControlCode from Wrapper with code 4
>> DEBUG  | wrapperp | 2014/07/08 12:48:37 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:37 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:37 | WrapperManager Debug: Send a
>> packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:37 | read a packet PING : ping
>> DEBUG  | wrapperp | 2014/07/08 12:48:42 | send a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:42 | WrapperManager Debug: Received
>> a packet PING : ping
>> INFO   | jvm 1    | 2014/07/08 12:48:42 | WrapperManager Debug: Send a
>> packet PING : ping
>>
>