Send connman mailing list submissions to
[email protected]
To subscribe or unsubscribe via email, send a message with subject or
body 'help' to
[email protected]
You can reach the person managing the list at
[email protected]
When replying, please edit your Subject line so it is more specific
than "Re: Contents of connman digest..."
Today's Topics:
1. Re: Next release (Richard Röjfors)
----------------------------------------------------------------------
Date: Tue, 17 Mar 2020 14:09:32 +0100
From: Richard Röjfors <[email protected]>
Subject: Re: Next release
To: Jussi Laakkonen <[email protected]>
Cc: Daniel Wagner <[email protected]>, connman <[email protected]>
Message-ID:
<cahb-pjnytw3nhyw0xq5kiwrba0dh+j6px0kuh3tk1tor-q_...@mail.gmail.com>
Content-Type: multipart/alternative;
boundary="000000000000a78d9105a10ca715"
--000000000000a78d9105a10ca715
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Hi Jussi,
I saw your patch got accepted about the same time you sent it to the
mailinglist, so did not test it during that time, since someone else
obviously did that.
Now I have had devices running for a while but unfortunately openvpn does
not reconnect automatically, I double checked so the settings were not
changed by some unknown reason.
We run over cellular and I will provide some chunks of the log. Its a
mixture of ofono and connman logs, but that might be helpful to see the
timing.
If this gets to verbose please let me know if you want to discuss further
off list.
The device connects to the cellular network and the vpn goes up:
08:19:17 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify()
/ublox_0 status roaming (5)
08:19:17 debug ofonod[532]: ../git/src/gprs.c:gprs_attached_update()
0x22aec78, attached: 1, gprs->attached: 0
08:19:17 debug ofonod[532]: ../git/src/gprs.c:gprs_set_attached_property()
0x22aec78 0 -> 1
08:19:17 debug ofonod[532]:
../git/drivers/ubloxmodem/network-registration.c:ctze_notify() tz +04 dst 0
time 20/03/14,09:19:39
08:19:17 debug ofonod[532]: ../git/src/network.c:ofono_netreg_time_notify()
net time 2020-03-14 09:19:39 utcoff 3600 dst 0
08:19:17 warn connmand[474]: ipconfig state 2 ipconfig method 1
08:19:17 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:ublox_gprs_activate_primary() cid =
1
08:19:17 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 20201 ci 8577130
08:19:17 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
08:19:17 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
08:19:17 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:cgdcont_cb() ok 1
08:19:17 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
08:19:17 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 29
08:19:17 debug ofonod[532]:
../git/src/network.c:ofono_netreg_strength_notify() strength 93
08:19:20 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:cgact_enable_cb() ok 1
08:19:20 debug ofonod[532]: ../git/src/modem.c:get_modem_property() modem
0x22aec00 property NetworkInterface
08:19:20 debug ofonod[532]: ../git/src/gprs.c:pri_activate_callback()
0x22b9b68
08:19:20 info connman-vpnd[481]: usb0 {update} flags 69699
<UP,RUNNING,LOWER_UP>
08:19:20 info connman-vpnd[481]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
08:19:20 info connman-vpnd[481]: usb0 {newlink} index 7 operstate 0
<UNKNOWN>
08:19:20 info connmand[474]: usb0 {update} flags 69699 <UP,RUNNING,LOWER_UP=
>
08:19:20 info connmand[474]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
08:19:20 info connmand[474]: usb0 {newlink} index 7 operstate 0 <UNKNOWN>
08:19:20 info connmand[474]: usb0 {add} route ff00:: gw :: scope 0
<UNIVERSE>
08:19:20 info connmand[474]: usb0 {add} route fe80:: gw :: scope 0
<UNIVERSE>
08:19:20 warn connmand[474]: ipconfig state 3 ipconfig method 1
08:19:20 info connmand[474]: Setting hostname to <hostname>
08:19:20 info connmand[474]: usb0 {del} route fe80:: gw :: scope 0
<UNIVERSE>
08:19:20 info connmand[474]: usb0 {del} route ff00:: gw :: scope 0
<UNIVERSE>
08:19:20 info connmand[474]: usb0 {add} address 192.168.1.100/24 label usb0
family 2
08:19:20 info connmand[474]: usb0 {add} route 192.168.1.0 gw 0.0.0.0 scope
253 <LINK>
08:19:20 info connmand[474]: usb0 {add} route 192.168.1.1 gw 0.0.0.0 scope
253 <LINK>
08:19:20 info connmand[474]: usb0 {add} route 0.0.0.0 gw 192.168.1.1 scope
0 <UNIVERSE>
08:19:20 warn connmand[474]: ipconfig state 2 ipconfig method 1
08:19:20 info connmand[474]: vpn0 {create} index 8 type 65534 <NONE>
08:19:20 info connmand[474]: vpn0 {update} flags 4240 <DOWN>
08:19:20 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
08:19:20 info connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN>
08:19:20 debug ofonod[532]: ../git/plugins/udevng.c:add_serial_device()
Device is missing required OFONO_DRIVER property
08:19:20 info connman-vpnd[481]: vpn0 {create} index 8 type 65534 <NONE>
08:19:20 info connman-vpnd[481]: vpn0 {update} flags 4240 <DOWN>
08:19:20 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN>
08:19:20 warn connmand[474]: ipconfig state 2 ipconfig method 1
08:19:20 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_cb() cops_cb: Oper, XXX
XX 2
08:19:20 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)
08:19:20 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
08:19:20 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
08:19:20 info connmand[474]: usb0 {add} route 212.227.81.55 gw 192.168.1.1
scope 0 <UNIVERSE>
08:19:20 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 0 ci 16
08:19:20 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
08:19:20 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
08:19:20 debug ofonod[532]:
../git/drivers/atmodem/gprs.c:at_cgdcont_read_cb() ok 1
08:19:20 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activated()
cid 1
08:19:20 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activated()
cid 1 already activated
08:19:20 warn connman-vpnd[481]: Connected management socket
08:19:20 warn connman-vpnd[481]: openvpn request >INFO:OpenVPN Management
Interface Version 1 -- type 'help' for more info^M
08:19:20 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
08:19:20 info connmand[474]: usb0 {del} route 212.227.81.55 gw 192.168.1.1
scope 0 <UNIVERSE>
08:19:20 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 30
08:19:20 debug ofonod[532]:
../git/src/network.c:ofono_netreg_strength_notify() strength 96
08:19:20 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_cb() cops_cb: Oper, XXX
XX 2
08:19:20 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888
08:19:22 debug ofonod[532]: ../git/plugins/udevng.c:check_modem_list()
08:19:25 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN>
08:19:25 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
08:19:25 info connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN>
08:19:25 info connman-vpnd[481]: vpn0 {update} flags 102609
<UP,RUNNING,LOWER_UP>
08:19:25 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 6 <UP>
08:19:25 info connmand[474]: vpn0 {update} flags 102609
<UP,RUNNING,LOWER_UP>
08:19:25 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
08:19:25 info connmand[474]: vpn0 {newlink} index 8 operstate 6 <UP>
08:19:25 info connmand[474]: vpn0 {add} route ff00:: gw :: scope 0
<UNIVERSE>
08:19:25 info connmand[474]: vpn0 {add} route fe80:: gw :: scope 0
<UNIVERSE>
08:19:25 info connmand[474]: vpn0 {add} address 10.129.36.7/16 label vpn0
family 2
08:19:25 info connmand[474]: vpn0 {add} route 10.129.0.0 gw 0.0.0.0 scope
253 <LINK>
08:19:25 info connmand[474]: rp_filter set to 2 (loose mode routing), old
value was 0
08:19:25 warn connmand[474]: ipconfig state 4 ipconfig method 1
08:19:25 info connmand[474]: usb0 {add} route 84.19.146.225 gw 192.168.1.1
scope 0 <UNIVERSE>
08:19:25 info connmand[474]: vpn0 {del} route fe80:: gw :: scope 0
<UNIVERSE>
08:19:25 info connmand[474]: vpn0 {del} route ff00:: gw :: scope 0
<UNIVERSE>
08:19:25 info connmand[474]: vpn0 {add} route 10.128.0.0 gw 10.129.0.1
scope 0 <UNIVERSE>
08:19:25 info connmand[474]: vpn0 {add} route 10.127.0.0 gw 10.129.0.1
scope 0 <UNIVERSE>
08:19:25 info connmand[474]: vpn0 {add} route 10.129.0.0 gw 10.129.0.1
scope 0 <UNIVERSE>
Time passes by (~12hrs) and unfortunately we get kicked out from the
network:
20:17:52 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 0 tech -1
lac -1 ci -1
20:17:52 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888
20:17:52 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 0
(unregistered)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
0, driver_attached: 1
20:17:52 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 0
(unregistered)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
0, driver_attached: 0
20:17:52 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify()
/ublox_0 status unknown (4)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_attach_callback()
/ublox_0 error =3D 0
20:17:52 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 3 tech -1
lac -1 ci -1
20:17:52 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 3
(denied)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
0, driver_attached: 0
20:17:52 debug ofonod[532]: ../git/src/gprs.c:registration_status_cb()
/ublox_0 error 0 status 3
20:17:52 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify()
/ublox_0 status denied (3)
20:17:52 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_detached_notify()
/ublox_0
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_attached_update()
0x22aec78, attached: 0, gprs->attached: 1
20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_set_attached_property()
0x22aec78 1 -> 0
20:17:52 info connmand[474]: rp_filter restored to 0
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 info connman-vpnd[481]: pid 622 was not killed, retrying after 2
sec
20:17:52 err connmand[474]: notifier disconnect underflow
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 info connman-vpnd[481]: vpn0 {update} flags 37009 <UP>
20:17:52 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN>
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 debug ofonod[532]: ../git/plugins/udevng.c:remove_device()
/sys/devices/virtual/net/vpn0
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 info connmand[474]: usb0 {del} address 192.168.1.100/24 label usb0
20:17:52 info connmand[474]: usb0 {del} route 192.168.1.0 gw 0.0.0.0 scope
253 <LINK>
20:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes
20:17:52 info connmand[474]: (null) {TX} 3 packets 128 bytes
20:17:52 info connmand[474]: (null) {update} flags 37009 <UP>
20:17:52 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
20:17:52 info connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN>
20:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes
20:17:52 info connmand[474]: (null) {TX} 3 packets 128 bytes
20:17:52 info connmand[474]: (null) {update} flags 102609
<UP,RUNNING,LOWER_UP>
20:17:52 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
20:17:52 info connmand[474]: vpn0 {newlink} index 8 operstate 6 <UP>
20:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes
20:17:52 info connmand[474]: (null) {TX} 3 packets 128 bytes
20:17:52 info connmand[474]: (null) {update} flags 37008 <DOWN>
20:17:52 info connmand[474]: vpn0 {newlink} index 8 address
00:00:00:00:00:00 mtu 1500
20:17:52 info connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN>
20:17:52 info connmand[474]: (null) {del} address 10.129.36.7/16 label vpn0
20:17:52 info connmand[474]: vpn0 {dellink} index 8 operstate 2 <DOWN>
20:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes
20:17:52 info connmand[474]: (null) {TX} 3 packets 128 bytes
20:17:52 info connmand[474]: (null) {remove} index 8
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 info connman-vpnd[481]: vpn0 {update} flags 102609
<UP,RUNNING,LOWER_UP>
20:17:52 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 6 <UP>
20:17:52 info connman-vpnd[481]: vpn0 {update} flags 37008 <DOWN>
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:52 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN>
20:17:52 info connman-vpnd[481]: vpn0 {dellink} index 8 operstate 2 <DOWN>
20:17:52 info connman-vpnd[481]: vpn0 {remove} index 8
20:17:55 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 3 tech -1
lac -1 ci -1
20:17:55 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)
20:17:55 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 3
(denied)
20:17:55 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
0, driver_attached: 0
We get registered again:
20:17:57 debug ofonod[532]:
../git/drivers/ubloxmodem/network-registration.c:ctze_notify() tz +04 dst 0
time 20/03/14,21:18:19
20:17:57 debug ofonod[532]: ../git/src/network.c:ofono_netreg_time_notify()
net time 2020-03-14 21:18:19 utcoff 3600 dst 0
20:17:57 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 57005 ci 2147483647
20:17:57 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 0
20:17:57 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
20:17:57 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 27
20:17:57 debug ofonod[532]:
../git/src/network.c:ofono_netreg_strength_notify() strength 87
20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_attach_callback()
/ublox_0 error =3D 0
20:17:57 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify()
/ublox_0 status roaming (5)
20:17:57 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_cb() cops_cb: Oper, XXX
XX 2
20:17:57 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)
20:17:57 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
20:17:57 debug ofonod[532]: ../git/src/gprs.c:registration_status_cb()
/ublox_0 error 0 status 5
20:17:57 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify()
/ublox_0 status roaming (5)
20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_attached_update()
0x22aec78, attached: 1, gprs->attached: 0
20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_set_attached_property()
0x22aec78 0 -> 1
20:17:58 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 20201 ci 8577130
20:17:58 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
Data bearer attached again: Seems like a try is done to connect to the vpn.
20:17:58 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
20:17:58 warn connmand[474]: ipconfig state 3 ipconfig method 1
20:17:58 info connmand[474]: Setting hostname to <hostname>
20:17:58 info connmand[474]: usb0 {add} address 192.168.1.100/24 label usb0
family 2
20:17:58 info connmand[474]: usb0 {add} route 192.168.1.0 gw 0.0.0.0 scope
253 <LINK>
20:17:58 info connmand[474]: usb0 {add} route 192.168.1.1 gw 0.0.0.0 scope
253 <LINK>
20:17:58 info connmand[474]: usb0 {add} route 0.0.0.0 gw 192.168.1.1 scope
0 <UNIVERSE>
20:17:58 warn connmand[474]: ipconfig state 2 ipconfig method 1
20:17:58 info connmand[474]: vpn0 {create} index 9 type 65534 <NONE>
20:17:58 info connmand[474]: vpn0 {update} flags 4240 <DOWN>
20:17:58 info connmand[474]: vpn0 {newlink} index 9 address
00:00:00:00:00:00 mtu 1500
20:17:58 info connmand[474]: vpn0 {newlink} index 9 operstate 2 <DOWN>
20:17:58 info connman-vpnd[481]: vpn0 {create} index 9 type 65534 <NONE>
20:17:58 info connman-vpnd[481]: vpn0 {update} flags 4240 <DOWN>
20:17:58 info connman-vpnd[481]: vpn0 {newlink} index 9 operstate 2 <DOWN>
20:17:58 warn connmand[474]: ipconfig state 2 ipconfig method 1
20:17:58 debug ofonod[532]: ../git/plugins/udevng.c:add_serial_device()
Device is missing required OFONO_DRIVER property
20:17:58 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
20:17:58 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 27
20:17:58 warn connman-vpnd[481]: Connected management socket
20:17:58 warn connman-vpnd[481]: openvpn request >INFO:OpenVPN Management
Interface Version 1 -- type 'help' for more info^M
20:17:58 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_cb() cops_cb: OPER, XXX
XX 2
20:17:58 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888
20:17:59 debug ofonod[532]: ../git/plugins/udevng.c:check_modem_list()
20:17:59 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:cgev_notify() cid 1, active cid: 1
Suddenly the context gets deactivated, during the time vpn tries to connect
20:17:59 debug ofonod[532]:
../git/src/gprs.c:ofono_gprs_context_deactivated() 0x22aeb38 0x22aec78 1
20:17:59 info connman-vpnd[481]: usb0 {update} flags 4098 <DOWN>
20:17:59 info connmand[474]: usb0 {RX} 7696 packets 1329655 bytes
20:17:59 info connman-vpnd[481]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
20:17:59 info connmand[474]: usb0 {TX} 8199 packets 1553446 bytes
20:17:59 info connman-vpnd[481]: usb0 {newlink} index 7 operstate 2 <DOWN>
20:17:59 info connmand[474]: usb0 {update} flags 4098 <DOWN>
20:17:59 info connmand[474]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
20:17:59 info connmand[474]: usb0 {newlink} index 7 operstate 2 <DOWN>
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 info connman-vpnd[481]: pid 3204 was not killed, retrying after 2
sec
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 info connmand[474]: usb0 {del} address 192.168.1.100/24 label usb0
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 warn connmand[474]: ipconfig state 2 ipconfig method 1
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:ublox_gprs_activate_primary() cid =
1
20:17:59 info connmand[474]: vpn0 {dellink} index 9 operstate 2 <DOWN>
20:17:59 info connmand[474]: (null) {remove} index 9
20:17:59 debug ofonod[532]: ../git/plugins/udevng.c:remove_device()
/sys/devices/virtual/net/vpn0
20:17:59 info connman-vpnd[481]: vpn0 {dellink} index 9 operstate 2 <DOWN>
20:17:59 info connman-vpnd[481]: vpn0 {remove} index 9
20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1
20:17:59 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:cgdcont_cb() ok 1
20:17:59 warn connmand[474]: ipconfig state 7 ipconfig method 1
20:18:00 debug ofonod[532]:
../git/drivers/ubloxmodem/gprs-context.c:cgact_enable_cb() ok 1
20:18:00 debug ofonod[532]: ../git/src/modem.c:get_modem_property() modem
0x22aec00 property NetworkInterface
20:18:00 debug ofonod[532]: ../git/src/gprs.c:pri_activate_callback()
0x22b9b68
Context is activated again. Connman manage to get time via ntp and things
looks good, except that the vpn is not reconnected.
20:18:00 info connman-vpnd[481]: usb0 {update} flags 69699
<UP,RUNNING,LOWER_UP>
20:18:00 info connman-vpnd[481]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
20:18:00 info connman-vpnd[481]: usb0 {newlink} index 7 operstate 0
<UNKNOWN>
20:18:00 info connmand[474]: usb0 {RX} 7696 packets 1329655 bytes
20:18:00 info connmand[474]: usb0 {TX} 8199 packets 1553446 bytes
20:18:00 info connmand[474]: usb0 {update} flags 69699 <UP,RUNNING,LOWER_UP=
>
20:18:00 info connmand[474]: usb0 {newlink} index 7 address
02:07:01:18:00:0B mtu 1400
20:18:00 info connmand[474]: usb0 {newlink} index 7 operstate 0 <UNKNOWN>
20:18:00 warn connmand[474]: ipconfig state 3 ipconfig method 1
20:18:00 info connmand[474]: Setting hostname to <hostname>
20:18:00 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 57005 ci 2147483647
20:18:00 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
20:18:00 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
20:18:00 debug ofonod[532]:
../git/drivers/atmodem/gprs.c:at_cgdcont_read_cb() ok 1
20:18:00 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activated()
cid 1
20:18:00 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activated()
cid 1 already activated
20:18:00 info connmand[474]: usb0 {add} address 192.168.1.100/24 label usb0
family 2
20:18:00 info connmand[474]: usb0 {add} route 192.168.1.0 gw 0.0.0.0 scope
253 <LINK>
20:18:00 info connmand[474]: usb0 {add} route 192.168.1.1 gw 0.0.0.0 scope
253 <LINK>
20:18:00 info connmand[474]: usb0 {add} route 0.0.0.0 gw 192.168.1.1 scope
0 <UNIVERSE>
20:18:00 info connmand[474]: usb0 {add} route 212.227.81.55 gw 192.168.1.1
scope 0 <UNIVERSE>
20:18:00 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
20:18:01 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 29
20:18:01 debug ofonod[532]:
../git/src/network.c:ofono_netreg_strength_notify() strength 93
20:18:01 info connmand[474]: ntp: adjust (jump): +22.500568 sec
20:18:23 info connmand[474]: usb0 {del} route 212.227.81.55 gw 192.168.1.1
scope 0 <UNIVERSE>
20:18:23 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_cb() cops_cb: Oper, XXX
XX 2
20:18:23 debug ofonod[532]:
../git/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888
20:18:26 debug ofonod[532]:
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2
lac 57005 ci 2147483647
20:18:26 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5
(roaming)
20:18:26 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach:
1, driver_attached: 1
20:18:26 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:cops_numeric_cb() Cops
numeric got mcc: XXX, mnc: XX
20:18:26 debug ofonod[532]:
../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 29
Den tors 23 jan. 2020 kl 15:38 skrev Jussi Laakkonen <
[email protected]>:
> Hi Richard,
>
> On 1/22/20 1:50 PM, Richard R=C3=B6jfors wrote:
> >
> > Yes we are using TCP.
> >
>
> I assumed so, I think I faced a similar problem with our setup testing
> free VPNBook OpenVPN using TCP. But yours may still be a different one.
>
> >
> > Sounds great! I will try to verify it. Its not super easy to reproduce,
> > but over time and a few
> > devices it always happens. I'm thinking I could hack ofono a little to
> > simulate
> > the situation....
> >
>
> I submitted a patch for OpenVPN plugin just moments ago to connman list.
> Please check if that improves your situation. After all, it is fixing a
> regression introduced by the changes I sent for OpenVPN.
>
> I still have a hunch there could be an improvement in place for the
> vpn-provider.c to track the connman state, and to delay the connection
> if connman is not reporting to be online. This would prevent connections
> to VPNs when, in case just like yours, the default service (mobile data,
> wifi) goes down only momentarily.
>
> In our fork we have this functionality already implemented. Now I just
> need to find time to create a patch/patches against connman upstream for
> Daniel and others reading the list to review.
>
> Sincerely,
> Jussi
>
>
--000000000000a78d9105a10ca715
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
<div dir=3D"ltr"><div dir=3D"ltr">Hi Jussi,<div><br></div><div>I saw your p=
atch got accepted about the same time you sent it to the mailinglist, so di=
d not test it during that time, since someone else obviously did that.</div=
><div><br></div><div>Now I have had devices running for a while but unfortu=
nately openvpn does not reconnect automatically, I double checked so the se=
ttings were not changed by some unknown=C2=A0reason.=C2=A0</div><div><br></=
div><div>We run over cellular and I will provide some chunks of the log. It=
s a mixture of ofono and connman logs, but that might be helpful to see the=
timing.</div><div><br></div><div>If this gets to verbose please=C2=A0let m=
e know if you want to discuss=C2=A0further off list.</div><div><br></div><d=
iv>The device connects to the cellular network and the vpn goes up:<br><br>=
08:19:17 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_notify() /u=
blox_0 status roaming (5)<br>08:19:17 debug ofonod[532]: ../git/src/gprs.c:=
gprs_attached_update() 0x22aec78, attached: 1, gprs->attached: 0<br>08:1=
9:17 debug ofonod[532]: ../git/src/gprs.c:gprs_set_attached_property() 0x22=
aec78 0 -> 1<br>08:19:17 debug ofonod[532]: ../git/drivers/ubloxmodem/ne=
twork-registration.c:ctze_notify() tz +04 dst 0 time 20/03/14,09:19:39<br>0=
8:19:17 debug ofonod[532]: ../git/src/network.c:ofono_netreg_time_notify() =
net time 2020-03-14 09:19:39 utcoff 3600 dst 0<br>08:19:17 warn connmand[47=
4]: ipconfig state 2 ipconfig method 1<br>08:19:17 debug ofonod[532]: ../gi=
t/drivers/ubloxmodem/gprs-context.c:ublox_gprs_activate_primary() cid 1<br>=
08:19:17 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_notify=
() /ublox_0 status 5 tech 2 lac 20201 ci 8577130<br>08:19:17 debug ofonod[5=
32]: ../git/src/gprs.c:netreg_status_changed() 5 (roaming)<br>08:19:17 debu=
g ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach: 1, driver_att=
ached: 1<br>08:19:17 debug ofonod[532]: ../git/drivers/ubloxmodem/gprs-cont=
ext.c:cgdcont_cb() ok 1<br>08:19:17 debug ofonod[532]: ../git/drivers/atmod=
em/network-registration.c:cops_numeric_cb() Cops numeric got mcc: XXX, mnc:=
XX<br>08:19:17 debug ofonod[532]: ../git/drivers/atmodem/network-registrat=
ion.c:csq_cb() csq_cb: 29<br>08:19:17 debug ofonod[532]: ../git/src/network=
.c:ofono_netreg_strength_notify() strength 93<br>08:19:20 debug ofonod[532]=
: ../git/drivers/ubloxmodem/gprs-context.c:cgact_enable_cb() ok 1<br>08:19:=
20 debug ofonod[532]: ../git/src/modem.c:get_modem_property() modem 0x22aec=
00 property NetworkInterface<br>08:19:20 debug ofonod[532]: ../git/src/gprs=
.c:pri_activate_callback() 0x22b9b68<br>08:19:20 info connman-vpnd[481]: us=
b0 {update} flags 69699 <UP,RUNNING,LOWER_UP><br>08:19:20 info connma=
n-vpnd[481]: usb0 {newlink} index 7 address 02:07:01:18:00:0B mtu 1400<br>0=
8:19:20 info connman-vpnd[481]: usb0 {newlink} index 7 operstate 0 <UNKN=
OWN><br>08:19:20 info connmand[474]: usb0 {update} flags 69699 <UP,RU=
NNING,LOWER_UP><br>08:19:20 info connmand[474]: usb0 {newlink} index 7 a=
ddress 02:07:01:18:00:0B mtu 1400<br>08:19:20 info connmand[474]: usb0 {new=
link} index 7 operstate 0 <UNKNOWN><br>08:19:20 info connmand[474]: u=
sb0 {add} route ff00:: gw :: scope 0 <UNIVERSE><br>08:19:20 info conn=
mand[474]: usb0 {add} route fe80:: gw :: scope 0 <UNIVERSE><br>08:19:=
20 warn connmand[474]: ipconfig state 3 ipconfig method 1<br>08:19:20 info =
connmand[474]: Setting hostname to <hostname><br>08:19:20 info connma=
nd[474]: usb0 {del} route fe80:: gw :: scope 0 <UNIVERSE><br>08:19:20=
info connmand[474]: usb0 {del} route ff00:: gw :: scope 0 <UNIVERSE>=
<br>08:19:20 info connmand[474]: usb0 {add} address <a href=3D"http://192.1=
68.1.100/24">192.168.1.100/24</a> label usb0 family 2<br>08:19:20 info conn=
mand[474]: usb0 {add} route 192.168.1.0 gw 0.0.0.0 scope 253 <LINK><b=
r>08:19:20 info connmand[474]: usb0 {add} route 192.168.1.1 gw 0.0.0.0 scop=
e 253 <LINK><br>08:19:20 info connmand[474]: usb0 {add} route 0.0.0.0=
gw 192.168.1.1 scope 0 <UNIVERSE><br>08:19:20 warn connmand[474]: ip=
config state 2 ipconfig method 1<br>08:19:20 info connmand[474]: vpn0 {crea=
te} index 8 type 65534 <NONE><br>08:19:20 info connmand[474]: vpn0 {u=
pdate} flags 4240 <DOWN><br>08:19:20 info connmand[474]: vpn0 {newlin=
k} index 8 address 00:00:00:00:00:00 mtu 1500<br>08:19:20 info connmand[474=
]: vpn0 {newlink} index 8 operstate 2 <DOWN><br>08:19:20 debug ofonod=
[532]: ../git/plugins/udevng.c:add_serial_device() Device is missing requir=
ed OFONO_DRIVER property<br>08:19:20 info connman-vpnd[481]: vpn0 {create} =
index 8 type 65534 <NONE><br>08:19:20 info connman-vpnd[481]: vpn0 {u=
pdate} flags 4240 <DOWN><br>08:19:20 info connman-vpnd[481]: vpn0 {ne=
wlink} index 8 operstate 2 <DOWN><br>08:19:20 warn connmand[474]: ipc=
onfig state 2 ipconfig method 1<br>08:19:20 debug ofonod[532]: ../git/drive=
rs/atmodem/network-registration.c:cops_cb() cops_cb: Oper, XXX XX 2<br>08:1=
9:20 debug ofonod[532]: ../git/src/network.c:current_operator_callback() 0x=
22b2ed8, (nil)<br>08:19:20 debug ofonod[532]: ../git/src/gprs.c:netreg_stat=
us_changed() 5 (roaming)<br>08:19:20 debug ofonod[532]: ../git/src/gprs.c:g=
prs_netreg_update() attach: 1, driver_attached: 1<br>08:19:20 info connmand=
[474]: usb0 {add} route 212.227.81.55 gw 192.168.1.1 scope 0 <UNIVERSE&g=
t;<br>08:19:20 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_=
notify() /ublox_0 status 5 tech 2 lac 0 ci 16<br>08:19:20 debug ofonod[532]=
: ../git/src/gprs.c:netreg_status_changed() 5 (roaming)<br>08:19:20 debug o=
fonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach: 1, driver_attach=
ed: 1<br>08:19:20 debug ofonod[532]: ../git/drivers/atmodem/gprs.c:at_cgdco=
nt_read_cb() ok 1<br>08:19:20 debug ofonod[532]: ../git/src/gprs.c:ofono_gp=
rs_cid_activated() cid 1<br>08:19:20 debug ofonod[532]: ../git/src/gprs.c:o=
fono_gprs_cid_activated() cid 1 already activated<br>08:19:20 warn connman-=
vpnd[481]: Connected management socket<br>08:19:20 warn connman-vpnd[481]: =
openvpn request >INFO:OpenVPN Management Interface Version 1 -- type =
9;help' for more info^M<br>08:19:20 debug ofonod[532]: ../git/drivers/a=
tmodem/network-registration.c:cops_numeric_cb() Cops numeric got mcc: XXX, =
mnc: XX<br>08:19:20 info connmand[474]: usb0 {del} route 212.227.81.55 gw 1=
92.168.1.1 scope 0 <UNIVERSE><br>08:19:20 debug ofonod[532]: ../git/d=
rivers/atmodem/network-registration.c:csq_cb() csq_cb: 30<br>08:19:20 debug=
ofonod[532]: ../git/src/network.c:ofono_netreg_strength_notify() strength =
96<br>08:19:20 debug ofonod[532]: ../git/drivers/atmodem/network-registrati=
on.c:cops_cb() cops_cb: Oper, XXX XX 2<br>08:19:20 debug ofonod[532]: ../gi=
t/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888<br>08:19:2=
2 debug ofonod[532]: ../git/plugins/udevng.c:check_modem_list() <br>08:19:2=
5 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN><b=
r>08:19:25 info connmand[474]: vpn0 {newlink} index 8 address 00:00:00:00:0=
0:00 mtu 1500<br>08:19:25 info connmand[474]: vpn0 {newlink} index 8 operst=
ate 2 <DOWN><br>08:19:25 info connman-vpnd[481]: vpn0 {update} flags =
102609 <UP,RUNNING,LOWER_UP><br>08:19:25 info connman-vpnd[481]: vpn0=
{newlink} index 8 operstate 6 <UP><br>08:19:25 info connmand[474]: v=
pn0 {update} flags 102609 <UP,RUNNING,LOWER_UP><br>08:19:25 info conn=
mand[474]: vpn0 {newlink} index 8 address 00:00:00:00:00:00 mtu 1500<br>08:=
19:25 info connmand[474]: vpn0 {newlink} index 8 operstate 6 <UP><br>=
08:19:25 info connmand[474]: vpn0 {add} route ff00:: gw :: scope 0 <UNIV=
ERSE><br>08:19:25 info connmand[474]: vpn0 {add} route fe80:: gw :: scop=
e 0 <UNIVERSE><br>08:19:25 info connmand[474]: vpn0 {add} address <a =
href=3D"http://10.129.36.7/16";>10.129.36.7/16</a> label vpn0 family 2<br>08=
:19:25 info connmand[474]: vpn0 {add} route 10.129.0.0 gw 0.0.0.0 scope 253=
<LINK><br>08:19:25 info connmand[474]: rp_filter set to 2 (loose mod=
e routing), old value was 0<br>08:19:25 warn connmand[474]: ipconfig state =
4 ipconfig method 1<br>08:19:25 info connmand[474]: usb0 {add} route 84.19.=
146.225 gw 192.168.1.1 scope 0 <UNIVERSE><br>08:19:25 info connmand[4=
74]: vpn0 {del} route fe80:: gw :: scope 0 <UNIVERSE><br>08:19:25 inf=
o connmand[474]: vpn0 {del} route ff00:: gw :: scope 0 <UNIVERSE><br>=
08:19:25 info connmand[474]: vpn0 {add} route 10.128.0.0 gw 10.129.0.1 scop=
e 0 <UNIVERSE><br>08:19:25 info connmand[474]: vpn0 {add} route 10.12=
7.0.0 gw 10.129.0.1 scope 0 <UNIVERSE><br>08:19:25 info connmand[474]=
: vpn0 {add} route 10.129.0.0 gw 10.129.0.1 scope 0 <UNIVERSE><br></d=
iv><div><br></div><div><br></div><div>Time passes by (~12hrs) and unfortuna=
tely we get kicked out from the network:</div><div><br></div><div><br></div=
><div>20:17:52 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_=
notify() /ublox_0 status 0 tech -1 lac -1 ci -1<br>20:17:52 debug ofonod[53=
2]: ../git/src/network.c:current_operator_callback() 0x22b2ed8, 0x22b8888<b=
r>20:17:52 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 0 (=
unregistered)<br>20:17:52 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_=
update() attach: 0, driver_attached: 1<br>20:17:52 debug ofonod[532]: ../gi=
t/src/gprs.c:netreg_status_changed() 0 (unregistered)<br>20:17:52 debug ofo=
nod[532]: ../git/src/gprs.c:gprs_netreg_update() attach: 0, driver_attached=
: 0<br>20:17:52 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_status_noti=
fy() /ublox_0 status unknown (4)<br>20:17:52 debug ofonod[532]: ../git/src/=
gprs.c:gprs_attach_callback() /ublox_0 error =3D 0<br>20:17:52 debug ofonod=
[532]: ../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 3 =
tech -1 lac -1 ci -1<br>20:17:52 debug ofonod[532]: ../git/src/network.c:cu=
rrent_operator_callback() 0x22b2ed8, (nil)<br>20:17:52 debug ofonod[532]: .=
./git/src/gprs.c:netreg_status_changed() 3 (denied)<br>20:17:52 debug ofono=
d[532]: ../git/src/gprs.c:gprs_netreg_update() attach: 0, driver_attached: =
0<br>20:17:52 debug ofonod[532]: ../git/src/gprs.c:registration_status_cb()=
/ublox_0 error 0 status 3<br>20:17:52 debug ofonod[532]: ../git/src/gprs.c=
:ofono_gprs_status_notify() /ublox_0 status denied (3)<br>20:17:52 debug of=
onod[532]: ../git/src/gprs.c:ofono_gprs_detached_notify() /ublox_0<br>20:17=
:52 debug ofonod[532]: ../git/src/gprs.c:gprs_attached_update() 0x22aec78, =
attached: 0, gprs->attached: 1<br>20:17:52 debug ofonod[532]: ../git/src=
/gprs.c:gprs_set_attached_property() 0x22aec78 1 -> 0<br>20:17:52 info c=
onnmand[474]: rp_filter restored to 0<br>20:17:52 warn connmand[474]: ipcon=
fig state 6 ipconfig method 1<br>20:17:52 warn connmand[474]: ipconfig stat=
e 6 ipconfig method 1<br>20:17:52 info connman-vpnd[481]: pid 622 was not k=
illed, retrying after 2 sec<br>20:17:52 err connmand[474]: notifier disconn=
ect underflow<br>20:17:52 warn connmand[474]: ipconfig state 6 ipconfig met=
hod 1<br>20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1<br=
>20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:17:5=
2 info connman-vpnd[481]: vpn0 {update} flags 37009 <UP><br>20:17:52 =
info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <DOWN><br>=
20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:17:52=
debug ofonod[532]: ../git/plugins/udevng.c:remove_device() /sys/devices/vi=
rtual/net/vpn0<br>20:17:52 warn connmand[474]: ipconfig state 6 ipconfig me=
thod 1<br>20:17:52 info connmand[474]: usb0 {del} address <a href=3D"http:/=
/192.168.1.100/24">192.168.1.100/24</a> label usb0<br>20:17:52 info connman=
d[474]: usb0 {del} route 192.168.1.0 gw 0.0.0.0 scope 253 <LINK><br>2=
0:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes<br>20:17:52 info =
connmand[474]: (null) {TX} 3 packets 128 bytes<br>20:17:52 info connmand[47=
4]: (null) {update} flags 37009 <UP><br>20:17:52 info connmand[474]: =
vpn0 {newlink} index 8 address 00:00:00:00:00:00 mtu 1500<br>20:17:52 info =
connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN><br>20:17:52 =
info connmand[474]: (null) {RX} 0 packets 0 bytes<br>20:17:52 info connmand=
[474]: (null) {TX} 3 packets 128 bytes<br>20:17:52 info connmand[474]: (nul=
l) {update} flags 102609 <UP,RUNNING,LOWER_UP><br>20:17:52 info connm=
and[474]: vpn0 {newlink} index 8 address 00:00:00:00:00:00 mtu 1500<br>20:1=
7:52 info connmand[474]: vpn0 {newlink} index 8 operstate 6 <UP><br>2=
0:17:52 info connmand[474]: (null) {RX} 0 packets 0 bytes<br>20:17:52 info =
connmand[474]: (null) {TX} 3 packets 128 bytes<br>20:17:52 info connmand[47=
4]: (null) {update} flags 37008 <DOWN><br>20:17:52 info connmand[474]=
: vpn0 {newlink} index 8 address 00:00:00:00:00:00 mtu 1500<br>20:17:52 inf=
o connmand[474]: vpn0 {newlink} index 8 operstate 2 <DOWN><br>20:17:5=
2 info connmand[474]: (null) {del} address <a href=3D"http://10.129.36.7/16=
">10.129.36.7/16</a> label vpn0<br>20:17:52 info connmand[474]: vpn0 {delli=
nk} index 8 operstate 2 <DOWN><br>20:17:52 info connmand[474]: (null)=
{RX} 0 packets 0 bytes<br>20:17:52 info connmand[474]: (null) {TX} 3 packe=
ts 128 bytes<br>20:17:52 info connmand[474]: (null) {remove} index 8<br>20:=
17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:17:52 in=
fo connman-vpnd[481]: vpn0 {update} flags 102609 <UP,RUNNING,LOWER_UP>=
;<br>20:17:52 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 6 &l=
t;UP><br>20:17:52 info connman-vpnd[481]: vpn0 {update} flags 37008 <=
DOWN><br>20:17:52 warn connmand[474]: ipconfig state 6 ipconfig method 1=
<br>20:17:52 info connman-vpnd[481]: vpn0 {newlink} index 8 operstate 2 <=
;DOWN><br>20:17:52 info connman-vpnd[481]: vpn0 {dellink} index 8 operst=
ate 2 <DOWN><br>20:17:52 info connman-vpnd[481]: vpn0 {remove} index =
8<br>20:17:55 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_n=
otify() /ublox_0 status 3 tech -1 lac -1 ci -1<br>20:17:55 debug ofonod[532=
]: ../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)<br>20:=
17:55 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 3 (denie=
d)<br>20:17:55 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() at=
tach: 0, driver_attached: 0</div><div><br></div><div><br></div><div>We get =
registered again:</div><div><br></div><div><br>20:17:57 debug ofonod[532]: =
../git/drivers/ubloxmodem/network-registration.c:ctze_notify() tz +04 dst 0=
time 20/03/14,21:18:19<br>20:17:57 debug ofonod[532]: ../git/src/network.c=
:ofono_netreg_time_notify() net time 2020-03-14 21:18:19 utcoff 3600 dst 0<=
br>20:17:57 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_not=
ify() /ublox_0 status 5 tech 2 lac 57005 ci 2147483647<br>20:17:57 debug of=
onod[532]: ../git/src/gprs.c:netreg_status_changed() 5 (roaming)<br>20:17:5=
7 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() attach: 1, driv=
er_attached: 0<br>20:17:57 debug ofonod[532]: ../git/drivers/atmodem/networ=
k-registration.c:cops_numeric_cb() Cops numeric got mcc: XXX, mnc: XX<br>20=
:17:57 debug ofonod[532]: ../git/drivers/atmodem/network-registration.c:csq=
_cb() csq_cb: 27<br>20:17:57 debug ofonod[532]: ../git/src/network.c:ofono_=
netreg_strength_notify() strength 87<br>20:17:57 debug ofonod[532]: ../git/=
src/gprs.c:gprs_attach_callback() /ublox_0 error =3D 0<br>20:17:57 debug of=
onod[532]: ../git/src/gprs.c:ofono_gprs_status_notify() /ublox_0 status roa=
ming (5)<br>20:17:57 debug ofonod[532]: ../git/drivers/atmodem/network-regi=
stration.c:cops_cb() cops_cb: Oper, XXX XX 2<br>20:17:57 debug ofonod[532]:=
../git/src/network.c:current_operator_callback() 0x22b2ed8, (nil)<br>20:17=
:57 debug ofonod[532]: ../git/src/gprs.c:netreg_status_changed() 5 (roaming=
)<br>20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_netreg_update() att=
ach: 1, driver_attached: 1<br>20:17:57 debug ofonod[532]: ../git/src/gprs.c=
:registration_status_cb() /ublox_0 error 0 status 5<br>20:17:57 debug ofono=
d[532]: ../git/src/gprs.c:ofono_gprs_status_notify() /ublox_0 status roamin=
g (5)<br>20:17:57 debug ofonod[532]: ../git/src/gprs.c:gprs_attached_update=
() 0x22aec78, attached: 1, gprs->attached: 0<br>20:17:57 debug ofonod[53=
2]: ../git/src/gprs.c:gprs_set_attached_property() 0x22aec78 0 -> 1<br>2=
0:17:58 debug ofonod[532]: ../git/src/network.c:ofono_netreg_status_notify(=
) /ublox_0 status 5 tech 2 lac 20201 ci 8577130<br>20:17:58 debug ofonod[53=
2]: ../git/src/gprs.c:netreg_status_changed() 5 (roaming)</div><div><br></d=
iv><div><br></div><div>Data bearer attached again: Seems like a try is done=
to connect to the vpn.</div><div><br></div><div><br>20:17:58 debug ofonod[=
532]: ../git/src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1<=
br>20:17:58 warn connmand[474]: ipconfig state 3 ipconfig method 1<br>20:17=
:58 info connmand[474]: Setting hostname to <hostname><br>20:17:58 in=
fo connmand[474]: usb0 {add} address <a href=3D"http://192.168.1.100/24";>19=
2.168.1.100/24</a> label usb0 family 2<br>20:17:58 info connmand[474]: usb0=
{add} route 192.168.1.0 gw 0.0.0.0 scope 253 <LINK><br>20:17:58 info=
connmand[474]: usb0 {add} route 192.168.1.1 gw 0.0.0.0 scope 253 <LINK&=
gt;<br>20:17:58 info connmand[474]: usb0 {add} route 0.0.0.0 gw 192.168.1.1=
scope 0 <UNIVERSE><br>20:17:58 warn connmand[474]: ipconfig state 2 =
ipconfig method 1<br>20:17:58 info connmand[474]: vpn0 {create} index 9 typ=
e 65534 <NONE><br>20:17:58 info connmand[474]: vpn0 {update} flags 42=
40 <DOWN><br>20:17:58 info connmand[474]: vpn0 {newlink} index 9 addr=
ess 00:00:00:00:00:00 mtu 1500<br>20:17:58 info connmand[474]: vpn0 {newlin=
k} index 9 operstate 2 <DOWN><br>20:17:58 info connman-vpnd[481]: vpn=
0 {create} index 9 type 65534 <NONE><br>20:17:58 info connman-vpnd[48=
1]: vpn0 {update} flags 4240 <DOWN><br>20:17:58 info connman-vpnd[481=
]: vpn0 {newlink} index 9 operstate 2 <DOWN><br>20:17:58 warn connman=
d[474]: ipconfig state 2 ipconfig method 1<br>20:17:58 debug ofonod[532]: .=
./git/plugins/udevng.c:add_serial_device() Device is missing required OFONO=
_DRIVER property<br>20:17:58 debug ofonod[532]: ../git/drivers/atmodem/netw=
ork-registration.c:cops_numeric_cb() Cops numeric got mcc: XXX, mnc: XX<br>=
20:17:58 debug ofonod[532]: ../git/drivers/atmodem/network-registration.c:c=
sq_cb() csq_cb: 27<br>20:17:58 warn connman-vpnd[481]: Connected management=
socket<br>20:17:58 warn connman-vpnd[481]: openvpn request >INFO:OpenVP=
N Management Interface Version 1 -- type 'help' for more info^M<br>=
20:17:58 debug ofonod[532]: ../git/drivers/atmodem/network-registration.c:c=
ops_cb() cops_cb: OPER, XXX XX 2<br>20:17:58 debug ofonod[532]: ../git/src/=
network.c:current_operator_callback() 0x22b2ed8, 0x22b8888<br>20:17:59 debu=
g ofonod[532]: ../git/plugins/udevng.c:check_modem_list() <br>20:17:59 debu=
g ofonod[532]: ../git/drivers/ubloxmodem/gprs-context.c:cgev_notify() cid 1=
, active cid: 1</div><div><br></div><div><br></div><div>Suddenly the contex=
t gets deactivated, during the time vpn tries to connect</div><div><br></di=
v><div><br>20:17:59 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_context=
_deactivated() 0x22aeb38 0x22aec78 1</div><div>20:17:59 info connman-vpnd[4=
81]: usb0 {update} flags 4098 <DOWN><br></div><div>20:17:59 info conn=
mand[474]: usb0 {RX} 7696 packets 1329655 bytes<br>20:17:59 info connman-vp=
nd[481]: usb0 {newlink} index 7 address 02:07:01:18:00:0B mtu 1400<br>20:17=
:59 info connmand[474]: usb0 {TX} 8199 packets 1553446 bytes<br>20:17:59 in=
fo connman-vpnd[481]: usb0 {newlink} index 7 operstate 2 <DOWN><br>20=
:17:59 info connmand[474]: usb0 {update} flags 4098 <DOWN><br>20:17:5=
9 info connmand[474]: usb0 {newlink} index 7 address 02:07:01:18:00:0B mtu =
1400<br>20:17:59 info connmand[474]: usb0 {newlink} index 7 operstate 2 <=
;DOWN><br>20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method =
1<br>20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:=
17:59 info connman-vpnd[481]: pid 3204 was not killed, retrying after 2 sec=
<br>20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:1=
7:59 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>20:17:59 war=
n connmand[474]: ipconfig state 6 ipconfig method 1<br>20:17:59 info connma=
nd[474]: usb0 {del} address <a href=3D"http://192.168.1.100/24";>192.168.1.1=
00/24</a> label usb0<br>20:17:59 warn connmand[474]: ipconfig state 6 ipcon=
fig method 1<br>20:17:59 warn connmand[474]: ipconfig state 2 ipconfig meth=
od 1<br>20:17:59 warn connmand[474]: ipconfig state 6 ipconfig method 1<br>=
20:17:59 debug ofonod[532]: ../git/drivers/ubloxmodem/gprs-context.c:ublox_=
gprs_activate_primary() cid 1<br>20:17:59 info connmand[474]: vpn0 {dellink=
} index 9 operstate 2 <DOWN><br>20:17:59 info connmand[474]: (null) {=
remove} index 9<br>20:17:59 debug ofonod[532]: ../git/plugins/udevng.c:remo=
ve_device() /sys/devices/virtual/net/vpn0<br>20:17:59 info connman-vpnd[481=
]: vpn0 {dellink} index 9 operstate 2 <DOWN><br>20:17:59 info connman=
-vpnd[481]: vpn0 {remove} index 9<br>20:17:59 warn connmand[474]: ipconfig =
state 6 ipconfig method 1<br>20:17:59 debug ofonod[532]: ../git/drivers/ubl=
oxmodem/gprs-context.c:cgdcont_cb() ok 1<br>20:17:59 warn connmand[474]: ip=
config state 7 ipconfig method 1<br>20:18:00 debug ofonod[532]: ../git/driv=
ers/ubloxmodem/gprs-context.c:cgact_enable_cb() ok 1<br>20:18:00 debug ofon=
od[532]: ../git/src/modem.c:get_modem_property() modem 0x22aec00 property N=
etworkInterface<br>20:18:00 debug ofonod[532]: ../git/src/gprs.c:pri_activa=
te_callback() 0x22b9b68</div><div><br></div><div><br></div><div>Context is =
activated again. Connman manage to get time via ntp and things looks good, =
except that the vpn is not reconnected.</div><div><br></div><div><br>20:18:=
00 info connman-vpnd[481]: usb0 {update} flags 69699 <UP,RUNNING,LOWER_U=
P><br>20:18:00 info connman-vpnd[481]: usb0 {newlink} index 7 address 02=
:07:01:18:00:0B mtu 1400<br>20:18:00 info connman-vpnd[481]: usb0 {newlink}=
index 7 operstate 0 <UNKNOWN><br>20:18:00 info connmand[474]: usb0 {=
RX} 7696 packets 1329655 bytes<br>20:18:00 info connmand[474]: usb0 {TX} 81=
99 packets 1553446 bytes<br>20:18:00 info connmand[474]: usb0 {update} flag=
s 69699 <UP,RUNNING,LOWER_UP><br>20:18:00 info connmand[474]: usb0 {n=
ewlink} index 7 address 02:07:01:18:00:0B mtu 1400<br>20:18:00 info connman=
d[474]: usb0 {newlink} index 7 operstate 0 <UNKNOWN><br>20:18:00 warn=
connmand[474]: ipconfig state 3 ipconfig method 1<br>20:18:00 info connman=
d[474]: Setting hostname to <hostname><br>20:18:00 debug ofonod[532]:=
../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 tech 2=
lac 57005 ci 2147483647<br>20:18:00 debug ofonod[532]: ../git/src/gprs.c:n=
etreg_status_changed() 5 (roaming)<br>20:18:00 debug ofonod[532]: ../git/sr=
c/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1<br>20:18:00 deb=
ug ofonod[532]: ../git/drivers/atmodem/gprs.c:at_cgdcont_read_cb() ok 1<br>=
20:18:00 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activated() ci=
d 1<br>20:18:00 debug ofonod[532]: ../git/src/gprs.c:ofono_gprs_cid_activat=
ed() cid 1 already activated<br>20:18:00 info connmand[474]: usb0 {add} add=
ress <a href=3D"http://192.168.1.100/24";>192.168.1.100/24</a> label usb0 fa=
mily 2<br>20:18:00 info connmand[474]: usb0 {add} route 192.168.1.0 gw 0.0.=
0.0 scope 253 <LINK><br>20:18:00 info connmand[474]: usb0 {add} route=
192.168.1.1 gw 0.0.0.0 scope 253 <LINK><br>20:18:00 info connmand[47=
4]: usb0 {add} route 0.0.0.0 gw 192.168.1.1 scope 0 <UNIVERSE><br>20:=
18:00 info connmand[474]: usb0 {add} route 212.227.81.55 gw 192.168.1.1 sco=
pe 0 <UNIVERSE><br>20:18:00 debug ofonod[532]: ../git/drivers/atmodem=
/network-registration.c:cops_numeric_cb() Cops numeric got mcc: XXX, mnc: X=
X<br>20:18:01 debug ofonod[532]: ../git/drivers/atmodem/network-registratio=
n.c:csq_cb() csq_cb: 29<br>20:18:01 debug ofonod[532]: ../git/src/network.c=
:ofono_netreg_strength_notify() strength 93<br>20:18:01 info connmand[474]:=
ntp: adjust (jump): +22.500568 sec<br>20:18:23 info connmand[474]: usb0 {d=
el} route 212.227.81.55 gw 192.168.1.1 scope 0 <UNIVERSE><br>20:18:23=
debug ofonod[532]: ../git/drivers/atmodem/network-registration.c:cops_cb()=
cops_cb: Oper, XXX XX 2<br>20:18:23 debug ofonod[532]: ../git/src/network.=
c:current_operator_callback() 0x22b2ed8, 0x22b8888<br>20:18:26 debug ofonod=
[532]: ../git/src/network.c:ofono_netreg_status_notify() /ublox_0 status 5 =
tech 2 lac 57005 ci 2147483647<br>20:18:26 debug ofonod[532]: ../git/src/gp=
rs.c:netreg_status_changed() 5 (roaming)<br>20:18:26 debug ofonod[532]: ../=
git/src/gprs.c:gprs_netreg_update() attach: 1, driver_attached: 1<br>20:18:=
26 debug ofonod[532]: ../git/drivers/atmodem/network-registration.c:cops_nu=
meric_cb() Cops numeric got mcc: XXX, mnc: XX<br>20:18:26 debug ofonod[532]=
: ../git/drivers/atmodem/network-registration.c:csq_cb() csq_cb: 29<br></di=
v><div><br></div><div><br></div><div><br></div><div><br></div></div></div><=
br><div class=3D"gmail_quote"><div dir=3D"ltr" class=3D"gmail_attr">Den tor=
s 23 jan. 2020 kl 15:38 skrev Jussi Laakkonen <<a href=3D"mailto:jussi.l=
[email protected]">[email protected]</a>>:<br></div><blockquote=
class=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px so=
lid rgb(204,204,204);padding-left:1ex">Hi Richard,<br>
<br>
On 1/22/20 1:50 PM, Richard R=C3=B6jfors wrote:<br>
> <br>
> Yes we are using TCP.<br>
> <br>
<br>
I assumed so, I think I faced a similar problem with our setup testing <br>
free VPNBook OpenVPN using TCP. But yours may still be a different one.<br>
<br>
> <br>
> Sounds great! I will try to verify it. Its not super easy to reproduce=
, <br>
> but over time and a few<br>
> devices it always happens. I'm thinking I could hack ofono a littl=
e to <br>
> simulate<br>
> the situation....<br>
> <br>
<br>
I submitted a patch for OpenVPN plugin just moments ago to connman list. <b=
r>
Please check if that improves your situation. After all, it is fixing a <br=
>
regression introduced by the changes I sent for OpenVPN.<br>
<br>
I still have a hunch there could be an improvement in place for the <br>
vpn-provider.c to track the connman state, and to delay the connection <br>
if connman is not reporting to be online. This would prevent connections <b=
r>
to VPNs when, in case just like yours, the default service (mobile data, <b=
r>
wifi) goes down only momentarily.<br>
<br>
In our fork we have this functionality already implemented. Now I just <br>
need to find time to create a patch/patches against connman upstream for <b=
r>
Daniel and others reading the list to review.<br>
<br>
Sincerely,<br>
=C2=A0 Jussi<br>
<br>
</blockquote></div>
--000000000000a78d9105a10ca715--
------------------------------
Subject: Digest Footer
_______________________________________________
connman mailing list -- [email protected]
To unsubscribe send an email to [email protected]
------------------------------
End of connman Digest, Vol 53, Issue 14
***************************************
