win32utils devel - May 2006 - win32/service... still with problems.

Hello list,

In my quest to get Mongrel working as service for win32, found some
problems with win32/service that make it impossible to solve.

Attached is the simplest service script I could do with ruby, which
depends on win32/service.

I found that doing anything complex in service_stop (killing threads,
doing file handling, even sleeping for 0.25 seconds). crash the
service with backtraces (of the service) like this:

dead_service.rb:119:in `service_main'': uninitialized constant RUNNING
(NameError)
	from U:/Programming/Sources/ruby/try/dead_service.rb:131

Just commenting the sleep command solves that problem, but leaves
other issues there... like the impossible task of killing running
threads (from a ThreadGroup, as example).

Also, removing the while state == RUNNING loop solves the sleep and
file handling issues, but still exist problems with already running
threads that must be killed/stopped.

Or: I''m doing something wrong (in which case please enlighten me) or
there is something wrong on how the threading model is implemented?
(and the mix of C threads with ruby threads).

Thanks in advance for your time,

Regards,

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dead_service.rb
Type: application/octet-stream
Size: 3360 bytes
Desc: not available
Url :
http://rubyforge.org/pipermail/win32utils-devel/attachments/20060522/1270f741/attachment.obj

> -----Original Message-----
> From: win32utils-devel-bounces at rubyforge.org 
> [mailto:win32utils-devel-bounces at rubyforge.org] On Behalf Of 
> Luis Lavena
> Sent: Monday, May 22, 2006 10:01 AM
> To: win32utils-devel at rubyforge.org
> Subject: [Win32utils-devel] win32/service... still with problems.
> 
> 
> Hello list,
> 
> In my quest to get Mongrel working as service for win32, 
> found some problems with win32/service that make it 
> impossible to solve.
> 
> Attached is the simplest service script I could do with ruby, 
> which depends on win32/service.
> 
> I found that doing anything complex in service_stop (killing 
> threads, doing file handling, even sleeping for 0.25 
> seconds). crash the service with backtraces (of the service) 
> like this:
> 
> dead_service.rb:119:in `service_main'': uninitialized constant
RUNNING
> (NameError)
> 	from U:/Programming/Sources/ruby/try/dead_service.rb:131
Where does this backtrace go?  I don''t see anything like that when I
tail the log file:

2006-05-22 10:38:48 - ** Dead Simple Service starting...
2006-05-22 10:38:50 - ** Done initialization.
2006-05-22 10:38:50 - Entering Service Main
do nothing!

I have no idea why you''re seeing that error.  I don''t see it.

There are a couple of issues with your script (which may actually be
issues with our sample script).  You should re-raise exceptions or exit
when one of the commands fails.  For example:

rescue Win32::ServiceError => err
   puts "There was a problem installing the service:"
   puts err
end

Should be:

rescue Win32::ServiceError => err
   puts "There was a problem installing the service:"
   puts err
   raise
end

Otherwise, you''ll be dropping into a later part of the script, which is
probably not what you want.
 
> Or: I''m doing something wrong (in which case please enlighten 
> me) or there is something wrong on how the threading model is 
> implemented? (and the mix of C threads with ruby threads).
I think one thing you''ll want to avoid is having a Daemon calling
methods outside of itself, as you''re doing with the
''log'' method there,
which may be the source of the problem.  Although the example we ship
with the win32-service package mixes the command line stuff with the
actual Daemon code, in practice I separate the actual Daemon class and
the controller script into separate files.  It''s a good sanity
preserver
I''ve found.

Dan


This communication is the property of Qwest and may contain confidential or
privileged information. Unauthorized use of this communication is strictly 
prohibited and may be unlawful.  If you have received this communication 
in error, please immediately notify the sender by reply e-mail and destroy 
all copies of the communication and any attachments.

