turboladen / playful

A Ruby implementation of UPnP that works with Ruby >= 1.9.x
MIT License
127 stars 18 forks source link

Weird error when standard output is piped to less #6

Open pini-gh opened 11 years ago

pini-gh commented 11 years ago

Hi,

Reproducing this error should be fairly simple since it doesn't require any upnp device at all: 1- shut off every upnp device 2- run this short snippet:

#!/usr/bin/ruby
require 'upnp/ssdp'
require 'upnp/control_point'
EM.run do
  cp = UPnP::ControlPoint.new("upnp:rootdevice")
  cp.start do |new_device_channel, old_device_channel|
  end
end

3- this output should resemble this:

$ RUBYLIB=upnp/lib ./sonos.rb
Couldn't load HTTPI :em_http adapter.
D, [2012-12-29T14:12:40.663674 #9178] DEBUG -- : <UPnP::ControlPoint> Joining reactor...
D, [2012-12-29T14:12:40.670825 #9178] DEBUG -- : Sent datagram search:
D, [2012-12-29T14:12:40.671088 #9178] DEBUG -- : M-SEARCH * HTTP/1.1
D, [2012-12-29T14:12:40.671262 #9178] DEBUG -- : HOST: 239.255.255.250:1900
D, [2012-12-29T14:12:40.671433 #9178] DEBUG -- : MAN: "ssdp:discover"
D, [2012-12-29T14:12:40.671602 #9178] DEBUG -- : MX: 5
D, [2012-12-29T14:12:40.671770 #9178] DEBUG -- : ST: upnp:rootdevice
D, [2012-12-29T14:12:40.671938 #9178] DEBUG -- : 
D, [2012-12-29T14:12:40.672123 #9178] DEBUG -- : Sent datagram search:
D, [2012-12-29T14:12:40.672295 #9178] DEBUG -- : M-SEARCH * HTTP/1.1
D, [2012-12-29T14:12:40.672465 #9178] DEBUG -- : HOST: 239.255.255.250:1900
D, [2012-12-29T14:12:40.672635 #9178] DEBUG -- : MAN: "ssdp:discover"
D, [2012-12-29T14:12:40.672803 #9178] DEBUG -- : MX: 5
D, [2012-12-29T14:12:40.672970 #9178] DEBUG -- : ST: upnp:rootdevice
D, [2012-12-29T14:12:40.673356 #9178] DEBUG -- : 
log writing failed. no datagram socket
<UPnP::ControlPoint> Device count: 0
<UPnP::ControlPoint> Device unique: 0
D, [2012-12-29T14:12:50.720616 #9178] DEBUG -- : <UPnP::ControlPoint> Time since last timer: 5.005836496
D, [2012-12-29T14:12:50.720883 #9178] DEBUG -- : <UPnP::ControlPoint> Connections: 0
<UPnP::ControlPoint> Device count: 0
<UPnP::ControlPoint> Device unique: 0
D, [2012-12-29T14:12:55.725295 #9178] DEBUG -- : <UPnP::ControlPoint> Time since last timer: 5.004164775
D, [2012-12-29T14:12:55.725565 #9178] DEBUG -- : <UPnP::ControlPoint> Connections: 0
<UPnP::ControlPoint> Device count: 0
<UPnP::ControlPoint> Device unique: 0
...

4- run the snippet again with standard ouput piped to less; the following error occurs:

/var/lib/gems/1.9.1/gems/eventmachine-1.0.0/lib/eventmachine.rb:859:in `open_udp_socket': no datagram socket (RuntimeError)
        from /var/lib/gems/1.9.1/gems/eventmachine-1.0.0/lib/eventmachine.rb:859:in `open_datagram_socket'
        from /home/pini/Sonos/upnp/lib/upnp/ssdp.rb:52:in `block in listen'
        from /home/pini/Sonos/upnp/lib/upnp/ssdp.rb:59:in `call'
        from /home/pini/Sonos/upnp/lib/upnp/ssdp.rb:59:in `listen'
        from /home/pini/Sonos/upnp/lib/upnp/control_point.rb:86:in `block in listen'
        from /var/lib/gems/1.9.1/gems/eventmachine-1.0.0/lib/eventmachine.rb:1037:in `call'
        from /var/lib/gems/1.9.1/gems/eventmachine-1.0.0/lib/eventmachine.rb:1037:in `block in spawn_threadpool'

while standard output shows:

Couldn't load HTTPI :em_http adapter.
D, [2012-12-29T14:16:04.273818 #9260] DEBUG -- : <UPnP::ControlPoint> Joining reactor...
D, [2012-12-29T14:16:04.274643 #9260] DEBUG -- : Sent datagram search:
D, [2012-12-29T14:16:04.274718 #9260] DEBUG -- : M-SEARCH * HTTP/1.1
D, [2012-12-29T14:16:04.274760 #9260] DEBUG -- : HOST: 239.255.255.250:1900
D, [2012-12-29T14:16:04.274800 #9260] DEBUG -- : MAN: "ssdp:discover"
D, [2012-12-29T14:16:04.274838 #9260] DEBUG -- : MX: 5
D, [2012-12-29T14:16:04.274876 #9260] DEBUG -- : ST: upnp:rootdevice
D, [2012-12-29T14:16:04.274913 #9260] DEBUG -- : 
D, [2012-12-29T14:16:04.274964 #9260] DEBUG -- : Sent datagram search:
D, [2012-12-29T14:16:04.275002 #9260] DEBUG -- : M-SEARCH * HTTP/1.1
D, [2012-12-29T14:16:04.275040 #9260] DEBUG -- : HOST: 239.255.255.250:1900
D, [2012-12-29T14:16:04.275078 #9260] DEBUG -- : MAN: "ssdp:discover"
D, [2012-12-29T14:16:04.275115 #9260] DEBUG -- : MX: 5
D, [2012-12-29T14:16:04.275152 #9260] DEBUG -- : ST: upnp:rootdevice
D, [2012-12-29T14:16:04.275187 #9260] DEBUG -- : 
D, [2012-12-29T14:16:09.312892 #9260] DEBUG -- : <UPnP::ControlPoint> Connections: 1
<UPnP::ControlPoint> Device count: 0
<UPnP::ControlPoint> Device unique: 0

Notice the last DEBUG line which reports one connection. It isn't present in the previous trace when stdout isn't redirected.

What do you think?

Thanks,

_g.