tomkuijsten / restup

Webserver for universal windows platform (UWP) apps
MIT License
114 stars 48 forks source link

Web server hangs when content is returned in Windows IoT build 10.0.14393.693 #111

Open NameOfTheDragon opened 7 years ago

NameOfTheDragon commented 7 years ago

I've been trying to put Restup to use on my Raspberry Pi 3 and I'm having reliability issues whenever I try to return any content e.g. for a Get request.

As long as I only return a status code, then the server seems to work and at least doesn't hang, but even then Postman says that it didn't receive any response (although it sees that the connection was closed).

However, if I try to return any data for a Get request, even just a string literal, then the web server hangs and after a few tens of seconds the background task terminates.

The request is arriving and being parsed and routed successfully, but everything hangs when returning the response.

Here's an example of the code that exhibits the problem:

namespace TA.PiLights
    {
    [RestController(InstanceCreationType.PerCall)]
    public sealed class LampController
        {
        [UriFormat("lamp/{id}/{action}")]
        public IGetResponse LampControl(int id, string action)
            {
            var lampPins = LampHardwareInterface.LampPins;
            var lowerAction = action.ToLowerInvariant();
            var turnOn = lowerAction == "on";
            Debug.WriteLine($"Request to turn {action} lamp(s) {id}");
            if (id > lampPins.Count || id < 0)
                {
                Debug.WriteLine($"Invalid lamp ID={id}");
                return new GetResponse(GetResponse.ResponseStatus.NotFound);
                }
            var pin = lampPins[id];
            pin.Write(turnOn ? GpioPinValue.Low : GpioPinValue.High); // Switches are active low
            var state = turnOn ? "On" : "Off";
            var statusMessage = $"Lamp {id} turned {state}";
            Debug.WriteLine(statusMessage);
            return new GetResponse(GetResponse.ResponseStatus.OK, statusMessage);
            }
        }
    }

If I run that code and send a request to http://xxxxxxx:8800/api/lamp/0/On then the lamp turns on but no response comes back and after a few tens of seconds the background task terminates and all the lamps turn off. In Postman, here's what I see: image

In the Visual Studio debug output, I see:

Request to turn On lamp(s) 0
Lamp 0 turned On
The thread 0x854 has exited with code 0 (0x0).
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\Newtonsoft.Json.dll'. Cannot find or open the PDB file.
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\System.Runtime.Serialization.Primitives.dll'. Cannot find or open the PDB file.
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\System.Linq.Expressions.dll'. Cannot find or open the PDB file.
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\System.ObjectModel.dll'. Cannot find or open the PDB file.
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\System.Xml.XDocument.dll'. Cannot find or open the PDB file.
'backgroundTaskHost.exe' (CoreCLR: CoreCLR_UWP_Domain): Loaded 'C:\Data\Users\DefaultAccount\AppData\Local\DevelopmentFiles\TA.PiLights-uwpVS.Debug_ARM.Tim\System.Xml.ReaderWriter.dll'. Cannot find or open the PDB file.
The program '[2952] backgroundTaskHost.exe' has exited with code 1 (0x1).

If I change the last line of the code to:

            return new GetResponse(GetResponse.ResponseStatus.OK/*, statusMessage*/);

Then the background task no longer crashes and it'll accept another request - but it still doesn't return any responses.

I'm not sure if this is because I'm using a newer build of Windows 10 IoT Core - I'm on 10.0.14393.693 and using the matching SDK.

Jark commented 7 years ago

Hi @NameOfTheDragon ,

Since you're using a back ground task, have you made sure to us a BackgroundTaskDeferral to make sure the task stays alive and doesn't get garbage collected?

Also you need to make sure to store a reference to the created HttpServer in the task.

See https://github.com/tomkuijsten/restup/blob/master/src/HeadlessDemo/StartupTask.cs for more information.

I have also just tested a slightly modified HeadlessDemo on a PI 2 with version 10.0.14393.693 (per call controller returns "bla" as its response) in https://github.com/tomkuijsten/restup/tree/master/src/HeadlessDemo and it seems like it's working as it should.

image

Hope this helps and that you'll be able to figure it out!

Cheers,

Jark

NameOfTheDragon commented 7 years ago

Thanks for the reply.

Yes I'm creating a task deferral, but it looks like I'm not keeping a reference to the HttpServer object.

    public sealed class StartupTask : IBackgroundTask
        {
        public async void Run(IBackgroundTaskInstance taskInstance)
            {
            var taskDeferral = taskInstance.GetDeferral();
            await LampHardwareInterface.InitializeHardware();
            var restRouteHandler = new RestRouteHandler();
            restRouteHandler.RegisterController<LampController>();

            var configuration = new HttpServerConfiguration()
                .ListenOnPort(8800)
                .RegisterRoute("api", restRouteHandler)
                .EnableCors();

            var httpServer = new HttpServer(configuration);
            await httpServer.StartServerAsync();
            }

I will try holding a reference to be on the safe side and get back to you. --Tim

Jark commented 7 years ago

Please also hold a reference to the created taskDeferral, since the class I linked above (https://github.com/tomkuijsten/restup/blob/master/src/HeadlessDemo/StartupTask.cs) has an explicit comment saying that you need to keep a reference to the task deferral as well.

I believe @tomkuijsten might have put that in there.

NameOfTheDragon commented 7 years ago

OK, yes that seems to have been the problem. The server is now stable and I'm getting responses. That seems like a bit of a rookie mistake in hindsight, but I think it may have dropped out of some flailing around trying to solve other problems I was having with the Visual Studio tooling. Sorry for the false alarm :)

tomkuijsten commented 7 years ago

Good to hear that the issue has been resolved. Can we improve the wiki to prevent others to make this mistake, what do you think @NameOfTheDragon ?

NameOfTheDragon commented 7 years ago

That's a reasonable question, and I would say the answer is "yes".

Hope that helps! --Tim

Jark commented 7 years ago

The extra documentation is definitely a good idea, I'm thinking of also changing the default log factory in LogManager to something that logs to Debug.WriteLine so the disposing of the http server would be visible in the debug output and hopefully allow pinpointing of problems in a quicker way as well.

NameOfTheDragon commented 7 years ago

@Jark That has to be worth a try too. In my situation I saw the debugger "freezing" for long periods of time (tens of seconds) prior the background task terminating, so I'm not sure if the output would make it to the debugger, but it has to be worth a shot. I think that defaulting to Debug.WriteLine is a good idea, where else would you send it?

Jark commented 7 years ago

@NameOfTheDragon restup has a feature of plugging in your own Logging implementation that you would use in your application (like MetroLog for instance). See https://github.com/tomkuijsten/restup/wiki/Logging.

The default Logger is a NullLogger, which just ignores any log statements that come in. The idea being that someone would not want any logging by default and if they did then they would use their own log library. In fact I see that that article has a DebugLogger we could just include and instantiate in the source.

So yeah, I think it's a bit of an oversight at the time, I'll do some work later this afternoon to include it and make it the default. Unless @tomkuijsten disagrees?

tomkuijsten commented 7 years ago

I agree

NameOfTheDragon commented 7 years ago

I'm sorry I can't offer to help - I'm snowed under at the moment. Thanks for a really useful utility though.