Sporadic Web Sever Crash

UncleJohnsBand · 2008-07-14, 02:26 PM

About a month ago I started seeing sporadic Cassini web server crashes occur. Below is the log info from the gbpvrrecording service.

GBPVR Recording Service Log:

Code:
2008-07-14 00:13:52.285    VERBOSE    [14]    Hour is currently 0. Conversions will happen between 1:00 and 6:00

2008-07-14 00:44:52.261    VERBOSE    [14]    Hour is currently 0. Conversions will happen between 1:00 and 6:00

2008-07-14 01:15:52.253    VERBOSE    [14]    Hour is currently 1. Conversions will happen between 1:00 and 6:00

2008-07-14 01:46:52.229    VERBOSE    [14]    Hour is currently 1. Conversions will happen between 1:00 and 6:00

2008-07-14 02:17:02.191    VERBOSE    [14]    Hour is currently 2. Conversions will happen between 1:00 and 6:00

2008-07-14 02:48:02.167    VERBOSE    [14]    Hour is currently 2. Conversions will happen between 1:00 and 6:00

2008-07-14 03:18:07.144    VERBOSE    [14]    Hour is currently 3. Conversions will happen between 1:00 and 6:00

2008-07-14 03:48:22.120    VERBOSE    [14]    Hour is currently 3. Conversions will happen between 1:00 and 6:00

2008-07-14 04:18:27.660    VERBOSE    [14]    Hour is currently 4. Conversions will happen between 1:00 and 6:00

2008-07-14 04:48:28.093    VERBOSE    [14]    Hour is currently 4. Conversions will happen between 1:00 and 6:00

2008-07-14 04:56:22.612    ERROR    [11]    FATAL UNHANDLED EXCEPTION:: System.Net.Sockets.SocketException: Only one usage of each socket address (protocol/network address/port) is normally permitted

Server stack trace: 

   at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress)

   at System.Net.Sockets.Socket.Bind(EndPoint localEP)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg, Int32 methodPtr, Boolean fExecuteInContext)

Exception rethrown at [0]: 

   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)

   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at Cassini.xcdc6d50076d34ea4.x1eebd27da31f16e1(Object xf236ab116fb26f27)

   at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)

   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

System Event Log Entry:

Code:
Event Type:    Error

Event Source:    Service Control Manager

Event Category:    None

Event ID:    7034

Date:        7/14/2008

Time:        04:57:16 AM

User:        N/A

Computer:    DEN

Description:

The GB-PVR Recording Service service terminated unexpectedly.  It has done this 2 time(s).

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

App Event Log Entry #1:

Code:
Event Type:    Error

Event Source:    ASP.NET 2.0.50727.0

Event Category:    None

Event ID:    1334

Date:        7/14/2008

Time:        04:56:22 AM

User:        N/A

Computer:    DEN

Description:

An unhandled exception occurred and the process was terminated.

Application ID: GBPVRRecordingService.exe

Process ID: 3992

Exception: System.Net.Sockets.SocketException

Message: Only one usage of each socket address (protocol/network address/port) is normally permitted

StackTrace: 

Server stack trace: 

   at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress)

   at System.Net.Sockets.Socket.Bind(EndPoint localEP)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg, Int32 methodPtr, Boolean fExecuteInContext)

Exception rethrown at [0]: 

   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)

   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at Cassini.xcdc6d50076d34ea4.x1eebd27da31f16e1(Object xf236ab116fb26f27)

   at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)

   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

App Event Log Entry #2:

Code:
Event Type:    Error

Event Source:    .NET Runtime 2.0 Error Reporting

Event Category:    None

Event ID:    5000

Date:        7/14/2008

Time:        04:56:31 AM

User:        N/A

Computer:    DEN

Description:

EventType clr20r3, P1 gbpvrrecordingservice.exe, P2 1.0.3069.9824, P3 3a, P4 mscorlib, P5 2.0.0.0, P6 471ebc5b, P7 416b, P8 27, P9 system.net.sockets.socket, P10 NIL.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Data:

0000: 63 00 6c 00 72 00 32 00   c.l.r.2.

0008: 30 00 72 00 33 00 2c 00   0.r.3.,.

0010: 20 00 67 00 62 00 70 00    .g.b.p.

0018: 76 00 72 00 72 00 65 00   v.r.r.e.

0020: 63 00 6f 00 72 00 64 00   c.o.r.d.

0028: 69 00 6e 00 67 00 73 00   i.n.g.s.

0030: 65 00 72 00 76 00 69 00   e.r.v.i.

0038: 63 00 65 00 2e 00 65 00   c.e...e.

0040: 78 00 65 00 2c 00 20 00   x.e.,. .

0048: 31 00 2e 00 30 00 2e 00   1...0...

