Skip to content

Commit

Permalink
Merge branch 'mer1774_debug_blocking_ops' into 'master'
Browse files Browse the repository at this point in the history 
Add debug logging about blocking operations

See merge request !25
  • Loading branch information
@spiiroin
spiiroin committed Mar 24, 2017
2 parents 435effc + 54af65c commit 4721fbd
Show file tree
Hide file tree
Showing 7 changed files with 104 additions and 39 deletions.
4 changes: 2 additions & 2 deletions rpm/usb-moded.spec
View file
Expand Up @@ -321,8 +321,8 @@ when the UI fails.
%setup -q

%build
%autogen
%configure --enable-app-sync --enable-meegodevlock --enable-debug --enable-connman --enable-systemd --enable-mer-ssu
test -e Makefile || (%autogen)
test -e Makefile || (%configure --enable-app-sync --enable-meegodevlock --enable-debug --enable-connman --enable-systemd --enable-mer-ssu)
make all doc %{?_smp_mflags}

%install
Expand Down
26 changes: 13 additions & 13 deletions src/usb_moded-modesetting.c
View file
Expand Up @@ -194,7 +194,7 @@ static int set_mass_storage_mode(struct mode_list_elem *data)
usb_moded_unload_module(MODULE_MASS_STORAGE);
sprintf(command2, "modprobe %s luns=%d \n", MODULE_MASS_STORAGE, mountpoints);
log_debug("usb-load command = %s \n", command2);
ret = system(command2);
ret = usb_moded_system(command2);
if(ret)
return(ret);
}
Expand All @@ -209,21 +209,21 @@ static int set_mass_storage_mode(struct mode_list_elem *data)
else
mountpath = mounts[i];
umount: command = g_strconcat("mount | grep ", mountpath, NULL);
ret = system(command);
ret = usb_moded_system(command);
g_free(command);
if(!ret)
{
/* no check for / needed as that will fail to umount anyway */
command = g_strconcat("umount ", mountpath, NULL);
log_debug("unmount command = %s\n", command);
ret = system(command);
ret = usb_moded_system(command);
g_free(command);
if(ret != 0)
{
if(try != 3)
{
try++;
sleep(1);
usb_moded_sleep(1);
log_err("Umount failed. Retrying\n");
report_mass_storage_blocker(mount, 1);
goto umount;
Expand All @@ -243,15 +243,15 @@ umount: command = g_strconcat("mount | grep ", mountpath, NULL);
}

/* activate mounts after sleeping 1s to be sure enumeration happened and autoplay will work in windows*/
sleep(1);
usb_moded_sleep(1);
for(i=0 ; mounts[i] != NULL; i++)
{

if(strcmp(data->mode_module, MODULE_NONE))
{
sprintf(command2, "echo %i > /sys/devices/platform/musb_hdrc/gadget/gadget-lun%d/nofua", fua, i);
log_debug("usb lun = %s active\n", command2);
system(command2);
usb_moded_system(command2);
sprintf(command2, "/sys/devices/platform/musb_hdrc/gadget/gadget-lun%d/file", i);
log_debug("usb lun = %s active\n", command2);
write_to_file(command2, mounts[i]);
Expand Down Expand Up @@ -301,13 +301,13 @@ static int unset_mass_storage_mode(struct mode_list_elem *data)
else
mountpath = mounts[i];
command = g_strconcat("mount | grep ", mountpath, NULL);
ret = system(command);
ret = usb_moded_system(command);
g_free(command);
if(ret)
{
command = g_strconcat("mount ", mountpath, NULL);
log_debug("mount command = %s\n",command);
ret = system(command);
ret = usb_moded_system(command);
g_free(command);
/* mount returns 0 if success */
if(ret != 0 )
Expand All @@ -321,7 +321,7 @@ static int unset_mass_storage_mode(struct mode_list_elem *data)
{
command = g_strconcat("mount -t tmpfs tmpfs -o ro --size=512K ", mount, NULL);
log_debug("Total failure, mount ro tmpfs as fallback\n");
ret = system(command);
ret = usb_moded_system(command);
g_free(command);
}
usb_moded_send_error_signal(RE_MOUNT_FAILED);
Expand All @@ -342,7 +342,7 @@ static int unset_mass_storage_mode(struct mode_list_elem *data)
{
sprintf(command2, "echo \"\" > /sys/devices/platform/musb_hdrc/gadget/gadget-lun%d/file", i);
log_debug("usb lun = %s inactive\n", command2);
system(command2);
usb_moded_system(command2);
}
}
g_strfreev(mounts);
Expand All @@ -363,7 +363,7 @@ static void report_mass_storage_blocker(const char *mountpoint, int try)

lsof_command = g_strconcat("lsof ", mountpoint, NULL);

if( (stream = popen(lsof_command, "r")) )
if( (stream = usb_moded_popen(lsof_command, "r")) )
{
char *text = 0;
size_t size = 0;
Expand Down Expand Up @@ -456,7 +456,7 @@ int set_dynamic_mode(void)
char command[256];

g_snprintf(command, 256, "ifdown %s ; ifup %s", data->network_interface, data->network_interface);
system(command);
usb_moded_system(command);
#else
usb_network_down(data);
network = usb_network_up(data);
Expand All @@ -482,7 +482,7 @@ int set_dynamic_mode(void)
if(data->appsync && !ret)
{
/* let's sleep for a bit (350ms) to allow interfaces to settle before running postsync */
usleep(350000);
usb_moded_msleep(350);
activate_sync_post(data->mode_name);
}

Expand Down
4 changes: 2 additions & 2 deletions src/usb_moded-modules.c
View file
Expand Up @@ -201,7 +201,7 @@ int usb_moded_module_cleanup(const char *module)
if(!strcmp(module, MODULE_NONE))
goto END;
/* wait a bit for all components listening on dbus to clean up their act
sleep(2); */
usb_moded_sleep(2); */
/* check if things were not reconnected in that timespan
if(get_usb_connection_state())
return(0);
Expand All @@ -224,7 +224,7 @@ int usb_moded_module_cleanup(const char *module)
while(failure)
{
/* module did not get unloaded. We will wait a bit and try again */
sleep(1);
usb_moded_sleep(1);
/* send the REALLY disconnect message */
usb_moded_send_signal(USB_REALLY_DISCONNECT);
failure = usb_moded_unload_module(module);
Expand Down
35 changes: 16 additions & 19 deletions src/usb_moded-network.c
View file
Expand Up @@ -155,13 +155,13 @@ static int set_usb_ip_forward(struct mode_list_elem *data, struct ipforward_data
}
write_to_file("/proc/sys/net/ipv4/ip_forward", "1");
snprintf(command, 128, "/sbin/iptables -t nat -A POSTROUTING -o %s -j MASQUERADE", nat_interface);
system(command);
usb_moded_system(command);

snprintf(command, 128, "/sbin/iptables -A FORWARD -i %s -o %s -m state --state RELATED,ESTABLISHED -j ACCEPT", nat_interface, interface);
system(command);
usb_moded_system(command);

snprintf(command, 128, "/sbin/iptables -A FORWARD -i %s -o %s -j ACCEPT", interface, nat_interface);
system(command);
usb_moded_system(command);

free(interface);
free(nat_interface);
Expand All @@ -178,7 +178,7 @@ static void clean_usb_ip_forward(void)
connman_reset_state();
#endif
write_to_file("/proc/sys/net/ipv4/ip_forward", "0");
system("/sbin/iptables -F FORWARD");
usb_moded_system("/sbin/iptables -F FORWARD");
}

#ifdef OFONO
Expand Down Expand Up @@ -491,10 +491,7 @@ gboolean connman_set_tethering(const char *path, gboolean on)
{
if (i>0)
{
struct timespec tv;
tv.tv_sec = 0;
tv.tv_nsec = 200000000;
nanosleep(&tv, NULL);
usb_moded_msleep(200);
}
if (connman_try_set_tethering(connection, path, on))
{
Expand Down Expand Up @@ -711,7 +708,7 @@ static int connman_set_cellular_online(DBusConnection *dbus_conn_connman, const
/* we don't care for the reply, which is empty anyway if all goes well */
ret = !dbus_connection_send(dbus_conn_connman, msg, NULL);
/* sleep for the connection to come up */
sleep(5);
usb_moded_sleep(5);
/* make sure the message is sent before cleaning up and closing the connection */
dbus_connection_flush(dbus_conn_connman);
dbus_message_unref(msg);
Expand Down Expand Up @@ -782,10 +779,10 @@ static int connman_wifi_power_control(DBusConnection *dbus_conn_connman, int on)

/* /net/connman/technology/wifi net.connman.Technology.SetProperty string:Powered variant:boolean:false */
if(wifistatus && !on)
system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/wifi net.connman.Technology.SetProperty string:Powered variant:boolean:false");
usb_moded_system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/wifi net.connman.Technology.SetProperty string:Powered variant:boolean:false");
if(wifistatus && on)
/* turn on wifi after tethering is over and wifi was on before */
system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/wifi net.connman.Technology.SetProperty string:Powered variant:boolean:true");
usb_moded_system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/wifi net.connman.Technology.SetProperty string:Powered variant:boolean:true");

return(0);
}
Expand Down Expand Up @@ -972,11 +969,11 @@ int usb_network_up(struct mode_list_elem *data)
const char *service = NULL;

/* make sure connman will recognize the gadget interface NEEDED? */
//system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/gadget net.connman.Technology.SetProperty string:Powered variant:boolean:true");
//system("/sbin/ifconfig rndis0 up");
//usb_moded_system("/bin/dbus-send --print-reply --type=method_call --system --dest=net.connman /net/connman/technology/gadget net.connman.Technology.SetProperty string:Powered variant:boolean:true");
//usb_moded_system("/sbin/ifconfig rndis0 up");

log_debug("waiting for connman to pick up interface\n");
sleep(1);
usb_moded_sleep(1);
dbus_error_init(&error);

if( (dbus_conn_connman = dbus_bus_get(DBUS_BUS_SYSTEM, &error)) == 0 )
Expand Down Expand Up @@ -1089,25 +1086,25 @@ int usb_network_up(struct mode_list_elem *data)
if(!strcmp(ip, "dhcp"))
{
sprintf(command, "dhclient -d %s\n", interface);
ret = system(command);
ret = usb_moded_system(command);
if(ret != 0)
{
sprintf(command, "udhcpc -i %s\n", interface);
system(command);
usb_moded_system(command);
}

}
else
{
sprintf(command, "ifconfig %s %s %s\n", interface, ip, netmask);
system(command);
usb_moded_system(command);
}

/* TODO: Check first if there is a gateway set */
if(gateway)
{
sprintf(command, "route add default gw %s\n", gateway);
system(command);
usb_moded_system(command);
}

free(interface);
Expand Down Expand Up @@ -1179,7 +1176,7 @@ int usb_network_down(struct mode_list_elem *data)
return(0);

sprintf(command, "ifconfig %s down\n", interface);
system(command);
usb_moded_system(command);

/* dhcp client shutdown happens on disconnect automatically */
if(data->nat)
Expand Down
62 changes: 60 additions & 2 deletions src/usb_moded.c
View file
Expand Up @@ -191,7 +191,7 @@ void set_usb_connected(gboolean connected)
static gboolean set_disconnected(gpointer data)
{
/* let usb settle */
sleep(1);
usb_moded_sleep(1);
/* only disconnect for real if we are actually still disconnected */
if(!get_usb_connection_state())
{
Expand Down Expand Up @@ -1130,6 +1130,64 @@ void usb_moded_stop(int exitcode)
g_main_loop_quit(usb_moded_mainloop);
}

/** Wrapper to give visibility to blocking system() calls usb-moded is making
*/
int
usb_moded_system_(const char *file, int line, const char *func,
const char *command)
{
log_debug("EXEC %s; from %s:%d: %s()",
command, file, line, func);

int rc = system(command);

if( rc != 0 )
log_warning("EXEC %s; exit code is %d", command, rc);

return rc;
}

/** Wrapper to give visibility subprocesses usb-moded is invoking via popen()
*/
FILE *
usb_moded_popen_(const char *file, int line, const char *func,
const char *command, const char *type)
{
log_debug("EXEC %s; from %s:%d: %s()",
command, file, line, func);

return popen(command, type);
}

/** Wrapper to give visibility to blocking sleeps usb-moded is making
*/
void
usb_moded_usleep_(const char *file, int line, const char *func,
useconds_t usec)
{
struct timespec ts = {
.tv_sec = (usec / 1000000),
.tv_nsec = (usec % 1000000) * 1000
};

long ms = (ts.tv_nsec + 1000000 - 1) / 1000000;

if( !ms ) {
log_debug("SLEEP %ld seconds; from %s:%d: %s()",
(long)ts.tv_sec, file, line, func);
}
else if( ts.tv_sec ) {
log_debug("SLEEP %ld.%03ld seconds; from %s:%d: %s()",
(long)ts.tv_sec, ms, file, line, func);
}
else {
log_debug("SLEEP %ld milliseconds; from %s:%d: %s()",
ms, file, line, func);
}

do { } while( nanosleep(&ts, &ts) == -1 && errno != EINTR );
}

int main(int argc, char* argv[])
{
int opt = 0, opt_idx = 0;
Expand Down Expand Up @@ -1220,7 +1278,7 @@ int main(int argc, char* argv[])
* INITIALIZE
* - - - - - - - - - - - - - - - - - - - */

/* silence system() calls */
/* silence usb_moded_system() calls */
if(log_type != LOG_TO_STDERR || log_level != LOG_DEBUG )
{
freopen("/dev/null", "a", stdout);
Expand Down
11 changes: 11 additions & 0 deletions src/usb_moded.h
View file
Expand Up @@ -96,4 +96,15 @@ extern int cable_connection_delay;

void usb_moded_stop(int exitcode);

int usb_moded_system_(const char *file, int line, const char *func, const char *command);
#define usb_moded_system(command) usb_moded_system_(__FILE__,__LINE__,__FUNCTION__,(command))

FILE *usb_moded_popen_(const char *file, int line, const char *func, const char *command, const char *type);
#define usb_moded_popen(command, type) usb_moded_popen_(__FILE__,__LINE__,__FUNCTION__,(command),(type))

void usb_moded_usleep_(const char *file, int line, const char *func, useconds_t usec);
#define usb_moded_usleep(usec) usb_moded_usleep_(__FILE__,__LINE__,__FUNCTION__,(usec))
#define usb_moded_msleep(msec) usb_moded_usleep_(__FILE__,__LINE__,__FUNCTION__,(msec)*1000)
#define usb_moded_sleep(sec) usb_moded_usleep_(__FILE__,__LINE__,__FUNCTION__,(sec)*1000000)

#endif /* USB_MODED_H */
1 change: 0 additions & 1 deletion systemd/usb-moded.service
View file
Expand Up @@ -14,7 +14,6 @@ EnvironmentFile=-/run/usb-moded/*.conf
ExecStart=/usr/sbin/usb_moded --systemd --force-syslog $USB_MODED_ARGS $USB_MODED_HW_ADAPTATION_ARGS
Restart=always
ExecReload=/bin/kill -HUP $MAINPID
BusName=com.meego.usb_moded

[Install]
WantedBy=basic.target

0 comments on commit 4721fbd

Please sign in to comment.