On 5/22/06, Berger, Daniel <Daniel.Berger at qwest.com>
wrote:
>
> Where does this backtrace go?  I don''t see anything like that when
I
> tail the log file:
>
> 2006-05-22 10:38:48 - ** Dead Simple Service starting...
> 2006-05-22 10:38:50 - ** Done initialization.
> 2006-05-22 10:38:50 - Entering Service Main
> do nothing!
>
> I have no idea why you''re seeing that error.  I don''t see
it.
>
Actually, after the do nothing! you should see "Leaving Service Main",
which don''t happen (don''t see why in your setup
don''t, but here it do,
winxp).
> There are a couple of issues with your script (which may actually be
> issues with our sample script).  You should re-raise exceptions or exit
> when one of the commands fails.  For example:
>
[...]
> Otherwise, you''ll be dropping into a later part of the script,
which is
> probably not what you want.
The command part don''t affect the Daemon part, both are discarted by
the ARGV[0] and the ENV["HOMEDRIVE"]!=nil

Anyway, followed your suggestions (split the ctrl and the daemon),
with the same result:

2006-05-22 14:19:50 - ** Dead Simple Service starting...
2006-05-22 14:19:52 - ** Done initialization.
2006-05-22 14:19:52 - Entering Service Main
2006-05-22 14:20:00 - Stop Signal received.
do nothing!
U:/Programming/Sources/ruby/try/dead_service.rb:45:in `service_stop'':
uninitialized constant RUNNING (NameError)
	from U:/Programming/Sources/ruby/try/dead_service.rb:52:in
`service_main''
	from U:/Programming/Sources/ruby/try/dead_service.rb:63
> I think one thing you''ll want to avoid is having a Daemon calling
> methods outside of itself, as you''re doing with the
''log'' method there,
> which may be the source of the problem.  [...]
Removing the call to the outside function (donothing) solved the
uninitialized constant problem, but the "Leaving Service Main" never
shows, so looks like was terminated previously (no safe cleanup).

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dead_service.rb
Type: application/octet-stream
Size: 1564 bytes
Desc: not available
Url :
http://rubyforge.org/pipermail/win32utils-devel/attachments/20060522/8f9132b2/attachment.obj
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dead_service_ctrl.rb
Type: application/octet-stream
Size: 1972 bytes
Desc: not available
Url :
http://rubyforge.org/pipermail/win32utils-devel/attachments/20060522/8f9132b2/attachment-0001.obj

On 5/22/06, Luis Lavena <luislavena at gmail.com> wrote:
[snip]

Also, I''ll like to add the randomness of the problem:

2006-05-22 14:28:17 - ** Dead Simple Service starting...
2006-05-22 14:28:19 - ** Done initialization.
2006-05-22 14:28:19 - Entering Service Main
2006-05-22 14:28:21 - Stop Signal received.
2006-05-22 14:28:28 - ** Dead Simple Service starting...
2006-05-22 14:28:30 - ** Done initialization.
2006-05-22 14:28:30 - Entering Service Main
2006-05-22 14:28:35 - Stop Signal received.
2006-05-22 14:28:37 - Leaving Service Main


Started and stopped the service 2 times, the first left on
service_stop, without cleanup/correct exit of service_main.

The second time left ok, exiting the loop.

Is a 50-50 chance of success with this?

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi

> -----Original Message-----
> From: win32utils-devel-bounces at rubyforge.org 
> [mailto:win32utils-devel-bounces at rubyforge.org] On Behalf Of 
> Luis Lavena
> Sent: Monday, May 22, 2006 11:27 AM
> To: Development and ideas for win32utils projects
> Subject: Re: [Win32utils-devel] win32/service... still with problems.
<snip>
> Actually, after the do nothing! you should see "Leaving 
> Service Main", which don''t happen (don''t see why in
your
> setup don''t, but here it do, winxp).
I didn''t see it because your ''log'' method was defined
outside of your
daemon class.  In fact, your script works just fine once you move those
methods within the Daemon class itself.  Attached is the script I''m
using.  Here was the output:

2006-05-22 11:58:09 - ** Dead Simple Service starting...

2006-05-22 11:58:11 - ** Done initialization.

2006-05-22 11:58:11 - Entering Service Main
do nothing!

2006-05-22 11:58:49 - Leaving Service Main

(I added some spaces there since Outlook is joining them into a single
string for some reason).

Hope that helps.

Dan