0050: 33 00 30 00 36 00 39 00   3.0.6.9.

0058: 2e 00 39 00 38 00 32 00   ..9.8.2.

0060: 34 00 2c 00 20 00 33 00   4.,. .3.

0068: 61 00 2c 00 20 00 6d 00   a.,. .m.

0070: 73 00 63 00 6f 00 72 00   s.c.o.r.

0078: 6c 00 69 00 62 00 2c 00   l.i.b.,.

0080: 20 00 32 00 2e 00 30 00    .2...0.

0088: 2e 00 30 00 2e 00 30 00   ..0...0.

0090: 2c 00 20 00 34 00 37 00   ,. .4.7.

0098: 31 00 65 00 62 00 63 00   1.e.b.c.

00a0: 35 00 62 00 2c 00 20 00   5.b.,. .

00a8: 34 00 31 00 36 00 62 00   4.1.6.b.

00b0: 2c 00 20 00 32 00 37 00   ,. .2.7.

00b8: 2c 00 20 00 73 00 79 00   ,. .s.y.

00c0: 73 00 74 00 65 00 6d 00   s.t.e.m.

00c8: 2e 00 6e 00 65 00 74 00   ..n.e.t.

00d0: 2e 00 73 00 6f 00 63 00   ..s.o.c.

00d8: 6b 00 65 00 74 00 73 00   k.e.t.s.

00e0: 2e 00 73 00 6f 00 63 00   ..s.o.c.

00e8: 6b 00 65 00 74 00 20 00   k.e.t. .

00f0: 4e 00 49 00 4c 00 0d 00   N.I.L...

00f8: 0a 00                     ..

***sub*** · 2008-07-14, 05:02 PM

Do you happen to know if that was first time the web server was used since the recording service was last started? or had it been used, but then left idle for several hours, and this was the first use after the idle period? or something else entirely?

UncleJohnsBand · 2008-07-14, 08:04 PM

sub Wrote:Do you happen to know if that was first time the web server was used since the recording service was last started? or had it been used, but then left idle for several hours, and this was the first use after the idle period? or something else entirely?

Something else entirely.....hadn't been used for several (>6) hours. The crash is all by itself....nothing is accessing it at this time.

Every time it crashes like this it appears to be early in the a.m. and I am not accessing anything. There is not a set time or frequency for it happening.....I had it happen a couple days in a row....then 3 days a-ok.....then two days in a row....that type of uncrackable pattern.

It is very strange.

***sub*** · 2008-07-14, 08:06 PM

I'm not quite sure how I'll track this one down.

Is that "early in the a.m" the same time as anything else? For example, EPG update?

UncleJohnsBand · 2008-07-14, 08:30 PM

sub Wrote:I'm not quite sure how I'll track this one down.

Is that "early in the a.m" the same time as anything else? For example, EPG update?

No....EPG happens mid-day.....12:00 p.m. The crash always seems to occur between 4:00 a.m. and 5:30 a.m. It leaves the two instances of PVRX2 running.....so I have to kill them, then restart the service.

There is nothing running at that time on the sytsem....I have some backup jobs that run that use the volume shadow copy feature but they finish an hour or so before the crash occurs.

I looked at system changes and the only thing of note is I switched from AVG 8.0 to Avast Home 4.8.........but I can't directly correlate that change to when this started.....I switched to Avast about 2 weeks before this started occurring.

***sub*** · 2008-07-14, 09:06 PM

For the next release I've put a try/catch around the area that encounters the problem. Its not entirely clear to me what is triggering this, but hopefully this will help the app handle it gracefully.

UncleJohnsBand · 2008-07-15, 02:23 AM

sub Wrote:For the next release I've put a try/catch around the area that encounters the problem. Its not entirely clear to me what is triggering this, but hopefully this will help the app handle it gracefully.

Great...thanks....sounds like a plan.

UncleJohnsBand · 2008-07-16, 10:53 PM

sub....it happend this a.m. while I was watching Tv before I left for work....posted log below....perhaps it will help....

Code:
2008-07-16 05:02:14.809    VERBOSE    [15]    Hour is currently 5. Conversions will happen between 1:00 and 6:00

2008-07-16 05:33:14.690    VERBOSE    [15]    Hour is currently 5. Conversions will happen between 1:00 and 6:00

2008-07-16 05:46:19.047    VERBOSE    [7]    RecordingFactory.LoadNext24HourEvents()

2008-07-16 05:46:19.047    VERBOSE    [7]    forcing refresh of next 24 hour events for capture source:3

2008-07-16 05:46:19.063    VERBOSE    [7]    Starting LiveTV for captureSource: 3 channel oid: 62  filename: 

2008-07-16 05:46:23.594    VERBOSE    [7]    RenewLease 3