This communication is the property of Qwest and may contain confidential or
privileged information. Unauthorized use of this communication is strictly 
prohibited and may be unlawful.  If you have received this communication 
in error, please immediately notify the sender by reply e-mail and destroy 
all copies of the communication and any attachments.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dead_service.rb
Type: application/octet-stream
Size: 3515 bytes
Desc: dead_service.rb
Url :
http://rubyforge.org/pipermail/win32utils-devel/attachments/20060522/06bd0024/attachment-0001.obj

On 5/22/06, Berger, Daniel <Daniel.Berger at qwest.com>
wrote:
> I didn''t see it because your ''log'' method was
defined outside of your
> daemon class.  In fact, your script works just fine once you move those
> methods within the Daemon class itself.  Attached is the script
I''m
> using.  Here was the output:
>
> 2006-05-22 11:58:09 - ** Dead Simple Service starting...
>
> 2006-05-22 11:58:11 - ** Done initialization.
>
> 2006-05-22 11:58:11 - Entering Service Main
> do nothing!
>
> 2006-05-22 11:58:49 - Leaving Service Main
>
> (I added some spaces there since Outlook is joining them into a single
> string for some reason).
>
> Hope that helps.
>
> Dan
Daniel, you tried more than 1 start/stop cycles?

In the first run, everything worked ok, but several tries after it,
showed that it works "sometimes" and other don''t. (no matter
if you
left the service running for 1 second or 10 minutes)

Even with these modifications, not always work.

I find useless the service_stop method... sometimes it work, other
don''t. Moving the cleanup code from it to the service_main method
(after the loop) also not always work, if the method is in the wrong
point in time (like not evaluating state == RUNNING in that exact
moment), the thread that runs service_main get terminated by the
service.so

If you see the attached version, service_stop will try to raise the
Interrupt exception so the runner thread gets terminated.

that won''t happen...

if you move these 2 lines to service_main and comment service_stop, it
will work.

But if you add code that need more time to of execution, the thread
will get terminated:

	def service_main
		log "Entering Service Main"
		
		while state == RUNNING
			sleep 1
		end

		log "Exiting main loop."
		@runner.raise Interrupt

		# slower cleanup...
		sleep 3

		log "Leaving Service Main"
	end


"Leaving Service Main" will never show up in the log, nor will wait 3
seconds.

Maybe I don''t get it, but I created a framework for service in
FreeBASIC and also C++, with custom options for the events (onInit,
Main, onStop, onShutdown).

And these worked ok, but found that service.c:Service_Ctrl first
execute the associated method with the EventArray and then set the
service in a PENDING state, which 2 microseconds later get terminated
by the evaluation of the controlcode and the set of StopEvent...

So: slow code in service_stop make Service Manager think your service
hang. Evaluating state in service_main is useless because you need the
right timming (or luck) to evalaute it when was set, lucky enough
don''t get killed by the StopEvent raised...

I''m getting it wrong?

Please excuse my poor english (I try harder to express clearly what is
happening) but english is not my native/natural language.

Regards,

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dead_service.rb
Type: application/octet-stream
Size: 1735 bytes
Desc: not available
Url :
http://rubyforge.org/pipermail/win32utils-devel/attachments/20060522/55975998/attachment.obj

> -----Original Message-----
> From: win32utils-devel-bounces at rubyforge.org 
> [mailto:win32utils-devel-bounces at rubyforge.org] On Behalf Of 
> Luis Lavena
> Sent: Monday, May 22, 2006 12:38 PM
> To: Development and ideas for win32utils projects
> Subject: Re: [Win32utils-devel] win32/service... still with problems.
> 
> 
> On 5/22/06, Berger, Daniel <Daniel.Berger at qwest.com> wrote:
> > I didn''t see it because your ''log'' method
was defined
> outside of your 
> > daemon class.  In fact, your script works just fine once you move 
> > those methods within the Daemon class itself.  Attached is 
> the script 
> > I''m using.  Here was the output:
> >
> > 2006-05-22 11:58:09 - ** Dead Simple Service starting...
> >
> > 2006-05-22 11:58:11 - ** Done initialization.
> >
> > 2006-05-22 11:58:11 - Entering Service Main
> > do nothing!
> >
> > 2006-05-22 11:58:49 - Leaving Service Main
> >
> > (I added some spaces there since Outlook is joining them 
> into a single 
> > string for some reason).
> >
> > Hope that helps.
> >
> > Dan
> 
> Daniel, you tried more than 1 start/stop cycles?
Yes.  I ran a series of start/stops as fast as my little fingers would
let me.  No problem.
 
> In the first run, everything worked ok, but several tries 
> after it, showed that it works "sometimes" and other
don''t.
> (no matter if you left the service running for 1 second or 10 minutes)
When you say it didn''t work, do you mean that the the service_main or
service_stop hooks weren''t called?  Or some other error?

<snip>
> If you see the attached version, service_stop will try to 
> raise the Interrupt exception so the runner thread gets terminated.
Ok, I see the same behavior you mention - the service_stop handler
doesn''t get executed for some reason.  I think we''re back to
the thread
issues that Heesob mentioned in a previous post about this.

Heesob, care to weigh in?

Dan


This communication is the property of Qwest and may contain confidential or
privileged information. Unauthorized use of this communication is strictly 
prohibited and may be unlawful.  If you have received this communication 
in error, please immediately notify the sender by reply e-mail and destroy 
all copies of the communication and any attachments.

On 5/22/06, Berger, Daniel <Daniel.Berger at qwest.com> wrote:
[...]
> >
> > Daniel, you tried more than 1 start/stop cycles?
>
> Yes.  I ran a series of start/stops as fast as my little fingers would
> let me.  No problem.
>
Me too, I though was my pc, so dumped my p3 800mhz 512mb for a p4,
3.0ghz, 1gb... same results.
> > In the first run, everything worked ok, but several tries
> > after it, showed that it works "sometimes" and other
don''t.
> > (no matter if you left the service running for 1 second or 10 minutes)
>
> When you say it didn''t work, do you mean that the the service_main
or
> service_stop hooks weren''t called?  Or some other error?
the service_stop hook is called, but the code in there is no executed,
to the point the service stop responding and service manager report it
that the pipe has ended or an exception ocurred.
> > If you see the attached version, service_stop will try to
> > raise the Interrupt exception so the runner thread gets terminated.
>
> Ok, I see the same behavior you mention - the service_stop handler
> doesn''t get executed for some reason.  I think we''re back
to the thread
> issues that Heesob mentioned in a previous post about this.
>
> Heesob, care to weigh in?
>
I didn''t get the Heesob reply about this, maybe thats why I keep
asking the same :-P

On my freebasic (please, don''t think freebasic as old basica, is more
powerful than that, closer to c, but with basic syntax).

Anyway, on my framework, I solved this problem executing my Main
function (which will be service_main in the ruby side) in another
thread and wait for it to terminate until I destroy the events.

Also, wouldn''t be more correct report to the service manager that
SERVICE_STOP_PENDING (is stopping) before calling service_stop? in
service.c:78-83 thre is executed from EventHookHash prior reporting
the Service Manager that we received the stop signal and we are
stopping.

In service.c:114, dwControlCode is evaluated after setting the
ServiceState, and if it was CONTROL_STOP,  we set the Stop event,
something that exit service_main prematurely.

I don''t think service.c could be implemented as pure ruby (due
required native threads)... or not?

Please excuse my english (again), I try to explain better I could, but
is not easy due: complexity of the topic, and the self-learned nature
of the language.

Regards,

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi

Hi,