2008-07-16 05:46:23.594    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:46:23.594    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:46:53.624    VERBOSE    [7]    RenewLease 3

2008-07-16 05:46:53.624    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:46:53.624    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:47:23.654    VERBOSE    [7]    RenewLease 3

2008-07-16 05:47:23.654    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:47:23.670    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:47:53.685    VERBOSE    [7]    RenewLease 3

2008-07-16 05:47:53.685    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:47:53.685    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:48:23.715    VERBOSE    [7]    RenewLease 3

2008-07-16 05:48:23.715    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:48:23.715    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:48:53.745    VERBOSE    [7]    RenewLease 3

2008-07-16 05:48:53.745    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:48:53.745    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:49:23.776    VERBOSE    [7]    RenewLease 3

2008-07-16 05:49:23.776    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:49:23.776    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:49:53.790    VERBOSE    [7]    RenewLease 3

2008-07-16 05:49:53.790    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:49:53.790    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:50:23.805    VERBOSE    [7]    RenewLease 3

2008-07-16 05:50:23.805    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:50:23.805    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:50:53.820    VERBOSE    [7]    RenewLease 3

2008-07-16 05:50:53.820    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:50:53.820    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:51:23.850    VERBOSE    [7]    RenewLease 3

2008-07-16 05:51:23.850    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:51:23.850    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:51:53.896    VERBOSE    [7]    RenewLease 3

2008-07-16 05:51:53.896    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:51:53.896    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:52:23.879    VERBOSE    [7]    RenewLease 3

2008-07-16 05:52:23.879    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:52:23.879    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:52:53.925    VERBOSE    [7]    RenewLease 3

2008-07-16 05:52:53.925    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:52:53.956    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:52:56.550    ERROR    [11]    FATAL UNHANDLED EXCEPTION:: System.Net.Sockets.SocketException: Only one usage of each socket address (protocol/network address/port) is normally permitted

Server stack trace: 

   at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress)

   at System.Net.Sockets.Socket.Bind(EndPoint localEP)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)

   at System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage msg, Int32 methodPtr, Boolean fExecuteInContext)

Exception rethrown at [0]: 

   at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)

   at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)

   at Cassini.x1b6b12494b043e38.x2dcc0ca8fed1d43b()

   at Cassini.xcdc6d50076d34ea4.x1eebd27da31f16e1(Object xf236ab116fb26f27)

   at System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(Object state)

   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(_ThreadPoolWaitCallback tpWaitCallBack)

   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(Object state)

2008-07-16 05:54:57.281    ERROR    [5]    Found expired lease. Stopping recording.

2008-07-16 05:54:57.390    VERBOSE    [7]    RenewLease 3

2008-07-16 05:54:57.390    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:54:57.515    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

2008-07-16 05:54:58.655    VERBOSE    [7]    RenewLease 3

2008-07-16 05:54:58.655    VERBOSE    [7]    forcing refresh of next 2 hour events for all capture sources

2008-07-16 05:54:58.655    VERBOSE    [7]    RenewLease finished (accepted - preview mode)

***sub*** · 2008-07-16, 10:56 PM

Try the attached patch and let me know.

UncleJohnsBand · 2008-07-16, 11:00 PM

sub Wrote:Try the attached patch and let me know.

Ok...loaded up....we'll see what happens.

Possibly Related Threads…
Thread		Author	Replies	Views	Last Post
	playback of recordings crash the application	paf077	9	2,388	2010-06-27, 12:57 PM Last Post: paf077
	Repeatable Windows crash with MagicPro ProHDTV Gold Digital Tuner?	jksmurf	2	1,565	2010-05-30, 10:58 PM Last Post: jksmurf
	Crash after language change	dodododic	10	3,021	2010-05-09, 06:19 PM Last Post: dodododic
	Crash on Launch	ydekmekji	1	1,398	2010-04-01, 05:23 AM Last Post: whurlston
	FF, REW crash on playback	jw100	8	2,128	2010-03-30, 04:02 PM Last Post: jw100
	Crash on startup: GBPVRX2.x0061b801bdf12d35	drdr6	2	1,426	2010-03-22, 10:42 PM Last Post: drdr6
	Hadu crash?	chrisevans1001	11	8,337	2010-03-19, 07:43 PM Last Post: chrisevans1001
	crash on stopping a recording	gunterhausfrau	2	1,340	2010-01-14, 06:38 PM Last Post: gunterhausfrau
	Crash when running pvxr2 to import xml file	carpeVideo	5	2,319	2010-01-07, 02:40 PM Last Post: carpeVideo
	Play Program â Standby â Resume â Crash	Rene_1	9	2,771	2010-01-03, 09:58 AM Last Post: Rene_1