2006/5/23, Luis Lavena <luislavena at gmail.com>:
> On 5/22/06, Berger, Daniel <Daniel.Berger at qwest.com> wrote:
> [...]
> > >
> > > Daniel, you tried more than 1 start/stop cycles?
> >
> > Yes.  I ran a series of start/stops as fast as my little fingers would
> > let me.  No problem.
> >
> Me too, I though was my pc, so dumped my p3 800mhz 512mb for a p4,
> 3.0ghz, 1gb... same results.
>
> > > In the first run, everything worked ok, but several tries
> > > after it, showed that it works "sometimes" and other
don''t.
> > > (no matter if you left the service running for 1 second or 10
minutes)
> >
> > When you say it didn''t work, do you mean that the the
service_main or
> > service_stop hooks weren''t called?  Or some other error?
>
> the service_stop hook is called, but the code in there is no executed,
> to the point the service stop responding and service manager report it
> that the pipe has ended or an exception ocurred.
>
> > > If you see the attached version, service_stop will try to
> > > raise the Interrupt exception so the runner thread gets
terminated.
> >
> > Ok, I see the same behavior you mention - the service_stop handler
> > doesn''t get executed for some reason.  I think we''re
back to the thread
> > issues that Heesob mentioned in a previous post about this.
> >
> > Heesob, care to weigh in?
> >
> I didn''t get the Heesob reply about this, maybe thats why I keep
> asking the same :-P
>
I repeat the last answer.

As you know,the win32-service is multithreaded application.
But, Ruby''s sleep or select is not compatible with the Thread of
Windows.
While executing sleep or select in ruby code,the other thread cannot
do anything.

To workaround this stopping problem,

1. Use loop of short sleep insthead of long sleep.
ex) 10.times { sleep 1 } instead of sleep 10

2. Use nonblocking IO and socket.
> On my freebasic (please, don''t think freebasic as old basica, is
more
> powerful than that, closer to c, but with basic syntax).
>
> Anyway, on my framework, I solved this problem executing my Main
> function (which will be service_main in the ruby side) in another
> thread and wait for it to terminate until I destroy the events.
>
> Also, wouldn''t be more correct report to the service manager that
> SERVICE_STOP_PENDING (is stopping) before calling service_stop? in
> service.c:78-83 thre is executed from EventHookHash prior reporting
> the Service Manager that we received the stop signal and we are
> stopping.
>
> In service.c:114, dwControlCode is evaluated after setting the
> ServiceState, and if it was CONTROL_STOP,  we set the Stop event,
> something that exit service_main prematurely.
>
> I don''t think service.c could be implemented as pure ruby (due
> required native threads)... or not?
>
I tried but it would''t work for now.

The workaround of stopping problem for now is separate service control
process and working process.
In service_main, use system,fork or something create another ruby
program for working process and send kill to it when stop requested.
> Please excuse my english (again), I try to explain better I could, but
> is not easy due: complexity of the topic, and the self-learned nature
> of the language.
>
> Regards,
>
> --
> Luis Lavena
> Multimedia systems
> -
Regards,

Park Heesob

On 5/22/06, Heesob Park <phasis at gmail.com>
wrote:
> As you know,the win32-service is multithreaded application.
> But, Ruby''s sleep or select is not compatible with the Thread of
Windows.
> While executing sleep or select in ruby code,the other thread cannot
> do anything.
>
> To workaround this stopping problem,
>
> 1. Use loop of short sleep insthead of long sleep.
> ex) 10.times { sleep 1 } instead of sleep 10
>
> 2. Use nonblocking IO and socket.
>
Understand that, but wanted to "remark" that anything that take more
than 1 seconds to cleanup in service_main get terminated, no matter if
service_main finished or not.
> The workaround of stopping problem for now is separate service control
> process and working process.
> In service_main, use system,fork or something create another ruby
> program for working process and send kill to it when stop requested.
>
That will create 2 ruby process, one for the service (which will
depend of svchost.exe) and a child process...

If I send a kill signal, the child process will not cleanup properly,
something we must avoid in a good coded application.

For that approach, using srvany uses less memory than another ruby
process... (just loading the service.so and no other things we use 6MB
of memory).

Anyway, long live to the threading model of Ruby! (better yet, hate
Windows Threads).

Another workaround will be create a native (compiled) exe that
redirect stdin/stdout of the childprocess and execute the Cntrl-C to
finish it properly. I could do it with 30k exe and less than 1.5mb
footprint.
> Regards,
>
> Park Heesob
Thank you for the time you and Dan took answering my mails and testing
the scripts.

Regards,

-- 
Luis Lavena
Multimedia systems
-
Leaders are made, they are not born. They are made by hard effort,
which is the price which all of us must pay to achieve any goal that
is worthwhile.
Vince Lombardi